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_at_zhaw.ch> 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_at_sanitized.ch
> 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_at_sanitized.ch
> #mail_from squid_at_srv-app-901.sanitized.ch
> #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.
Received on Wed Jan 30 2013 - 10:05:43 MST
This archive was generated by hypermail 2.2.0 : Wed Jan 30 2013 - 12:00:04 MST