[squid-users] problem fetching one specific website -> doesn't get added to cache

From: <tomvo@dont-contact.us>
Date: Tue, 25 Oct 2005 12:36:22 +0200

Hi,

my environment: 2 squid servers on RHEL3, version info:
[root@RHL3 log]# squid -v
Squid Cache: Version 2.5.STABLE3
configure options: --host=i386-redhat-linux --build=i386-redhat-linux
--target=i386-redhat-linux-gnu --program-prefix= --prefix=/usr
--exec-prefix=/usr --bindir=/usr/bin --sbindir=/usr/sbin --sysconfdir=/etc
--datadir=/usr/share --includedir=/usr/include --libdir=/usr/lib
--libexecdir=/usr/libexec --localstatedir=/var --sharedstatedir=/usr/com
--mandir=/usr/share/man --infodir=/usr/share/info --exec_prefix=/usr
--bindir=/usr/sbin --libexecdir=/usr/lib/squid --localstatedir=/var
--sysconfdir=/etc/squid --enable-poll --enable-snmp
--enable-removal-policies=heap,lru
--enable-storeio=aufs,coss,diskd,null,ufs --enable-ssl
--with-openssl=/usr/kerberos --enable-delay-pools --enable-linux-netfilter
--with-pthreads
--enable-basic-auth-helpers=LDAP,NCSA,PAM,SMB,SASL,MSNT,winbind
--enable-ntlm-auth-helpers=SMB,winbind,fakeauth
--enable-external-acl-helpers=ip_user,ldap_group,unix_group,wbinfo_group,winbind_group
--enable-auth=basic,ntlm --enable-useragent-log --enable-referer-log

Problem: we recently upgraded our firewall infrastructure, and we needed
to reconnect all our servers to the new firewall, the network layout
changed a bit (more subnetting involved).

since the upgrade (which went fine), a number of annoying squid problems
popped up:

 there is one web site that is inaccessible via the proxy. I tried with
squidclient and i get an alarm clock. however, when checking with tcpdump,
i see that thereis data transfer going on between squid and the webserver
in both directions (which clears firewall blocking issues)

the info from squidcilent:

[root@RHL3 log]# squidclient -h 193.110.158.162 -p 8080
http://www.e-line.be
HTTP/1.0 200 OK
Server: Microsoft-IIS/5.0
Date: Tue, 25 Oct 2005 10:15:42 GMT
X-Powered-By: ASP.NET
Content-Type: text/html
X-Powered-By: PHP/5.0.3
X-Cache: MISS from paulus.vera.be.158.110.193.in-addr.arpa
Proxy-Connection: close

Alarm clock

and at the same time the tcpdump (the above url get's translated via
reverse lookup and forward lookup to the url shown beneath):
[root@RHL3 root]# tcpdump -vvv -i eth0:0 host cust143-123.dsl.versadsl.be

12:15:41.144177 paulus.vera.be.158.110.193.in-addr.arpa.34508 >
cust143-123.dsl.versadsl.be.http: S [tcp sum ok] 2435788026:2435788026(0)
win 5440 <mss 1360,sackOK,timestamp 55585852 0,nop,wscale 0> (DF) (ttl 64,
id 198, len 60)
12:15:41.160365 cust143-123.dsl.versadsl.be.http >
paulus.vera.be.158.110.193.in-addr.arpa.34508: S [tcp sum ok]
3638739633:3638739633(0) ack 2435788027 win 17184 <mss 1432,nop,wscale
0,nop,nop,timestamp 0 0,nop,nop,sackOK> (DF) (ttl 116, id 35134, len 64)
12:15:41.160410 paulus.vera.be.158.110.193.in-addr.arpa.34508 >
cust143-123.dsl.versadsl.be.http: . [tcp sum ok] 1:1(0) ack 1 win 5440
<nop,nop,timestamp 55585854 0> (DF) (ttl 64, id 199, len 52)
12:15:41.162019 paulus.vera.be.158.110.193.in-addr.arpa.34508 >
cust143-123.dsl.versadsl.be.http: P 1:217(216) ack 1 win 5440
<nop,nop,timestamp 55585854 0> (DF) (ttl 64, id 200, len 268)
12:15:41.265355 cust143-123.dsl.versadsl.be.http >
paulus.vera.be.158.110.193.in-addr.arpa.34508: P 1:157(156) ack 217 win
16968 <nop,nop,timestamp 144916 55585854> (DF) (ttl 116, id 35135, len
208)
12:15:41.265387 paulus.vera.be.158.110.193.in-addr.arpa.34508 >
cust143-123.dsl.versadsl.be.http: . [tcp sum ok] 217:217(0) ack 157 win
5440 <nop,nop,timestamp 55585864 144916> (DF) (ttl 64, id 201, len 52)
12:15:41.304118 cust143-123.dsl.versadsl.be.http >
paulus.vera.be.158.110.193.in-addr.arpa.34508: P 1577:2153(576) ack 217
win 16968 <nop,nop,timestamp 144916 55585854> (DF) (ttl 116, id 35137, len
628)
12:15:41.304152 paulus.vera.be.158.110.193.in-addr.arpa.34508 >
cust143-123.dsl.versadsl.be.http: . [tcp sum ok] 217:217(0) ack 157 win
5440 <nop,nop,timestamp 55585868 144916,nop,nop,sack sack 1 {1577:2153} >
(DF) (ttl 64, id 202, len 64)
12:15:53.841199 cust143-123.dsl.versadsl.be.http >
paulus.vera.be.158.110.193.in-addr.arpa.34508: . [tcp sum ok]
1577:1589(12) ack 217 win 16968 <nop,nop,timestamp 145043 55585868> (DF)
(ttl 116, id 35169, len 64)
12:15:53.841221 paulus.vera.be.158.110.193.in-addr.arpa.34508 >
cust143-123.dsl.versadsl.be.http: . [tcp sum ok] 217:217(0) ack 157 win
5440 <nop,nop,timestamp 55587122 144916,nop,nop,sack sack 2
{1577:1589}{1577:2153} > (DF) (ttl 64, id 203, len 72)
12:16:08.928582 cust143-123.dsl.versadsl.be.http >
paulus.vera.be.158.110.193.in-addr.arpa.34508: . [tcp sum ok]
1577:1589(12) ack 217 win 16968 <nop,nop,timestamp 145194 55587122> (DF)
(ttl 116, id 35237, len 64)
12:16:08.928628 paulus.vera.be.158.110.193.in-addr.arpa.34508 >
cust143-123.dsl.versadsl.be.http: . [tcp sum ok] 217:217(0) ack 157 win
5440 <nop,nop,timestamp 55588630 144916,nop,nop,sack sack 2
{1577:1589}{1577:2153} > (DF) (ttl 64, id 204, len 72)
12:16:13.957510 cust143-123.dsl.versadsl.be.http >
paulus.vera.be.158.110.193.in-addr.arpa.34508: . [tcp sum ok]
3009:3021(12) ack 217 win 16968 <nop,nop,timestamp 145244 55588630> (DF)
(ttl 116, id 35281, len 64)
12:16:13.957554 paulus.vera.be.158.110.193.in-addr.arpa.34508 >
cust143-123.dsl.versadsl.be.http: . [tcp sum ok] 217:217(0) ack 157 win
5440 <nop,nop,timestamp 55589133 144916,nop,nop,sack sack 2
{3009:3021}{1577:2153} > (DF) (ttl 64, id 205, len 72)
12:16:18.986690 cust143-123.dsl.versadsl.be.http >
paulus.vera.be.158.110.193.in-addr.arpa.34508: . [tcp sum ok]
4441:4453(12) ack 217 win 16968 <nop,nop,timestamp 145294 55589133> (DF)
(ttl 116, id 35496, len 64)
12:16:18.986729 paulus.vera.be.158.110.193.in-addr.arpa.34508 >
cust143-123.dsl.versadsl.be.http: . [tcp sum ok] 217:217(0) ack 157 win
5440 <nop,nop,timestamp 55589636 144916,nop,nop,sack sack 3
{4441:4453}{3009:3021}{1577:2153} > (DF) (ttl 64, id 206, len 80)
12:16:29.045207 cust143-123.dsl.versadsl.be.http >
paulus.vera.be.158.110.193.in-addr.arpa.34508: . [tcp sum ok]
1577:1589(12) ack 217 win 16968 <nop,nop,timestamp 145395 55589636> (DF)
(ttl 116, id 35789, len 64)
12:16:29.045250 paulus.vera.be.158.110.193.in-addr.arpa.34508 >
cust143-123.dsl.versadsl.be.http: . [tcp sum ok] 217:217(0) ack 157 win
5440 <nop,nop,timestamp 55590642 144916,nop,nop,sack sack 3
{1577:1589}{1577:2153}{4441:4453} > (DF) (ttl 64, id 207, len 80)
12:16:34.074400 cust143-123.dsl.versadsl.be.http >
paulus.vera.be.158.110.193.in-addr.arpa.34508: . [tcp sum ok]
3009:3021(12) ack 217 win 16968 <nop,nop,timestamp 145445 55590642> (DF)
(ttl 116, id 35792, len 64)
12:16:34.074421 paulus.vera.be.158.110.193.in-addr.arpa.34508 >
cust143-123.dsl.versadsl.be.http: . [tcp sum ok] 217:217(0) ack 157 win
5440 <nop,nop,timestamp 55591145 144916,nop,nop,sack sack 3
{3009:3021}{3009:3021}{1577:2153} > (DF) (ttl 64, id 208, len 80)
12:16:39.102311 cust143-123.dsl.versadsl.be.http >
paulus.vera.be.158.110.193.in-addr.arpa.34508: . [tcp sum ok]
4441:4453(12) ack 217 win 16968 <nop,nop,timestamp 145495 55591145> (DF)
(ttl 116, id 35794, len 64)
12:16:39.102343 paulus.vera.be.158.110.193.in-addr.arpa.34508 >
cust143-123.dsl.versadsl.be.http: . [tcp sum ok] 217:217(0) ack 157 win
5440 <nop,nop,timestamp 55591648 144916,nop,nop,sack sack 3
{4441:4453}{4441:4453}{3009:3021} > (DF) (ttl 64, id 209, len 80)
12:16:44.154993 cust143-123.dsl.versadsl.be.http >
paulus.vera.be.158.110.193.in-addr.arpa.34508: . 4453:5597(1144) ack 217
win 16968 <nop,nop,timestamp 145546 55591648> (DF) (ttl 116, id 35831, len
1196)
12:16:44.155024 paulus.vera.be.158.110.193.in-addr.arpa.34508 >
cust143-123.dsl.versadsl.be.http: . [tcp sum ok] 217:217(0) ack 157 win
5440 <nop,nop,timestamp 55592153 144916,nop,nop,sack sack 2
{4441:5597}{3009:3021} > (DF) (ttl 64, id 210, len 72)
12:17:09.277128 cust143-123.dsl.versadsl.be.http >
paulus.vera.be.158.110.193.in-addr.arpa.34508: . [tcp sum ok]
1577:1589(12) ack 217 win 16968 <nop,nop,timestamp 145797 55592153> (DF)
(ttl 116, id 36801, len 64)
12:17:09.277200 paulus.vera.be.158.110.193.in-addr.arpa.34508 >
cust143-123.dsl.versadsl.be.http: . [tcp sum ok] 217:217(0) ack 157 win
5440 <nop,nop,timestamp 55594665 144916,nop,nop,sack sack 3
{1577:1589}{1577:2153}{4441:5597} > (DF) (ttl 64, id 211, len 80)
12:17:14.306324 cust143-123.dsl.versadsl.be.http >
paulus.vera.be.158.110.193.in-addr.arpa.34508: . [tcp sum ok]
3009:3021(12) ack 217 win 16968 <nop,nop,timestamp 145847 55594665> (DF)
(ttl 116, id 36805, len 64)
12:17:14.306356 paulus.vera.be.158.110.193.in-addr.arpa.34508 >
cust143-123.dsl.versadsl.be.http: . [tcp sum ok] 217:217(0) ack 157 win
5440 <nop,nop,timestamp 55595168 144916,nop,nop,sack sack 3
{3009:3021}{3009:3021}{1577:2153} > (DF) (ttl 64, id 212, len 80)
12:17:19.335665 cust143-123.dsl.versadsl.be.http >
paulus.vera.be.158.110.193.in-addr.arpa.34508: . [tcp sum ok]
4441:4453(12) ack 217 win 16968 <nop,nop,timestamp 145898 55595168> (DF)
(ttl 116, id 37152, len 64)
12:17:19.335693 paulus.vera.be.158.110.193.in-addr.arpa.34508 >
cust143-123.dsl.versadsl.be.http: . [tcp sum ok] 217:217(0) ack 157 win
5440 <nop,nop,timestamp 55595671 144916,nop,nop,sack sack 3
{4441:4453}{4441:5597}{3009:3021} > (DF) (ttl 64, id 213, len 80)
12:17:24.390019 cust143-123.dsl.versadsl.be.http >
paulus.vera.be.158.110.193.in-addr.arpa.34508: . 4453:5597(1144) ack 217
win 16968 <nop,nop,timestamp 145948 55595671> (DF) (ttl 116, id 37154, len
1196)
12:17:24.390063 paulus.vera.be.158.110.193.in-addr.arpa.34508 >
cust143-123.dsl.versadsl.be.http: . [tcp sum ok] 217:217(0) ack 157 win
5440 <nop,nop,timestamp 55596177 144916,nop,nop,sack sack 3
{4453:5597}{4441:5597}{3009:3021} > (DF) (ttl 64, id 214, len 80)
etcetera...

i noticed with ethereal a lot of Dup ACK's, does this mean anything to
anyone ??

 85.006079 193.110.158.162 -> 62.166.143.123 TCP [TCP Dup ACK 6#10] 47690
> http [ACK] Seq=217 Ack=157 Win=5440 Len=0 TSV=55692470 TSER=154729
SLE=1577 SRE=1589 SLE=1577 SRE=2153 SLE=4441 SRE=5597
 90.033967 62.166.143.123 -> 193.110.158.162 HTTP Continuation or non-HTTP
traffic
 90.033991 193.110.158.162 -> 62.166.143.123 TCP [TCP Dup ACK 6#11] 47690
> http [ACK] Seq=217 Ack=157 Win=5440 Len=0 TSV=55692973 TSER=154729
SLE=3009 SRE=3021 SLE=3009 SRE=3021 SLE=1577 SRE=2153
 95.063181 62.166.143.123 -> 193.110.158.162 HTTP Continuation or non-HTTP
traffic
 95.063221 193.110.158.162 -> 62.166.143.123 TCP [TCP Dup ACK 6#12] 47690
> http [ACK] Seq=217 Ack=157 Win=5440 Len=0 TSV=55693476 TSER=154729
SLE=4441 SRE=4453 SLE=4441 SRE=5597 SLE=3009 SRE=3021
100.114935 62.166.143.123 -> 193.110.158.162 HTTP Continuation or non-HTTP
traffic
100.114974 193.110.158.162 -> 62.166.143.123 TCP [TCP Dup ACK 6#13] 47690
> http [ACK] Seq=217 Ack=157 Win=5440 Len=0 TSV=55693981 TSER=154729
SLE=4453 SRE=5597 SLE=4441 SRE=5597 SLE=3009 SRE=3021

---------------------------------------------------------------------------
Tom Van Overbeke - ABSI Unix System Engineer
email: tomvo@absi.be
Tel: +32 2 333 40 00 - Fax: +32 2 332 34 69
website: http://www.absi.be
---------------------------------------------------------------------------
Received on Tue Oct 25 2005 - 04:36:26 MDT

This archive was generated by hypermail pre-2.1.9 : Tue Nov 01 2005 - 12:00:05 MST