Re: [squid-users] Weird 3 second delay between Squid and F5 LB (reverse proxy)
On 7/27/07, Adrian Chadd <[EMAIL PROTECTED]> wrote: > Have you looked at it through tcpdump? > Those sorts of delays could be simple stuff like forward/reverse > DNS.. > > > Adrian Adiran, I have used straight IP instead of the VIP name with no change in symptoms, so it's not DNS. I've done tcpdumps and really have a hard time seeing anything that is questionable.. I am still looking at dumps to see if there is more to the story, but again to individual servers no issue, to the F5 LB a frequent 3 second (exact delay) Thanks Tory
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 ' 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 -
Re: [squid-users] Weird 3 second delay between Squid and F5 LB (reverse proxy)
On Fri, Jul 27, 2007, Tory M Blue wrote: > Adiran, I have used straight IP instead of the VIP name with no change > in symptoms, so it's not DNS. but could something -else- doing the DNS lookup.. > I've done tcpdumps and really have a hard time seeing anything that is > questionable.. I am still looking at dumps to see if there is more to > the story, but again to individual servers no issue, to the F5 LB a > frequent 3 second (exact delay) > Thanks > Tory Whats debugging on the F5 say? (I've not got an F5 so I can't do any testing at my end..) Adrian
Re: [squid-users] Weird 3 second delay between Squid and F5 LB (reverse proxy)
On 7/27/07, Adrian Chadd <[EMAIL PROTECTED]> wrote: > On Fri, Jul 27, 2007, Tory M Blue wrote: > > > Adiran, I have used straight IP instead of the VIP name with no change > > Whats debugging on the F5 say? > > (I've not got an F5 so I can't do any testing at my end..) > the tcpdumps are showing a reset from the LB, so this could be not internal to squid, although it felt like it. I think Squid is getting a reset and then taking sometime to create another connection and start all over again. I can post a snipet of a sniff, but it would only do any good for those that undestand what squid is doing at the packet layer Tory
Re: [squid-users] Weird 3 second delay between Squid and F5 LB (reverse proxy)
On fre, 2007-07-27 at 20:08 -0700, Tory M Blue wrote: > the tcpdumps are showing a reset from the LB, so this could be not > internal to squid, although it felt like it. I think Squid is getting > a reset and then taking sometime to create another connection and > start all over again. I can post a snipet of a sniff, but it would > only do any good for those that undestand what squid is doing at the > packet layer Squid is not operating at the packet layer at all.. it uses the TCP/IP stack of the host where you run Squid to do all the packet processing, focusing on connections. Regards Henrik
Re: [squid-users] Weird 3 second delay between Squid and F5 LB (reverse proxy) (RESOLUTION)
Top posting. The issue was with the Load Balancer closing the connection and the client thinking that the port was still open.. F5 did an amazing job with deciphering my dumps and following the packets. They stepped up and said "it does in fact look like our system and not Squid" Looking through cache01-new, every instance of a 3 second delay that I find, I see where 10.13.200.42 sends the SYN, which is sent through the BIG-IP to 10.13.200.153. In each instance, I find that 10.13.200.153, rather than replying to the SYN with a SYN-ACK, simply sends an ACK. This, bing incorrect, gets a RST response from 10.13.200.42. After all, 10.13.200.42 was expecting SYN-ACK, not ACK. After a three second delay, 10.13.200.42 initiates the handshake again, and this time 10.13.200.153 sends the SYN-ACK response, which allows the handshake to carry on. I had iniitially thought that this was the fault of 10.13.200.42, but looking over the w04-new tcpdump, and matching up the delay packets, it's very clear that there is no SYN-ACK, resulting in this 3 second delay. As to why 10.13.200.153 would respond to a SYN with just an ACK, I believe that this may be due to a port reuse issue. The server believes that port to still be in use, while the BIG-IP believes it to be closed. To get around this, I would suggest the use of incrementing autoport, where the BIG-IP does not try to use the same ephemeral port that the client uses, but rather makes use of some other ephemeral port. " Just wanted to close this out, I didn't think it was the Squid box but had to be sure. So I'm good to go! On 7/27/07, Adrian Chadd <[EMAIL PROTECTED]> wrote: > 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 ' 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
