WG: [squid-users] Squid processing very slow on some pdf

Hi due to George's hint about DNS resolution I found the solution

As we are not using ipv6 I have disabled ipv6 on the server and added the following line to the squid.conf

# Force ipv4
acl to_ipv6 dst ipv6
tcp_outgoing_address 160.85.104.12 !to_ipv

Not it works like a charm!

Thanks George.

-----Ursprüngliche Nachricht-----
Von: Sandrini Christian (xsnd)
Gesendet: Mittwoch, 30. Januar 2013 11:30
An: 'George Herbert'
Betreff: AW: [squid-users] Squid processing very slow on some pdf

Hi

I do see the following line in the cache.log when I enable debugging

2013/01/30 09:52:00.296| idnsGrokReply: www2.zhlex.zh.ch AAAA query failed. Trying A now instead.

There is actually a timeout.

# host www2.zhlex.zh.ch
www2.zhlex.zh.ch is an alias for zhcompublicweb1.djiktzh.ch.
zhcompublicweb1.djiktzh.ch is an alias for zhcompublicweb1.subd.djiktzh.ch.
zhcompublicweb1.subd.djiktzh.ch has address 195.65.218.66 ;; connection timed out; no servers could be reached Host zhcompublicweb1.subd.djiktzh.ch not found: 3(NXDOMAIN)

How could I fix that? How comes it works smooth without squid? Doesn't it have to resolve the name the same way as squid does?

-----Ursprüngliche Nachricht-----
Von: George Herbert [mailto:george.herbert_at_gmail.com]
Gesendet: Mittwoch, 30. Januar 2013 11:05
An: Sandrini Christian (xsnd)
Cc: squid-users_at_squid-cache.org
Betreff: Re: [squid-users] Squid processing very slow on some pdf

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/62FABE8867570E44C1257A21003
> 2892E/$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/62FABE8867570E44C1257A21003
> 2892E/$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 - 11:35:15 MST