On first impression from this data? Check DNS resolution from the Squid to that hostname. It sounds like a timeout / retry / recursion fail in progress... George William Herbert Sent from my iPhone On Jan 29, 2013, at 11:54 PM, "Sandrini Christian \(xsnd\)" <xsnd@xxxxxxx> wrote: > Hi > > We are using an f5 appliance that is loadbalancing http request to 3 squid servers. We use squid 3.1.10. When I want to open a pdf file of a certain domain it takes several minutes for 160kb. If I open the pdf without going through the proxy it is very quick. We have seen this problem only on the pdf of the following domain > > http://www2.zhlex.zh.ch/appl/zhlex_r.nsf/0/62FABE8867570E44C1257A210032892E/$file/414.252.3_29.1.08_77.pdf > > This is in the access.log. Squid takes 115 seconds to handle the request. > > 1359524314.374 115810 160.85.85.46 TCP_HIT/200 111028 GET http://www2.zhlex.zh.ch/appl/zhlex_r.nsf/0/62FABE8867570E44C1257A210032892E/$file/414.252.3_29.1.08_77.pdf - NONE/- application/pdf > > No logs have been written to cache.log during that time. > > I have captured the network traffic from the squidbox to www2.zhlex.zh.ch to find out the time squid takes to get the pdf. It does it in less than a second. > > tcpdump -i eth1 host www2.zhlex.zh.ch > tcpdump: verbose output suppressed, use -v or -vv for full protocol decode > listening on eth1, link-type EN10MB (Ethernet), capture size 65535 bytes > 06:30:45.491906 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [S], seq 1530511587, win 5840, options [mss 1460,nop,nop,sackOK], length 0 > 06:30:45.494241 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [S.], seq 3031868726, ack 1530511588, win 64240, options [mss 1380,nop,nop,sackOK], length 0 > 06:30:45.494259 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 1, win 5840, length 0 > 06:30:45.494353 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [P.], seq 1:519, ack 1, win 5840, length 518 > 06:30:45.524850 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [P.], seq 1:290, ack 519, win 63722, length 289 > 06:30:45.524864 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 290, win 6432, length 0 > 06:30:45.541484 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 290:1670, ack 519, win 63722, length 1380 > 06:30:45.541493 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 1670, win 9660, length 0 > 06:30:45.541603 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 1670:3050, ack 519, win 63722, length 1380 > 06:30:45.541612 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 3050, win 12420, length 0 > 06:30:45.541709 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 3050:4430, ack 519, win 63722, length 1380 > 06:30:45.541718 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 4430, win 15180, length 0 > 06:30:45.543929 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 4430:5810, ack 519, win 63722, length 1380 > 06:30:45.543937 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 5810, win 17940, length 0 > 06:30:45.544053 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 5810:7190, ack 519, win 63722, length 1380 > 06:30:45.544062 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 7190, win 20700, length 0 > 06:30:45.544162 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 7190:8570, ack 519, win 63722, length 1380 > 06:30:45.544170 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 8570, win 23460, length 0 > 06:30:45.544303 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 8570:9950, ack 519, win 63722, length 1380 > 06:30:45.544308 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 9950, win 26220, length 0 > 06:30:45.544372 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 9950:11330, ack 519, win 63722, length 1380 > 06:30:45.544381 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 11330, win 28980, length 0 > 06:30:45.544531 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 11330:12710, ack 519, win 63722, length 1380 > 06:30:45.544541 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 12710, win 33120, length 0 > 06:30:45.546216 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 12710:14090, ack 519, win 63722, length 1380 > 06:30:45.546226 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 14090, win 35880, length 0 > 06:30:45.546332 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 14090:15470, ack 519, win 63722, length 1380 > 06:30:45.546341 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 15470, win 38640, length 0 > 06:30:45.546463 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 15470:16850, ack 519, win 63722, length 1380 > 06:30:45.546472 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 16850, win 41400, length 0 > 06:30:45.546585 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 16850:18230, ack 519, win 63722, length 1380 > 06:30:45.548946 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 32030:33410, ack 519, win 63722, length 1380 > 06:30:45.549036 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 33410:34790, ack 519, win 63722, length 1380 > 06:30:45.549045 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 34790, win 64860, length 0 > 06:30:45.549150 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 34790:36170, ack 519, win 63722, length 1380 > 06:30:45.549283 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 36170:37550, ack 519, win 63722, length 1380 > 06:30:45.549293 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 37550, win 64860, length 0 > 06:30:45.549403 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 37550:38930, ack 519, win 63722, length 1380 > 06:30:45.549520 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 38930:40310, ack 519, win 63722, length 1380 > 06:30:45.549530 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 40310, win 64860, length 0 > 06:30:45.549651 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 40310:41690, ack 519, win 63722, length 1380 > 06:30:45.549863 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 41690:43070, ack 519, win 63722, length 1380 > 06:30:45.549875 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 43070, win 64860, length 0 > 06:30:45.549880 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 43070:44450, ack 519, win 63722, length 1380 > 06:30:45.549989 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 44450:45830, ack 519, win 63722, length 1380 > 06:30:45.549998 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 45830, win 64860, length 0 > 06:30:45.550120 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 45830:47210, ack 519, win 63722, length 1380 > 06:30:45.550229 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 47210:48590, ack 519, win 63722, length 1380 > 06:30:45.550239 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 48590, win 64860, length 0 > 06:30:45.550404 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], seq 48590:49970, ack 519, win 63722, length 1380 > 06:30:45.550413 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [P.], seq 49970:50566, ack 519, win 63722, length 596 > 06:30:45.550420 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 50566, win 64860, length 0 > 06:30:45.550730 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [F.], seq 519, ack 50566, win 64860, length 0 > 06:30:45.552075 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [F.], seq 50566, ack 519, win 63722, length 0 > 06:30:45.552084 IP srv-app-902.zhaw.ch.34179 > 195.65.218.66.http: Flags [.], ack 50567, win 64860, length 0 > 06:30:45.552535 IP 195.65.218.66.http > srv-app-902.zhaw.ch.34179: Flags [.], ack 520, win 63722, length 0 > > Config: > > #debug_options ALL,1 33,2 28,8 > > acl manager proto cache_object > acl localhost src 127.0.0.1/32 > acl bigip src 160.85.104.21/32 > acl to_localhost dst 127.0.0.0/8 > acl monhost src 160.85.192.190/32 > acl srv-ts-057 src 160.85.186.73/32 > acl srv-ts-058 src 160.85.186.74/32 > acl snmppublic snmp_community Fast3thernet > acl ZHAWnet src 160.85.0.0/16 # ZHAW > acl ZHAWnet src 195.176.253.59/32 # HSWNAT > acl ZHAWnet src 10.196.0.0/16 # VoIP > acl ZHAWnet src 10.194.4.0/22 # HAP > acl ZHAWnet src 10.194.36.0/22 # HSSAZ > acl ZHAWnet src 172.28.8.0/24 # Management Netz 1 > acl ZHAWnet src 172.28.9.0/24 # Management Netz 2 > acl ZHAWnet src 172.28.10.0/24 # FET-DEV > acl ZHAWnet src 172.28.11.0/24 # FET-TEST > acl ZHAWnet src 172.28.12.0/24 # BET-DEV > acl ZHAWnet src 172.28.13.0/24 # BET-TEST > acl ZHAWnet src 172.28.14.0/24 # FET-VDP > acl ZHAWnet src 172.28.15.0/24 # FET-VDP > acl STAFFMGR src 160.85.85.0/26 > acl SSL_ports port 443 8443 28443 50001 > acl Safe_ports port 80 # http > acl Safe_ports port 21 # ftp > acl Safe_ports port 443 # https > acl Safe_ports port 70 # gopher > acl Safe_ports port 210 # wais > acl Safe_ports port 1025-65535 # unregistered ports > acl Safe_ports port 280 # http-mgmt > acl Safe_ports port 488 # gss-http > acl Safe_ports port 591 # filemaker > acl Safe_ports port 777 # multiling http > acl CONNECT method CONNECT > acl MONZHAWCH dstdomain mon.sanitized.ch > acl ZREG dstdomain zreg.sanitized.ch > acl MS dstdomain domzhwin01.sanitized.ch > acl MS dstdomain domzhwin02.sanitized.ch > acl MS dstdomain domzhwin03.sanitized.ch > acl MS dstdomain dc01.sanitized.ch > acl MS dstdomain dc02.sanitized.ch > acl MS dstdomain dc03.sanitized.ch > acl MS dstdomain dc04.sanitized.ch > acl MS dstdomain dc10.sanitized.ch > acl MS dstdomain dc11.sanitized.ch > acl MS dstdomain turtle.sanitized.ch > acl MS dstdomain zebra.sanitized.ch > acl MS dstdomain dolphin.sanitized.ch > acl MS dstdomain orca.sanitized.ch > acl MS dstdomain kangaroo.sanitized.ch > acl MS dstdomain lobster.sanitized.ch > acl MS dstdomain calamari.sanitized.ch > acl MS dstdomain warthog.sanitized.ch > acl MS dstdomain billabong.sanitized.ch > acl MS dstdomain zeus.sanitized.ch > acl MS dstdomain rhino1.sanitized.ch > acl MS dstdomain rhino2.sanitized.ch > acl MS dstdomain zhaw.sanitized.ch > acl MS dstdomain barracuda.sanitized.ch > acl MS dstdomain caesar.sanitized.ch > acl MS dstdomain octopus.sanitized.ch > acl MS dstdomain pandora.sanitized.ch > acl MS dstdomain gonzo.sanitized.ch > acl PUT method PUT > http_access allow PUT ZHAWnet > http_access deny PUT > acl PURGE method PURGE > http_access allow PURGE localhost > http_access deny PURGE > acl PROPFIND method PROPFIND > http_access allow PROPFIND srv-ts-057 > http_access allow PROPFIND srv-ts-058 > http_access deny PROPFIND > http_access allow manager localhost > http_access deny manager > http_access deny !Safe_ports > http_access deny CONNECT !SSL_ports > http_access deny to_localhost > http_access deny !STAFFMGR MONZHAWCH > http_access deny !STAFFMGR ZREG > http_access deny MS > http_access allow ZHAWnet > http_access deny all > icp_access deny all > follow_x_forwarded_for allow localhost > follow_x_forwarded_for allow bigip > acl_uses_indirect_client on > delay_pool_uses_indirect_client on > log_uses_indirect_client on > http_port 160.85.104.11:8080 > hierarchy_stoplist cgi-bin ? > cache_mem 768 MB > maximum_object_size_in_memory 32 KB > cache_dir ufs /var/cache/squid 25000 64 256 > coredump_dir /var/cache/squid > #access_log /var/log/squid/access.log > #cache_log /var/log/squid/cache.log > cache_store_log none > #pid_filename /var/run/squid.pid > ftp_user wwwuser@xxxxxxxxxxxx > refresh_pattern ^ftp: 1440 20% 10080 > refresh_pattern ^gopher: 1440 0% 1440 > refresh_pattern -i (/cgi-bin/|\?) 0 0% 0 > refresh_pattern . 0 20% 4320 > acl shoutcast rep_header X-HTTP09-First-Line ^ICY.[0-9] > acl apache rep_header Server ^Apache > request_timeout 30 seconds > cache_mgr servicedesk@xxxxxxxxxxxx > #mail_from squid@xxxxxxxxxxxxxxxxxxxxxxxx > #mail_program /usr/local/bin/mutt > cache_effective_user squid > cache_effective_group squid > httpd_suppress_version_string on > visible_hostname srv-app-901.sanitized.ch > unique_hostname srv-app-901.sanitized.ch > snmp_port 3401 > snmp_access allow snmppublic monhost > snmp_access deny all > snmp_incoming_address 160.85.104.11 > snmp_outgoing_address 255.255.255.255 > icp_port 0 > allow_underscore off > dns_retransmit_interval 3 seconds > dns_timeout 1 minute > #dns_nameservers 160.85.192.100 160.85.193.100 > dns_nameservers 160.85.192.100 > append_domain .sanitized.ch > max_filedescriptors 8192 > > Has anyone an idea why squid takes so long for this request? How could I debug further? > > Thanks a lot.
