Amos I got the same errors wit Stable11 this is why I switched back to the
original fedora squid package.
Here are the logs I got for Stable11
2009/01/19 09:36:52| helperStatefulOpenServers: Starting 5 'ntlm_auth'
processes
[2009/01/19 09:36:52, 0] utils/ntlm_auth.c:get_winbind_domain(173)
could not obtain winbind domain name!
[2009/01/19 09:36:52, 0] utils/ntlm_auth.c:get_winbind_domain(173)
[2009/01/19 09:36:52, 0] utils/ntlm_auth.c:get_winbind_domain(173)
could not obtain winbind domain name!
could not obtain winbind domain name!
[2009/01/19 09:36:52, 0] utils/ntlm_auth.c:get_winbind_domain(173)
could not obtain winbind domain name!
2009/01/19 09:36:52| User-Agent logging is disabled.
2009/01/19 09:36:52| Referer logging is disabled.
[2009/01/19 09:36:52, 0] utils/ntlm_auth.c:get_winbind_domain(173)
could not obtain winbind domain name!
2009/01/19 09:36:52| Unlinkd pipe opened on FD 16
2009/01/19 09:36:52| Local cache digest enabled; rebuild/rewrite every
3600/3600
sec
2009/01/19 09:36:52| Store logging disabled
2009/01/19 09:36:52| Swap maxSize 209879040 KB, estimated 16144541 objects
2009/01/19 09:36:52| Target number of buckets: 807227
2009/01/19 09:36:52| Using 1048576 Store buckets
2009/01/19 09:36:52| Max Mem size: 3145728 KB
2009/01/19 09:36:52| Max Swap size: 209879040 KB
2009/01/19 09:36:52| Version 1 of swap file without LFS support detected...
2009/01/19 09:36:52| Rebuilding storage in /cache1 (CLEAN)
2009/01/19 09:36:52| Using Least Load store dir selection
2009/01/19 09:36:52| Set Current Directory to /var/spool/squid
2009/01/19 09:36:52| Loaded Icons.
2009/01/19 09:36:52| Accepting transparently proxied HTTP connections at
0.0.0.0
, port 8080, FD 17.
2009/01/19 09:36:52| Accepting ICP messages at 0.0.0.0, port 3130, FD 18.
2009/01/19 09:36:52| HTCP Disabled.
2009/01/19 09:36:52| Ready to serve requests.
2009/01/19 09:36:53| Store rebuilding is 0.62% complete
2009/01/19 09:36:58| Done reading /cache1 swaplog (657105 entries)
2009/01/19 09:36:58| Finished rebuilding storage from disk.
2009/01/19 09:36:58| 657105 Entries scanned
2009/01/19 09:36:58| 0 Invalid entries.
2009/01/19 09:36:58| 0 With invalid flags.
2009/01/19 09:36:58| 657062 Objects loaded.
2009/01/19 09:36:58| 0 Objects expired.
2009/01/19 09:36:58| 0 Objects cancelled.
2009/01/19 09:36:58| 15 Duplicate URLs purged.
2009/01/19 09:36:58| 28 Swapfile clashes avoided.
2009/01/19 09:36:58| Took 5.84 seconds (112585.44 objects/sec).
2009/01/19 09:36:58| Beginning Validation Procedure
2009/01/19 09:36:58| 262144 Entries Validated so far.
2009/01/19 09:36:58| 1048576 Entries Validated so far.
2009/01/19 09:36:58| Completed Validation Procedure
2009/01/19 09:36:58| Validated 1314252 Entries
2009/01/19 09:36:58| store_swap_size = 14199244
2009/01/19 09:37:00| storeLateRelease: released 2 objects
2009/01/19 09:38:13| clientParseRequestMethod: Unsupported method attempted
by 1
0.128.145.118: This is not a bug. see squid.conf extension_methods
2009/01/19 09:38:13| clientParseRequestMethod: Unsupported method in request
'__
_/______k9_;N_7___%________*_^_jq__<e__aW_____Ckx_'
2009/01/19 09:38:13| clientProcessRequest: Invalid Request
2009/01/19 09:40:33| storeDirWriteCleanLogs: Starting...
2009/01/19 09:40:33| WARNING: Closing open FD 18
2009/01/19 09:40:33| 65536 entries written so far.
2009/01/19 09:40:33| 131072 entries written so far.
2009/01/19 09:40:33| 196608 entries written so far.
2009/01/19 09:40:33| 262144 entries written so far.
2009/01/19 09:40:33| 327680 entries written so far.
2009/01/19 09:40:33| 393216 entries written so far.
2009/01/19 09:40:34| 458752 entries written so far.
2009/01/19 09:40:34| 524288 entries written so far.
2009/01/19 09:40:34| 589824 entries written so far.
2009/01/19 09:40:34| 655360 entries written so far.
2009/01/19 09:40:34| Finished. Wrote 659046 entries.
2009/01/19 09:40:34| Took 0.23 seconds (2904809.13 entries/sec).
FATAL: comm_write: fd 885: pending callback!
Squid Cache (Version 3.0.STABLE11): Terminated abnormally.
CPU Usage: 15.366 seconds = 7.359 user + 8.007 sys
Maximum Resident Size: 0 KB
Page faults with physical i/o: 0
Memory usage for squid via mallinfo():
total space in arena: 13108 KB
Ordinary blocks: 13023 KB 86 blks
Small blocks: 0 KB 1 blks
Holding blocks: 134036 KB 538 blks
Free Small blocks: 0 KB
Free Ordinary blocks: 84 KB
Total in use: 147059 KB 1122%
Total free: 84 KB 1%
2009/01/19 09:40:37| Starting Squid Cache version 3.0.STABLE11 for
x86_64-redhat
-linux-gnu...
2009/01/19 09:40:37| Process ID 1060
2009/01/19 09:40:37| With 16384 file descriptors available
2009/01/19 09:40:37| DNS Socket created at 0.0.0.0, port 46857, FD 7
2009/01/19 09:40:37| Adding domain smartelecom.org from /etc/resolv.conf
2009/01/19 09:40:37| Adding nameserver 127.0.0.1 from /etc/resolv.conf
2009/01/19 09:40:37| Adding nameserver 81.85.241.28 from /etc/resolv.conf
2009/01/19 09:40:37| Adding nameserver 81.85.241.29 from /etc/resolv.conf
2009/01/19 09:40:37| helperStatefulOpenServers: Starting 5 'ntlm_auth'
processes
[2009/01/19 09:40:37, 0] utils/ntlm_auth.c:get_winbind_domain(173)
could not obtain winbind domain name!
[2009/01/19 09:40:37, 0] utils/ntlm_auth.c:get_winbind_domain(173)
could not obtain winbind domain name!
[2009/01/19 09:40:37, 0] utils/ntlm_auth.c:get_winbind_domain(173)
could not obtain winbind domain name!
[2009/01/19 09:40:37, 0] utils/ntlm_auth.c:get_winbind_domain(173)
could not obtain winbind domain name!
2009/01/19 09:40:37| User-Agent logging is disabled.
2009/01/19 09:40:37| Referer logging is disabled.
[2009/01/19 09:40:37, 0] utils/ntlm_auth.c:get_winbind_domain(173)
could not obtain winbind domain name!
2009/01/19 09:40:37| Unlinkd pipe opened on FD 16
2009/01/19 09:40:37| Local cache digest enabled; rebuild/rewrite every
3600/3600
sec
2009/01/19 09:40:37| Store logging disabled
2009/01/19 09:40:37| Swap maxSize 209879040 KB, estimated 16144541 objects
2009/01/19 09:40:37| Target number of buckets: 807227
2009/01/19 09:40:37| Using 1048576 Store buckets
2009/01/19 09:40:37| Max Mem size: 3145728 KB
2009/01/19 09:40:37| Max Swap size: 209879040 KB
2009/01/19 09:40:37| Version 1 of swap file without LFS support detected...
2009/01/19 09:40:37| Rebuilding storage in /cache1 (CLEAN)
2009/01/19 09:40:37| Using Least Load store dir selection
2009/01/19 09:40:37| Set Current Directory to /var/spool/squid
2009/01/19 09:40:37| Loaded Icons.
2009/01/19 09:40:37| Accepting transparently proxied HTTP connections at
0.0.0.0
, port 8080, FD 17.
2009/01/19 09:40:37| Accepting ICP messages at 0.0.0.0, port 3130, FD 18.
2009/01/19 09:40:37| HTCP Disabled.
2009/01/19 09:40:37| Ready to serve requests.
2009/01/19 09:40:37| Store rebuilding is 0.62% complete
2009/01/19 09:40:43| Done reading /cache1 swaplog (659046 entries)
2009/01/19 09:40:43| Finished rebuilding storage from disk.
2009/01/19 09:40:43| 659046 Entries scanned
2009/01/19 09:40:43| 0 Invalid entries.
2009/01/19 09:40:43| 0 With invalid flags.
2009/01/19 09:40:43| 658900 Objects loaded.
2009/01/19 09:40:43| 0 Objects expired.
2009/01/19 09:40:43| 0 Objects cancelled.
2009/01/19 09:40:43| 44 Duplicate URLs purged.
2009/01/19 09:40:43| 102 Swapfile clashes avoided.
2009/01/19 09:40:43| Took 5.99 seconds (110051.77 objects/sec).
2009/01/19 09:40:43| Beginning Validation Procedure
2009/01/19 09:40:43| 262144 Entries Validated so far.
2009/01/19 09:40:43| 524288 Entries Validated so far.
2009/01/19 09:40:43| 786432 Entries Validated so far.
2009/01/19 09:40:43| 1310720 Entries Validated so far.
2009/01/19 09:40:43| Completed Validation Procedure
2009/01/19 09:40:43| Validated 1318037 Entries
2009/01/19 09:40:43| store_swap_size = 14223796
2009/01/19 09:40:44| storeLateRelease: released 18 objects
2009/01/19 09:42:28| clientParseRequestMethod: Unsupported method attempted
by 1
0.128.135.208: This is not a bug. see squid.conf extension_methods
2009/01/19 09:42:28| clientParseRequestMethod: Unsupported method in request
'_'
9_=_l_`-_*w_N0qH____R_ _n*_A9+W_3__.______ ___W___)____#_s_g___
__#tV/]____%_?__
5M_7_*__"w______u_'
2009/01/19 09:42:28| clientProcessRequest: Invalid Request
2009/01/19 09:44:20| clientParseRequestMethod: Unsupported method attempted
by 1
0.128.135.208: This is not a bug. see squid.conf extension_methods
2009/01/19 09:44:20| clientParseRequestMethod: Unsupported method in request
'__
d___=-z______yG__n____6_o~U[X_Q____)L_x_\-p$a___-_2L_{_____'
2009/01/19 09:44:20| clientProcessRequest: Invalid Request
2009/01/19 09:48:39| clientParseRequestMethod: Unsupported method attempted
by 1
0.128.135.208: This is not a bug. see squid.conf extension_methods
2009/01/19 09:48:39| clientParseRequestMethod: Unsupported method in request
'__
___b__\__]__TrSf__|____'u__________'____Y_8___ _g___K____8___O__$__
___\_v_`W_#_
x_e_W__\ _xD___2_X'
2009/01/19 09:48:39| clientProcessRequest: Invalid Request
2009/01/19 09:49:46| clientParseRequestMethod: Unsupported method attempted
by 1
0.128.135.208: This is not a bug. see squid.conf extension_methods
2009/01/19 09:49:46| clientParseRequestMethod: Unsupported method in request
'__
_4$_Ji_[___A_L_'_A<F_:____*_y________P___K___t____I___Z_____<sFT___H_}__V_'_
___D
_n________l____}q'
As you see it is exactly the same error. Then another thing I noticed that
when squid restarts and start rebuilding the cache it says Store rebuilding
is 0.62% complete and then done directly although I have till now in the
cache around 22G of cached material. Is this normal do you think the problem
is store related?
>
>Three problems:
>First that is 3.0.STABLE10 running. Not the STABEL11 you say you installed.
>Second (non-fatal) problem:
> Some client is pumping binary data into squid through its listening port
>as a 'request'. Are you perhaps intercepting traffic?
I suspect this is a client who has some sort of malware on his pc I will
contact him to check out his system
> 2009/01/19 19:17:45| clientParseRequestMethod: Unsupported method in
> request
> '__
>
_______j___A__t_#__vQ_____s_V_s_{WZ_fd}_____3__9G(_____(__DQ_N___W_Ba__T_u__
> _`__
> __OH_k_#>_k____Wz+'
> 2009/01/19 19:17:45| clientProcessRequest: Invalid Request
>Third (non-fatal, slow-speed) problem, IO seems to be overloading:
> 2009/01/19 19:17:59| squidaio_queue_request: WARNING - Queue congestion
>Are your disks full? Or just an overload of large requests at peak traffic
>times.
My discs are not full in fact I still have a lot of space but this might be
overload when squid restarts by itself
Fourth (fatal) problem, Squid rotate/restarts and flushing it's indexes to
disk dies.
> 2009/01/19 19:20:08| ctx: exit level 0
> 2009/01/19 19:20:08| storeDirWriteCleanLogs: Starting...
> 2009/01/19 19:20:08| WARNING: Closing open FD 17
<snip>
> 2009/01/19 19:20:09| 851968 entries written so far.
> 2009/01/19 19:20:09| 917504 entries written so far.
> 2009/01/19 19:20:09| Finished. Wrote 978773 entries.
> 2009/01/19 19:20:09| Took 0.35 seconds (2810079.01 entries/sec).
> FATAL: comm_write: fd 1055: pending callback!
<snip>
I think this is already known, bugzilla is down right now so I can't check.
First, try getting the STABLE11 to actually be the running squid. That may
solve the issue for you.
> Something is happening where squid says FATAL: comm_write: fd 2296:
> pending
> callback! And it stops and restart.
> Does anyone have any idea what's wrong with the system. Do you think it is
> a
> configuration problem. The system is a core2 Duo 2.66G CPU and 8GB of RAM
> and 1 HDD exclusively for caching 250GB Sata 10000 RPM. Can the problem be
> resolved with Squid3 or shall I go back to squid 2.6 or 2.7?
>
> My uname -r output gives the following
>
> 2.6.27.9-73.fc9.x86_64 as function kernel
>
> Thank you
>
> Ragheb Rustom
>
>
>
>
Thanks Again
