Hi, Many thanks for the reply. I've run the latest 3.2 snapshot on a standalone server and have generated a cache.log and corresponding access.log files. I've got a number of entries in the file.
1). http://dummyhost5678.hull.ac.uk/fred.txt This as you can guess is a nonexistent URL used to healthcheck a web cache by our hardware load balancer. I'm expecting a 503 status code to come back as it doesn't exist. Usually this occurs and you can see a response time of something in the order of 30 msec (?). However you also see the NONE_ABORTED:HIER_NONE request status and a response time of 4987 msecs which I'm fairly sure shouldn't happen. 2). doing a grep of ( sure there'll be a more elegant way of doing this) grep response_time\>[123456789][123456789][123456789][123456789][123456789] access.log.trace you get a whole batch of really long response times. Lurking around in there are www.bbc.co.uk healthcheck requests from the load balancer with queries from a client as well that also time out. <squid_rec source_ip="150.237.129.18" client_ip="-" cache="150.237.85.227" time="1328845687.303" real_cache="150.237.85.247"><source_ip>150.237.129.18</source_ip><client_ip>-</client_ip><user_login>-</user_login><user_ident>-</user_ident><user_name>-</user_name><date_time>10/Feb/2012:03:48:07 +0000</date_time><request_method>GET</request_method><url>http://rssnewsapps.ziffdavis.com/eweekmac.xml</url><protocol>HTTP/1.1</protocol><status_code>200</status_code><reply_size>4378</reply_size><request_status>TCP_MISS:HIER_DIRECT</request_status><response_time>111160</response_time></squid_rec> <squid_rec source_ip="150.237.140.32" client_ip="-" cache="150.237.84.13" time="1328845702.136" real_cache="150.237.85.247"><source_ip>150.237.140.32</source_ip><client_ip>-</client_ip><user_login>-</user_login><user_ident>-</user_ident><user_name>-</user_name><date_time>10/Feb/2012:03:48:22 +0000</date_time><request_method>GET</request_method><url>http://news.google.com/?</url><protocol>HTTP/1.1</protocol><status_code>200</status_code><reply_size>49331</reply_size><request_status>TCP_CLIENT_REFRESH_MISS:HIER_DIRECT</request_status><response_time>111752</response_time></squid_rec> <squid_rec source_ip="150.237.128.66" client_ip="-" cache="150.237.84.13" time="1328845747.54" real_cache="150.237.85.247"><source_ip>150.237.128.66</source_ip><client_ip>-</client_ip><user_login>-</user_login><user_ident>-</user_ident><user_name>-</user_name><date_time>10/Feb/2012:03:49:07 +0000</date_time><request_method>GET</request_method><url>http://www.google.co.uk/</url><protocol>HTTP/1.1</protocol><status_code>0</status_code><reply_size>0</reply_size><request_status>NONE_ABORTED:HIER_NONE</request_status><response_time>59929</response_time></squid_rec> <squid_rec source_ip="150.237.129.253" client_ip="-" cache="150.237.84.13" time="1328845748.831" real_cache="150.237.85.247"><source_ip>150.237.129.253</source_ip><client_ip>-</client_ip><user_login>-</user_login><user_ident>-</user_ident><user_name>-</user_name><date_time>10/Feb/2012:03:49:08 +0000</date_time><request_method>CONNECT</request_method><url>d.dropbox.com:443</url><protocol>HTTP/1.1</protocol><status_code>200</status_code><reply_size>5030</reply_size><request_status>TCP_MISS:HIER_DIRECT</request_status><response_time>61367</response_time></squid_rec> I'll probably have a peek at the log files myself to see if i can find something but I'll zip them up and submit a bug as well. Rgds Alex On 9 Feb 2012, at 01:48, Alex Rousskov wrote: > On 02/08/2012 05:14 AM, alex sharaz wrote: > >> I then downloaded the latest patch release 3.2.0.15......11508 and >> installed it on the test server. With this release, again everything >> seemed ok and a browser connecting to squid would get the 1st page. Any >> further attempts would result in a seriously long delay before anything >> appeared in the browser. A netstat -a would show a connection from the >> client to squid access.log would show nothing and then eventually (sorry >> I've XML'ized the logs) something of the form shown below. >> >> <squid_rec source_ip="150.237.129.18" client_ip="-" >> cache="150.237.85.197" time="1328683548.416" >> real_cache="150.237.85.197"><source_ip>150.237.129.18</source_ip><client_ip>-</client_ip><user_login>-</user_login><user_ident>-</user_ident><user_name>-</user_name><date_time>08/Feb/2012:06:45:48 >> +0000</date_time><request_method>GET</request_method><url>http://www.mozilla.org/img/covehead/divider-notch.jpg</url><protocol>HTTP/1.1</protocol><status_code>0</status_code><reply_size>0</reply_size><request_status>NONE_ABORTED:HIER_NONE</request_status><response_time>22881</response_time></squid_rec> >> >> >> >> The only thing that's changed is the release of squid used. >> >> FWIW I've re-enabled ipv6 on the box and removed the --disable-ipv6 >> option from the configure to no avail. >> >> Bit stuck as to what to look at next, any suggestions? > > If you can reproduce the "seriously long delay" problem with just a few > requests, then I recommend enabling full debugging (debug options > ALL,9), starting Squid from scratch, submitting those requests, and > filing a bug report with the resulting cache.log. If you identify the > URL that has experienced the delay, it would help others to find the > troubling transaction in the logs. > > You could analyze the log yourself as well, of course. It is often easy > to spot the place where the delay happens, especially if you use the > scripts to trace isolated transactions. What to do next depends on where > the identified delay source. > > > HTH, > > Alex. ========== Time for another Macmillan Cancer Support event. This time its the 12 day Escape to Africa challenge View route at http://maps.google.co.uk/maps/ms?ie=UTF8&hl=en&msa=0&msid=203779866436035016780.00049e867720273b73c39&z=8 Please sponsor me at http://www.justgiving.com/Alex-Sharaz
