Re: [squid-users] very slow responses from squid

From: Gopinath Achari <gopinath_at_signal-networks.com>
Date: Fri, 13 Feb 2009 14:06:30 +0530

Please check does the DNS server responds to the dns query fastly.

If the DNS lookup is slow can make the squid respond slowly

add multiple DNS server entries in the squid.conf file

On Friday 13 February 2009 03:54, mikie_at_x.org.pl wrote:
> > mikie_at_x.org.pl wrote:
> >> Hi all,
> >>
> >> I'm going crazy with squid configuration. I've been trying to make it
> >> work
> >> fine for couple of weeks and finally gave up. Please, help! :)
> >>
> >> The problem is that squid responses are very very slow. I can notice a
> >> significant delays even when I use squid by myself (only my browser
> >> using
> >> it) and if I let some more people use it as transparent proxy, there is
> >> barely any response from squid on all machines.
> >>
> >> I install squid on slackware 12.2. Already tried few versions
> >> (2.7.STABLE5,2.7.STABLE6, 3.0.STABLE11) and many compile parameters.
> >> Let's
> >> say I do:
> >>
> >> ./configure \
> >> --prefix=/usr \
> >> --includedir=/usr/include \
> >> --datadir=/usr/share \
> >> --bindir=/usr/sbin \
> >> --libexecdir=/usr/lib/squid \
> >> --localstatedir=/var \
> >> --sysconfdir=/etc/squid
> >>
> >> I have the other instance of squid on other machine which works fine.
> >> But
> >> even when I move the config from this machine to my slackware box it
> >> does
> >> the same way - SLOW.
> >>
> >> System configuration is:
> >>
> >> # uname -a
> >> Linux ninja 2.6.27.7-smp #2 SMP Thu Nov 20 22:32:43 CST 2008 i686
> >> Intel(R)
> >> Xeon(TM) CPU 3.40GHz GenuineIntel GNU/Linux
> >>
> >> # free -m
> >> total used free shared buffers
> >> cached
> >> Mem: 3036 666 2370 0 356
> >> 203
> >> -/+ buffers/cache: 107 2929
> >> Swap: 4102 0 4102
> >>
> >> # df -h
> >> Filesystem Size Used Avail Use% Mounted on
> >> /dev/root 30G 6.8G 22G 24% /
> >> tmpfs 1.5G 0 1.5G 0% /dev/shm
> >>
> >>
> >>
> >> This is what I call SLOW:
> >>
> >> $ time w3m -dump www.slackware.org
> >> [...]
> >> real 3m9.045s
> >> ^^^^^^^^ !!!
> >> user 0m0.032s
> >> sys 0m0.008s
> >
> > Where was this request run from (the proxy itself, or another
> > computer)? Was this request intercepted by the proxy, and if so, how?
>
> It was run from another computer. Intercepted by proxy.
>
> The configuration is something like:
>
>
> Internet
>
> eth0 |
>
> |-------------|
> | Proxy Box |
> | ninja |
> |-------------|
>
> eth1 |10.10.0.26
>
> | 10.10.0.0/22 network
>
> Client (10.10.1.4)
>
> There is iptables rule at proxy box:
>
> iptables -A PREROUTING -t nat -i eth1 -s 10.10.0.0/22 -p tcp --dport 80 -j
> REDIRECT --to-port 3128
>
> > What does the access log look like after this request?
>
> In access.log around this request there was :
>
> 1234448425.123 9 10.10.2.133 TCP_MISS/200 3368 GET
> http://m.onet.pl/_m/187a57b2378f7f02dd93d2c1bf6500c7,39,29,0-0-321-214-0.jp
>g - DIRECT/213.180.130.204 image/jpeg
> 1234448425.133 8 10.10.2.133 TCP_MISS/200 2259 GET
> http://m.onet.pl/_m/3d31dcd40ed9a7005487ec67f1463bc1,39,29,0-2-460-305-0.jp
>g - DIRECT/213.180.130.204 image/jpeg
> 1234448425.137 0 10.10.2.133 TCP_HIT/200 6185 GET
> http://m.onet.pl/_m/26bcf6361b28af8acf4cbbf281a597f3,44,29,0-293-667-326-0.
>jpg - NONE/- image/jpeg
> 1234448425.159 7 10.10.2.133 TCP_MISS/200 3812 GET
> http://m.onet.pl/_m/e8e6bcb1a0f521461b6181707bc34543,43,29,0-0-300-196-0.jp
>g - DIRECT/213.180.130.204 image/jpeg
> 1234448425.177 7 10.10.2.133 TCP_MISS/200 2969 GET
> http://m.onet.pl/_m/18fefe81dbc86382cc83ba8ed8e12b18,42,29,24-1-229-154-0.j
>pg - DIRECT/213.180.130.204 image/jpeg
> 1234448425.192 7 10.10.2.133 TCP_MISS/200 2178 GET
> http://m.onet.pl/_m/d8f8780a335ad8d39bb75c34505f05ae,42,29,40-2-221-149-0.j
>pg - DIRECT/213.180.130.204 image/jpeg
> 1234448425.205 7 10.10.2.133 TCP_MISS/200 2549 GET
> http://m.onet.pl/_m/f766f193723220d2e712863f376ccf77,42,29,24-1-250-168-0.j
>pg - DIRECT/213.180.130.204 image/jpeg
> 1234448425.718 52 10.10.2.216 TCP_MISS/200 404 GET
> http://mail.google.com/a/gazeta.pl/channel/test? - DIRECT/74.125.39.19
> text/html
> 1234448426.733 77 10.10.2.216 TCP_MISS/200 418 GET
> http://mail.google.com/a/gazeta.pl/images/cleardot.gif? -
> DIRECT/74.125.39.83 image/gif
> 1234448427.805 10 10.10.1.43 TCP_MISS/200 692 GET
> http://gg.hit.gemius.pl/_1234448382820/rexdot.gif? - DIRECT/91.197.13.134
> image/gif
> 1234448428.742 19 10.10.2.2 TCP_MISS/200 1636 GET
> http://adserver.gadu-gadu.pl/getbanner.asp? - DIRECT/91.197.13.212
> text/html
> 1234448429.915 0 10.10.1.29 TCP_MEM_HIT/200 3450 GET
> http://pictures.trader.pl/pictures/0/2/0/107567540-101118-3.jpg - NONE/-
> image/jpeg
> 1234448429.921 0 10.10.1.29 TCP_MEM_HIT/200 3450 GET
> http://pictures.trader.pl/pictures/0/2/0/107567540-101118-3.jpg - NONE/-
> image/jpeg
> 1234448429.924 0 10.10.1.29 TCP_MEM_HIT/200 1787 GET
> http://pictures.trader.pl/pictures/search-results/0/2/0/107567540-101118-3.
>jpg - NONE/- image/jpeg
> 1234448430.443 16 10.10.2.48 TCP_MISS/200 1712 GET
> http://www.tvn24.pl/messages.xml - DIRECT/213.180.130.210 text/xml
> 1234448430.824 10 10.10.1.227 TCP_MISS/200 665 GET
> http://ggao.hit.gemius.pl/_1234448400782/redot.js/id=1_Xg7aszd5jQsnlOOSjrb5
>ZWP_gFPy_cuKEa0btbQ.H.87/stparam=qlgegkijli/sarg=0000000240675C7A -
> DIRECT/91.197.13.200 application/x-javascript
> 1234448431.854 0 10.10.1.29 TCP_MEM_HIT/200 1787 GET
> http://pictures.trader.pl/pictures/search-results/0/2/0/107567540-101118-3.
>jpg - NONE/- image/jpeg
> 1234448431.863 0 10.10.1.29 TCP_MEM_HIT/200 4850 GET
> http://pictures.trader.pl/pictures/0/8/6/107567540-101120-4.jpg - NONE/-
> image/jpeg
> 1234448431.882 0 10.10.1.29 TCP_MEM_HIT/200 2399 GET
> http://pictures.trader.pl/pictures/search-results/0/8/6/107567540-101120-4.
>jpg - NONE/- image/jpeg
> 1234448431.885 0 10.10.1.29 TCP_MEM_HIT/200 4850 GET
> http://pictures.trader.pl/pictures/0/8/6/107567540-101120-4.jpg - NONE/-
> image/jpeg
> 1234448431.942 267 10.10.2.195 TCP_MISS/200 32315 GET
> http://wyborcza.pl/reklamagw/0,78728.html - DIRECT/80.252.0.132 text/html
> 1234448432.612 1 10.10.1.4 TCP_HIT/200 14522 GET
> http://www.slackware.org/ - NONE/- text/html
> 1234448433.741 58 10.10.2.250 TCP_MISS/302 551 GET
> http://www.google.pl/ - DIRECT/74.125.39.104 text/html
> 1234448433.868 110 10.10.2.250 TCP_MISS/200 11702 GET
> http://www.google.pl/ig? - DIRECT/74.125.39.104 text/html
> 1234448434.158 34 10.10.2.250 TCP_MISS/302 551 GET
> http://www.google.pl/ - DIRECT/74.125.39.104 text/html
> 1234448434.466 0 10.10.2.137 TCP_MEM_HIT/301 600 GET
> http://google.pl/ - NONE/- text/html
> 1234448434.531 43 10.10.2.137 TCP_MISS/200 3279 GET
> http://www.google.pl/ - DIRECT/74.125.39.104 text/html
> 1234448434.611 35 10.10.2.137 TCP_MISS/200 6687 GET
> http://www.google.pl/images/nav_logo3.png - DIRECT/74.125.39.104 image/png
> 1234448434.658 0 10.10.2.53 TCP_MISS/504 1495 GET
> http://www.stelsy.com/page1 - DIRECT/www.stelsy.com text/html
> 1234448436.677 107 10.10.2.137 TCP_MISS/200 8117 GET
> http://www.google.pl/search? - DIRECT/74.125.39.104 text/html
> 1234448436.741 59 10.10.2.137 TCP_MISS/200 1982 GET
> http://www.google.pl/images/newspaper.gif - DIRECT/74.125.39.147 image/gif
> 1234448437.047 1264 10.10.1.105 TCP_MISS/200 21685 GET
> http://www.skyscrapercity.com/showthread.php? - DIRECT/66.249.128.93
> text/html
> 1234448437.731 0 10.10.2.53 TCP_MISS/504 1495 GET
> http://www.stelsy.com/page1 - DIRECT/www.stelsy.com text/html
> 1234448438.318 0 10.10.1.29 TCP_MEM_HIT/200 2399 GET
> http://pictures.trader.pl/pictures/search-results/0/8/6/107567540-101120-4.
>jpg - NONE/- image/jpeg
> 1234448438.343 1 10.10.1.29 TCP_HIT/200 13299 GET
> http://pictures.trader.pl/pictures/4/0/5/107567540-101122-5.jpg - NONE/-
> image/jpeg
> 1234448438.350 0 10.10.1.29 TCP_MEM_HIT/200 2267 GET
> http://pictures.trader.pl/pictures/search-results/4/0/5/107567540-101122-5.
>jpg - NONE/- image/jpeg
> 1234448438.996 4 10.10.1.244 TCP_MISS/200 692 GET
> http://arbo.hit.gemius.pl/_1234448439205/rexdot.gif? -
> DIRECT/195.42.113.219 image/gif
> 1234448439.526 14 10.10.1.209 TCP_MISS/200 556 GET
> http://interia.hit.gemius.pl/_1234448439529/redot.gif? -
> DIRECT/217.74.64.40 image/gif
> 1234448439.624 0 10.10.2.53 TCP_MISS/504 1495 GET
> http://www.stelsy.com/page1 - DIRECT/www.stelsy.com text/html
> 1234448440.673 0 10.10.2.53 TCP_MISS/504 1495 GET
> http://www.stelsy.com/page1 - DIRECT/www.stelsy.com text/html
> 1234448440.847 30 10.10.2.137 TCP_MISS/204 351 GET
> http://www.google.pl/url? - DIRECT/74.125.39.147 text/html
> 1234448441.692 31 10.10.1.141 TCP_MISS/204 330 GET
> http://www.google.pl/csi? - DIRECT/74.125.39.147 text/html
> 1234448442.627 0 10.10.2.6 TCP_MEM_HIT/301 600 GET http://google.pl/
> - NONE/- text/html
> 1234448443.926 13 10.10.1.35 TCP_MISS/304 392 GET
> http://film.onet.pl/zwiastuny/0 - DIRECT/213.180.130.201 image/gif
> 1234448443.938 109 10.10.2.250 TCP_MISS/200 11484 GET
> http://www.gazetaprawna.pl/serwisy/fundusze_unijne -
> DIRECT/193.164.157.253 text/html
> 1234448443.943 7 10.10.1.35 TCP_MISS/304 392 GET
> http://film.onet.pl/_g/_s/forum/abuse001.css - DIRECT/213.180.130.201
> text/css
>
> > Any additional
> > entries in the cache log?
>
> 2009/02/12 15:14:49| NOTICE: no explicit transparent proxy support
> enabled. Assuming getsockname() works on intercepted connections
> 2009/02/12 15:14:49| WARNING: Forwarding loop detected for:
> Client: 10.10.0.26 http_port: 10.10.0.26:3128
> GET
> http://10.10.0.26:3128/40E800104644424D5953464849455343475448506C000001BD66
>00000001760000003DEB000530BCC2C7CC HTTP/1.0
> Via: 1.0 ninja:3128 (squid/2.7.STABLE6)
> X-Forwarded-For: 10.10.2.191
> Host: 10.10.0.26:3128
> Cache-Control: max-age=259200
> Connection: keep-alive
>
>
> Hmmm... I didn't find such a records in cache.log before ("no explicit
> transparent proxy supported"). May be because I compiled squid with
> "--enable-linux-netfilter" that time. Anyway it worked the same way then.
>
>
> Thanks,
> Mike
Received on Fri Feb 13 2009 - 08:40:20 MST

This archive was generated by hypermail 2.2.0 : Fri Feb 13 2009 - 12:00:02 MST