Re: [squid-users] 2.7.Stable6 httpReadReply: Excess data

2009-06-16 Thread Amos Jeffries
On Tue, 16 Jun 2009 15:25:05 -0700 (PDT), Quin Guin 
wrote:
> Hi,
> 
>  I am in the need of some assistance in looking into a high number of 
>  "httpReadReply: Excess data " entries around 3000 cache.log entries per
>  day per SQUID server. The  httpReadReply: Excess data from "GET
>  http://xx"; this is happening on many sites from my reading it is in
>  most cases it is an issue with the content site/server.

The server supplying Squid dis one of two things:

1) sent a request/reply with Content-Length: N, then pushed more than N
bytes of data into Squid.

2) sent a request/reply with unknown Content-Length: followed some time
later by the HTTP byte sequence for end-of-object. Which was in turn
followed by even more bytes of data.

Both of these are an old signs of malware overflow attacks. Squid will
respond by unconditionally closing the link to that server.

> I am a bit
>  concerned that Is this a sign of of memory or disk issue because from
the
>  cache manager things look to be running well. I also do see some other
>  errors and I have included the below with more information on my setup.
>  The "urlParse: Illegal character in hostname
>  'www.google-%20analytics.com'" is just annoying adn if anyone has away
to
>  fix it beside blocking it I would appreciate any ideas on that.

This is another issue, possibly the cause of the above. The HTTP headers
being received by squid are mangled beyond repair.  The client sending the
request is severely broken.

If possible please get a binary dump of the stream going into squid. NP:
tcpdump requires -s65535 option to grab it all. From that you should be
able to see exactly how the headers are broken.

> 
>  I am starting to see latency and I have a 3 node cluster of SQUID
servers
>  setup as standard reverse proxies.

Latency is kind of to be expected of many connections are failing with
these errors and being aborted incomplete.

> 
> Cache.log entries:
> 
> 2009/06/16 21:21:43| httpReadReply: Excess data from "GET
> http://www.myyearbook.com/apps/home";
> 2009/06/16 21:22:03| clientTryParseRequest: FD 14 (10.22.0.64:40881)
> Invalid Request
> 2009/06/16 21:22:04| clientTryParseRequest: FD 49 (10.22.0.63:40894)
> Invalid Request
> 2009/06/16 21:22:06| clientTryParseRequest: FD 36 (10.22.0.63:40938)
> Invalid Request
> 2009/06/16 21:22:21| clientTryParseRequest: FD 290 (10.22.0.65:41114)
> Invalid Request
> 2009/06/16 21:22:21| clientTryParseRequest: FD 415 (10.22.0.65:41124)
> Invalid Request
> 2009/06/16 21:22:22| clientTryParseRequest: FD 361 (10.22.0.63:41168)
> Invalid Request
> 2009/06/16 21:22:35| clientTryParseRequest: FD 109 (10.22.0.64:41418)
> Invalid Request
> 2009/06/16 21:22:35| clientTryParseRequest: FD 129 (10.22.0.63:41431)
> Invalid Request
> 2009/06/16 21:22:36| clientTryParseRequest: FD 477 (10.22.0.65:41458)
> Invalid Request
> 2009/06/16 21:22:50| clientTryParseRequest: FD 356 (10.22.0.63:41707)
> Invalid Request
> 2009/06/16 21:22:51| clientTryParseRequest: FD 180 (10.22.0.64:41719)
> Invalid Request
> 2009/06/16 21:22:51| clientTryParseRequest: FD 197 (10.22.0.63:41744)
> Invalid Request
> 2009/06/16 21:23:01| clientTryParseRequest: FD 49 (10.22.0.64:41875)
> Invalid Request
> 2009/06/16 21:23:01| clientTryParseRequest: FD 104 (10.22.0.63:41887)
> Invalid Request
> 2009/06/16 21:23:02| clientTryParseRequest: FD 399 (10.22.0.64:41921)
> Invalid Request
> 2009/06/16 21:23:03| httpReadReply: Excess data from "GET
> http://www.myyearbook.com/apps/home";
> 2009/06/16 21:23:04| httpReadReply: Excess data from "GET
> http://www.myyearbook.com/apps/home";
> 2009/06/16 21:23:21| clientTryParseRequest: FD 117 (10.22.0.63:42346)
> Invalid Request
> 2009/06/16 21:23:21| clientTryParseRequest: FD 457 (10.22.0.65:42394)
> Invalid Request
> 2009/06/16 21:23:22| clientTryParseRequest: FD 328 (10.22.0.63:42458)
> Invalid Request
> 2009/06/16 21:23:23| urlParse: Illegal character in hostname
> 'www.google-%20analytics.com'

Hint:  %20 (aka whitespace) is not a part of the google domain name.

> 2009/06/16 21:23:25| httpReadReply: Excess data from "GET
>
http://sugg.search.yahoo.net/sg/?output=fxjsonp&nresults=10&command=horny%20granies";
> 2009/06/16 21:23:45| clientTryParseRequest: FD 544 (10.22.0.65:42839)
> Invalid Request
> 2009/06/16 21:23:46| clientTryParseRequest: FD 228 (10.22.0.64:42852)
> Invalid Request
> 2009/06/16 21:23:47| clientTryParseRequest: FD 54 (10.22.0.64:42874)
> Invalid Request
> 2009/06/16 21:23:49| urlParse: Illegal character in hostname
> 'www.google-%20analytics.com'
> 2009/06/16 21:24:03| clientTryParseRequest: FD 35 (10.22.0.63:43094)
> Invalid Request
> 
> Squid Cache: Version 2.7.STABLE6-20090511
> configure options:  '--prefix=/usr/local/squid-2.7.STABLE6-20090511'
> '--enable-epoll' '--with-pthreads' '--enable-snmp'
> '--enable-storeio=ufs,aufs,coss' '-with-large-files'
> '--enable-large-cache-files' '--enable-follow-x-forwarded-for'
> '--with-maxfd=16384' '--disable-dependency-tracking'
> '--disable-ident-lookup

[squid-users] 2.7.Stable6 httpReadReply: Excess data

2009-06-16 Thread Quin Guin

Hi,

 I am in the need of some assistance in looking into a high number of  
"httpReadReply: Excess data " entries around 3000 cache.log entries per day per 
SQUID server. The  httpReadReply: Excess data from "GET http://xx"; this is 
happening on many sites from my reading it is in most cases it is an issue with 
the content site/server. I am a bit concerned that Is this a sign of of memory 
or disk issue because from the cache manager things look to be running well. I 
also do see some other errors and I have included the below with more 
information on my setup. The "urlParse: Illegal character in hostname 
'www.google-%20analytics.com'" is just annoying adn if anyone has away to fix 
it beside blocking it I would appreciate any ideas on that.

 I am starting to see latency and I have a 3 node cluster of SQUID servers 
setup as standard reverse proxies. 

Cache.log entries:

2009/06/16 21:21:43| httpReadReply: Excess data from "GET 
http://www.myyearbook.com/apps/home";
2009/06/16 21:22:03| clientTryParseRequest: FD 14 (10.22.0.64:40881) Invalid 
Request
2009/06/16 21:22:04| clientTryParseRequest: FD 49 (10.22.0.63:40894) Invalid 
Request
2009/06/16 21:22:06| clientTryParseRequest: FD 36 (10.22.0.63:40938) Invalid 
Request
2009/06/16 21:22:21| clientTryParseRequest: FD 290 (10.22.0.65:41114) Invalid 
Request
2009/06/16 21:22:21| clientTryParseRequest: FD 415 (10.22.0.65:41124) Invalid 
Request
2009/06/16 21:22:22| clientTryParseRequest: FD 361 (10.22.0.63:41168) Invalid 
Request
2009/06/16 21:22:35| clientTryParseRequest: FD 109 (10.22.0.64:41418) Invalid 
Request
2009/06/16 21:22:35| clientTryParseRequest: FD 129 (10.22.0.63:41431) Invalid 
Request
2009/06/16 21:22:36| clientTryParseRequest: FD 477 (10.22.0.65:41458) Invalid 
Request
2009/06/16 21:22:50| clientTryParseRequest: FD 356 (10.22.0.63:41707) Invalid 
Request
2009/06/16 21:22:51| clientTryParseRequest: FD 180 (10.22.0.64:41719) Invalid 
Request
2009/06/16 21:22:51| clientTryParseRequest: FD 197 (10.22.0.63:41744) Invalid 
Request
2009/06/16 21:23:01| clientTryParseRequest: FD 49 (10.22.0.64:41875) Invalid 
Request
2009/06/16 21:23:01| clientTryParseRequest: FD 104 (10.22.0.63:41887) Invalid 
Request
2009/06/16 21:23:02| clientTryParseRequest: FD 399 (10.22.0.64:41921) Invalid 
Request
2009/06/16 21:23:03| httpReadReply: Excess data from "GET 
http://www.myyearbook.com/apps/home";
2009/06/16 21:23:04| httpReadReply: Excess data from "GET 
http://www.myyearbook.com/apps/home";
2009/06/16 21:23:21| clientTryParseRequest: FD 117 (10.22.0.63:42346) Invalid 
Request
2009/06/16 21:23:21| clientTryParseRequest: FD 457 (10.22.0.65:42394) Invalid 
Request
2009/06/16 21:23:22| clientTryParseRequest: FD 328 (10.22.0.63:42458) Invalid 
Request
2009/06/16 21:23:23| urlParse: Illegal character in hostname 
'www.google-%20analytics.com'
2009/06/16 21:23:25| httpReadReply: Excess data from "GET 
http://sugg.search.yahoo.net/sg/?output=fxjsonp&nresults=10&command=horny%20granies";
2009/06/16 21:23:45| clientTryParseRequest: FD 544 (10.22.0.65:42839) Invalid 
Request
2009/06/16 21:23:46| clientTryParseRequest: FD 228 (10.22.0.64:42852) Invalid 
Request
2009/06/16 21:23:47| clientTryParseRequest: FD 54 (10.22.0.64:42874) Invalid 
Request
2009/06/16 21:23:49| urlParse: Illegal character in hostname 
'www.google-%20analytics.com'
2009/06/16 21:24:03| clientTryParseRequest: FD 35 (10.22.0.63:43094) Invalid 
Request

Squid Cache: Version 2.7.STABLE6-20090511
configure options:  '--prefix=/usr/local/squid-2.7.STABLE6-20090511' 
'--enable-epoll' '--with-pthreads' '--enable-snmp' 
'--enable-storeio=ufs,aufs,coss' '-with-large-files' 
'--enable-large-cache-files' '--enable-follow-x-forwarded-for' 
'--with-maxfd=16384' '--disable-dependency-tracking' '--disable-ident-lookups' 
'--enable-removal-policies=heap,lru' '--disable-wccp' 'CFLAGS=-fPIE -Os -g 
-pipe -fsigned-char -O2 -g -pipe -m64' 'LDFLAGS=-pie'


Connection information for squid:
Number of clients accessing cache:9
Number of HTTP requests received:431867579
Number of ICP messages received:0
Number of ICP messages sent:0
Number of queued ICP replies:0
Request failure ratio: 0.00
Average HTTP requests per minute since start:14133.0
Average ICP messages per minute since start:0.0
Select loop called: 1303826448 times, 1.406 ms avg
Cache information for squid:
Request Hit Ratios:5min: 59.2%, 60min: 60.8%
Byte Hit Ratios:5min: 65.7%, 60min: 65.5%
Request Memory Hit Ratios:5min: 27.0%, 60min: 26.9%
Request Disk Hit Ratios:5min: 61.1%, 60min: 61.4%
Storage Swap size:207997068 KB
Storage Mem size:262592 KB
Mean Object Size:19.94 KB
Requests given to unlinkd:0
Median Service Times (seconds)  5 min60 min:
HTTP Requests (All):   0.01745  0.01469
Cache Misses:  0.10281  0.10857
Cache Hits:0.0  0.0
Near Hits: 0.07825  0.08729
N