Re: [squid-users] Weird 3 second delay between Squid and F5 LB (reverse proxy)

Have you looked at it through tcpdump?
Those sorts of delays could be simple stuff like forward/reverse
DNS..

Adrian

On Fri, Jul 27, 2007, Tory M Blue wrote:
> I'm not sure what is going on and have done so much tracing that I've
> just probably confused things more then anything else.
>
> i'm running Squid Cache: Version 2.6.STABLE12, on Fedora Core 6.
>
> It's configured to point to a single parent (which is a Virtual IP on
> the LB) with multiple servers sitting behind that virtual (so yes a
> pool).
>
> If i run wget's, socket scrpts etc, against squid pointing to a single
> host, or have all 4 hosts listed as parents, there is no issue.
>
> If I have squid pointing at the above mentioned VIP I see a 3 second
> delay every x connections, can be the 9th, 30th or 100th connection
> (again the 3 second delays are very random, but very bothersome).
>
> Another point of interest, running thru a Netapp Cache there are zero delays..
>
>
> Socket level test:
>
> Fri Jul 27 08:56:53 2007: Iteration #28
> Fri Jul 27 08:56:53 2007: Connecting to localhost:80...
> Fri Jul 27 08:56:53 2007: Connected.
> Fri Jul 27 08:56:53 2007: Sending request...
> Fri Jul 27 08:56:53 2007: Sent.
> Fri Jul 27 08:56:53 2007: Receiving response... <--- 3 second delay..
> Fri Jul 27 08:56:56 2007: Received complete response.
> Fri Jul 27 08:56:56 2007: Closing socket.
> Fri Jul 27 08:56:56 2007: Socket closed.
>
> Squid http debug: 3 second delay at end
> ----------------------------------------
> 2007/07/26 15:36:35| getMaxAge:
> 'http://host/abc/directorytest/c/i-1.JPG?rand=859749'
> 2007/07/26 15:36:35| ctx: enter level 0:
> 'http://host/abc/directorytest/c/i-1.JPG?rand=859749'
> 2007/07/26 15:36:35| refreshCheck:
> 'http:/host/abc/directorytest/c/i-1.JPG?rand=859749'
> 2007/07/26 15:36:35| STALE: expires 1185489395 < check_time 1185489455
> 2007/07/26 15:36:35| Staleness = 60
> 2007/07/26 15:36:35| refreshCheck: Matched '<none> 0 20% 259200'
> 2007/07/26 15:36:35| refreshCheck: age = 60
> 2007/07/26 15:36:35| check_time: Thu, 26 Jul 2007 22:37:35 GMT
> 2007/07/26 15:36:35| entry->timestamp: Thu, 26 Jul 2007 22:36:35 GMT
> 1185489395.994 SWAPOUT 00 00081DFD 741C0A705149FFD54F8CE6B6B4486D77
> 200 1185489396 1185383126 1185489396 image/jpeg 42492/42492 GET
> http://host/abc/directorytest/c/i-1.JPG?
> 2007/07/26 15:36:38| ctx: exit level 0 <--- shows the 3 second delay
>
>
> More Squid debug (different times) 3 second delay at end
> -------------------------------------------------
> 2007/07/26 15:06:54| fwdStateFree: 0x85b9388
> 2007/07/26 15:06:54| fwdStart:
> 'http://host/abc/directorytest/c/i-1.JPG?rand=279660'
> 2007/07/26 15:06:54| fwdStartComplete:
> http://host/abc/directorytest/c/i-1.JPG?rand=279660
> 2007/07/26 15:06:54| fwdConnectStart:
> http://host/abc/directorytest/c/i-1.JPG?rand=279660
> 2007/07/26 15:06:54| fwdConnectStart: got addr 0.0.0.0, tos 0
> 2007/07/26 15:07:03| fwdConnectDone: FD 17:
> 'http://host/abc/directorytest/c/i-1.JPG?rand=279660'
> 2007/07/26 15:07:03| fwdDispatch: FD 16: Fetching 'GET
> http://host/abc/directorytest/c/i-1.JPG?rand=279660'
> 2007/07/26 15:07:03| fwdComplete:
> http://hostabc/directorytest/c/i-1.JPG?rand=279660
> status 200
> 2007/07/26 15:07:03| fwdReforward:
> http://hostabc/directorytest/c/i-1.JPG?rand=279660?
> 2007/07/26 15:07:03| fwdReforward: No, ENTRY_FWD_HDR_WAIT isn't set
> 2007/07/26 15:07:03| fwdComplete: not re-forwarding status 200
> 1185487623.236 SWAPOUT 00 0008077B 8AB49FB3B897FB721E06A8ED91EE1AF 200
> 1185487623 1185383126 1185487623 image/jpeg 42492/42492 GET
> http://host/abc/directorytest/c/i-1.JPG?
> 2007/07/26 15:07:03| fwdServerClosed: FD 17
> http://host/abc/directorytest/c/i-1.JPG?rand=279660

-- 
- Xenion - http://www.xenion.com.au/ - VPS Hosting - Commercial Squid Support -
- $25/pm entry-level bandwidth-capped VPSes available in WA -