[tproxy] Problem with options tproxy in squid 3.0

3 Oct 2009

      Hi,
I use Debian 5.0 with kernel 2.6.31  compiled with tproxy
 dmesg |grep TPROXY
NF_TPROXY: Transparent proxy support initialized, version 4.1.0
NF_TPROXY: Copyright (c) 2006-2007 BalaBit IT Ltd.

I downloaded ad installed iptables from git.balabit.hu/bazsi
(downloaded with command git clone
git://git.balabit.hu/bazsi/iptables-tproxy.git)

my iptables rules
iptables -t mangle -N DIVERT
iptables -t mangle -A DIVERT -j MARK --set-mark 1
iptables -t mangle -A DIVERT -j ACCEPT
iptables -t mangle -A PREROUTING -p tcp -m socket -j DIVERT
iptables -t mangle -A PREROUTING -p tcp --dport 80 -j TPROXY
--tproxy-mark 0x1/0x1 --on-ip 127.0.0.1 --on-port 3129

and

ip rule add fwmark 1 lookup 100
ip route add local 0.0.0.0/0 dev lo table 100

cd /proc/sys/net/bridge/
for i in *
do
  echo 0 > $i
done
unset i

ip ro flu ca

I use current squid (version squid-3.HEAD-20090929) with options
squid -v
Squid Cache: Version 3.HEAD-20090929
configure options:  '--build=i686-linux-gnu' '--prefix=/usr'
'--includedir=${prefix}/include' '--mandir=${prefix}/share/man'
'--infodir=${prefix}/share/info' '--sysconfdir=/etc'
'--localstatedir=/var' '--libexecdir=${prefix}/lib/squid3'
'--srcdir=.' '--datadir=/usr/share/squid3' '--sysconfdir=/etc/squid3'
'--mandir=/usr/share/man' '--enable-removal-policies=lru,heap'
'--enable-delay-pools' '--enable-cache-digests'
'--enable-follow-x-forwarded-for' '--enable-arp-acl' '--enable-snmp'
'--with-large-files' '--enable-kill-parent-hack'
'--enable-linux-netfilter'

I use squid.conf

########### Start of squid.conf ##############
cache_effective_user squid

http_port 3128
http_port 3129 tproxy

debug_options ALL,9

cache_dir ufs /data 50000 16 256

cache_access_log /var/log/squid/access.log
cache_log /var/log/squid3/cache.log
cache_store_log /var/log/squid/store.log

via off
forwarded_for off
cache_replacement_policy heap LFUDA
memory_replacement_policy heap GDSF
fqdncache_size 51200
ipcache_size 51200
pipeline_prefetch on

hierarchy_stoplist cgi-bin ?
acl QUERY urlpath_regex cgi-bin \?
no_cache deny QUERY

hosts_file /etc/hosts

refresh_pattern ^ftp: 1440 20% 10080
refresh_pattern ^gopher: 1440 0% 1440
refresh_pattern . 0 40% 4320

acl all src 0.0.0.0/0.0.0.0

##Define your network below

acl Customers src xxx.xxx.xxx.xx/32
acl manager proto cache_object
acl localhost src 127.0.0.1/32
acl to_localhost dst 127.0.0.0/8
acl purge method PURGE
acl CONNECT method CONNECT

acl Safe_ports port 80 # http
acl Safe_ports port 21 # ftp
acl Safe_ports port 443 # https

acl Safe_ports port 1025-65535 # ports

acl SSL_ports port 443 563

http_access allow manager localhost
http_access deny manager
http_access allow purge localhost
http_access deny purge
http_access deny !Safe_ports
http_access deny CONNECT !SSL_ports

http_access allow localhost
http_access allow Customers
http_access deny all
http_reply_access allow all
icp_access allow Customers

icp_access deny all

visible_hostname proxy

coredump_dir /usr/local/squid

######## End of squid.conf ##########

I can't open web page from client. I get error (example)
The following error was encountered while trying to retrieve the URL:
http://www.whatismyip.com/

Connection to 72.233.89.199 failed.

The system returned: (110) Connection timed out

The remote host or network may be down. Please try the request again.

in tcpdump (tcpdump -vvv -nne -i any port 80) i view more connections
from web server to my client ip :

01:33:57.220480 Out 00:06:5b:8d:2a:0a ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 64, id 674, offset 0, flags [DF], proto TCP (6),
length 60)
    xxx.xxx.xxx.xxx.55549 > 72.233.89.199.80: Flags [S], cksum 0xc77b
(correct), seq 3045315523, win 5840, options [mss 1460,sackOK,TS val
28960222 ecr 0,nop,wscale 6], length 0
01:33:57.220494 Out 00:06:5b:8d:2a:0a ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 64, id 674, offset 0, flags [DF], proto TCP (6),
length 60)
    xxx.xxx.xxx.xxx.55549 > 72.233.89.199.80: Flags [S], cksum 0xc77b
(correct), seq 3045315523, win 5840, options [mss 1460,sackOK,TS val
28960222 ecr 0,nop,wscale 6], length 0
01:34:02.313347   P 00:13:20:8a:da:6c ethertype IPv4 (0x0800), length
62: (tos 0x0, ttl 128, id 34224, offset 0, flags [DF], proto TCP (6),
length 40)
    xxx.xxx.xxx.xxx.1811 > 72.233.89.199.80: Flags [R.], cksum 0x0cac
(correct), seq 46900914, ack 2096256457, win 0, length 0
01:34:02.313436  In 00:13:20:8a:da:6c ethertype IPv4 (0x0800), length
62: (tos 0x0, ttl 128, id 34224, offset 0, flags [DF], proto TCP (6),
length 40)
    xxx.xxx.xxx.xxx.1811 > 72.233.89.199.80: Flags [R.], cksum 0x0cac
(correct), seq 0, ack 1, win 0, length 0
01:34:02.355379   P 00:13:20:8a:da:6c ethertype IPv4 (0x0800), length
64: (tos 0x0, ttl 128, id 34232, offset 0, flags [DF], proto TCP (6),
length 48)
    xxx.xxx.xxx.xxx.1812 > 72.233.89.199.80: Flags [S], cksum 0x668d
(correct), seq 1946517920, win 65535, options [mss
1460,nop,nop,sackOK], length 0
01:34:02.355466  In 00:13:20:8a:da:6c ethertype IPv4 (0x0800), length
64: (tos 0x0, ttl 128, id 34232, offset 0, flags [DF], proto TCP (6),
length 48)
    xxx.xxx.xxx.xxx.1812 > 72.233.89.199.80: Flags [S], cksum 0x668d
(correct), seq 1946517920, win 65535, options [mss
1460,nop,nop,sackOK], length 0
01:34:02.355562 Out 00:06:5b:8d:2a:0a ethertype IPv4 (0x0800), length
64: (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto TCP (6),
length 48)
    72.233.89.199.80 > xxx.xxx.xxx.xxx.1812: Flags [S.], cksum 0xb3f1
(correct), seq 3439185596, ack 1946517921, win 5840, options [mss
1460,nop,nop,sackOK], length 0
01:34:02.355568 Out 00:06:5b:8d:2a:0a ethertype IPv4 (0x0800), length
64: (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto TCP (6),
length 48)
    72.233.89.199.80 > xxx.xxx.xxx.xxx.1812: Flags [S.], cksum 0xb3f1
(correct), seq 3439185596, ack 1946517921, win 5840, options [mss
1460,nop,nop,sackOK], length 0
01:34:02.355788   P 00:13:20:8a:da:6c ethertype IPv4 (0x0800), length
62: (tos 0x0, ttl 128, id 34234, offset 0, flags [DF], proto TCP (6),
length 40)
    xxx.xxx.xxx.xxx.1812 > 72.233.89.199.80: Flags [.], cksum 0xf785
(correct), seq 1, ack 1, win 65535, length 0
01:34:02.355861  In 00:13:20:8a:da:6c ethertype IPv4 (0x0800), length
62: (tos 0x0, ttl 128, id 34234, offset 0, flags [DF], proto TCP (6),
length 40)
    xxx.xxx.xxx.xxx.1812 > 72.233.89.199.80: Flags [.], cksum 0xf785
(correct), seq 1, ack 1, win 65535, length 0
01:34:02.355955   P 00:13:20:8a:da:6c ethertype IPv4 (0x0800), length
1257: (tos 0x0, ttl 128, id 34235, offset 0, flags [DF], proto TCP
(6), length 1241)
    xxx.xxx.xxx.xxx.1812 > 72.233.89.199.80: Flags [P.], seq 1:1202,
ack 1, win 65535, length 1201
01:34:02.356066  In 00:13:20:8a:da:6c ethertype IPv4 (0x0800), length
1257: (tos 0x0, ttl 128, id 34235, offset 0, flags [DF], proto TCP
(6), length 1241)
    xxx.xxx.xxx.xxx.1812 > 72.233.89.199.80: Flags [P.], seq 1:1202,
ack 1, win 65535, length 1201
01:34:02.356166 Out 00:06:5b:8d:2a:0a ethertype IPv4 (0x0800), length
56: (tos 0x0, ttl 64, id 9311, offset 0, flags [DF], proto TCP (6),
length 40)
    72.233.89.199.80 > xxx.xxx.xxx.xxx.1812: Flags [.], cksum 0xd6ae
(correct), seq 1, ack 1202, win 7206, length 0
01:34:02.356173 Out 00:06:5b:8d:2a:0a ethertype IPv4 (0x0800), length
56: (tos 0x0, ttl 64, id 9311, offset 0, flags [DF], proto TCP (6),
length 40)
    72.233.89.199.80 > xxx.xxx.xxx.xxx.1812: Flags [.], cksum 0xd6ae
(correct), seq 1, ack 1202, win 7206, length 0
01:34:02.369890 Out 00:06:5b:8d:2a:0a ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 64, id 40495, offset 0, flags [DF], proto TCP (6),
length 60)
    xxx.xxx.xxx.xxx.58739 > 72.233.89.199.80: Flags [S], cksum 0xfd81
(correct), seq 3438900426, win 5840, options [mss 1460,sackOK,TS val
28961509 ecr 0,nop,wscale 6], length 0
01:34:02.369911 Out 00:06:5b:8d:2a:0a ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 64, id 40495, offset 0, flags [DF], proto TCP (6),
length 60)
    xxx.xxx.xxx.xxx.58739 > 72.233.89.199.80: Flags [S], cksum 0xfd81
(correct), seq 3438900426, win 5840, options [mss 1460,sackOK,TS val
28961509 ecr 0,nop,wscale 6], length 0
01:34:02.559422   P 00:11:20:1b:74:40 ethertype IPv4 (0x0800), length
80: (tos 0xb8, ttl 113, id 28699, offset 0, flags [none], proto TCP
(6), length 64)
    72.233.89.199.80 > xxx.xxx.xxx.xxx.58739: Flags [S.], cksum 0xe83f
(correct), seq 1205108507, ack 3438900427, win 16384, options [mss
1380,nop,wscale 0,nop,nop,TS val 0 ecr 0,nop,nop,sackOK], length 0
01:34:02.559430 Out 00:11:20:1b:74:40 ethertype IPv4 (0x0800), length
80: (tos 0xb8, ttl 113, id 28699, offset 0, flags [none], proto TCP
(6), length 64)
    72.233.89.199.80 > xxx.xxx.xxx.xxx.58739: Flags [S.], cksum 0xe83f
(correct), seq 1205108507, ack 3438900427, win 16384, options [mss
1380,nop,wscale 0,nop,nop,TS val 0 ecr 0,nop,nop,sackOK], length 0
01:34:05.368856 Out 00:06:5b:8d:2a:0a ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 64, id 40496, offset 0, flags [DF], proto TCP (6),
length 60)
    xxx.xxx.xxx.xxx.58739 > 72.233.89.199.80: Flags [S], cksum 0xfa93
(correct), seq 3438900426, win 5840, options [mss 1460,sackOK,TS val
28962259 ecr 0,nop,wscale 6], length 0
01:34:05.368866 Out 00:06:5b:8d:2a:0a ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 64, id 40496, offset 0, flags [DF], proto TCP (6),
length 60)
    xxx.xxx.xxx.xxx.58739 > 72.233.89.199.80: Flags [S], cksum 0xfa93
(correct), seq 3438900426, win 5840, options [mss 1460,sackOK,TS val
28962259 ecr 0,nop,wscale 6], length 0
01:34:05.923366   P 00:11:20:1b:74:40 ethertype IPv4 (0x0800), length
80: (tos 0xb8, ttl 113, id 29952, offset 0, flags [none], proto TCP
(6), length 64)
    72.233.89.199.80 > xxx.xxx.xxx.xxx.58739: Flags [S.], cksum 0xe83f
(correct), seq 1205108507, ack 3438900427, win 16384, options [mss
1380,nop,wscale 0,nop,nop,TS val 0 ecr 0,nop,nop,sackOK], length 0
01:34:05.923382 Out 00:11:20:1b:74:40 ethertype IPv4 (0x0800), length
80: (tos 0xb8, ttl 113, id 29952, offset 0, flags [none], proto TCP
(6), length 64)
    72.233.89.199.80 > xxx.xxx.xxx.xxx.58739: Flags [S.], cksum 0xe83f
(correct), seq 1205108507, ack 3438900427, win 16384, options [mss
1380,nop,wscale 0,nop,nop,TS val 0 ecr 0,nop,nop,sackOK], length 0
01:34:09.259233 Out 00:06:5b:8d:2a:0a ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 64, id 20218, offset 0, flags [DF], proto TCP (6),
length 60)
01:34:09.259253 Out 00:06:5b:8d:2a:0a ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 64, id 20218, offset 0, flags [DF], proto TCP (6),
length 60)
01:34:09.259802   P 00:11:20:1b:74:40 ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 59, id 0, offset 0, flags [DF], proto TCP (6),
length 60)
01:34:09.259819 Out 00:11:20:1b:74:40 ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 59, id 0, offset 0, flags [DF], proto TCP (6),
length 60)
01:34:11.369115 Out 00:06:5b:8d:2a:0a ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 64, id 40497, offset 0, flags [DF], proto TCP (6),
length 60)
    xxx.xxx.xxx.xxx.58739 > 72.233.89.199.80: Flags [S], cksum 0xf4b7
(correct), seq 3438900426, win 5840, options [mss 1460,sackOK,TS val
28963759 ecr 0,nop,wscale 6], length 0
01:34:11.369123 Out 00:06:5b:8d:2a:0a ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 64, id 40497, offset 0, flags [DF], proto TCP (6),
length 60)
    xxx.xxx.xxx.xxx.58739 > 72.233.89.199.80: Flags [S], cksum 0xf4b7
(correct), seq 3438900426, win 5840, options [mss 1460,sackOK,TS val
28963759 ecr 0,nop,wscale 6], length 0
01:34:12.257174 Out 00:06:5b:8d:2a:0a ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 64, id 20219, offset 0, flags [DF], proto TCP (6),
length 60)
01:34:12.257188 Out 00:06:5b:8d:2a:0a ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 64, id 20219, offset 0, flags [DF], proto TCP (6),
length 60)
01:34:12.257650   P 00:11:20:1b:74:40 ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 59, id 0, offset 0, flags [DF], proto TCP (6),
length 60)
01:34:12.257666 Out 00:11:20:1b:74:40 ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 59, id 0, offset 0, flags [DF], proto TCP (6),
length 60)
01:34:12.542042   P 00:11:20:1b:74:40 ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 59, id 0, offset 0, flags [DF], proto TCP (6),
length 60)
01:34:12.542050 Out 00:11:20:1b:74:40 ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 59, id 0, offset 0, flags [DF], proto TCP (6),
length 60)
01:34:12.594189   P 00:11:20:1b:74:40 ethertype IPv4 (0x0800), length
80: (tos 0xb8, ttl 113, id 199, offset 0, flags [none], proto TCP (6),
length 64)
    72.233.89.199.80 > xxx.xxx.xxx.xxx.58739: Flags [S.], cksum 0xe83f
(correct), seq 1205108507, ack 3438900427, win 16384, options [mss
1380,nop,wscale 0,nop,nop,TS val 0 ecr 0,nop,nop,sackOK], length 0
01:34:12.594196 Out 00:11:20:1b:74:40 ethertype IPv4 (0x0800), length
80: (tos 0xb8, ttl 113, id 199, offset 0, flags [none], proto TCP (6),
length 64)
    72.233.89.199.80 > xxx.xxx.xxx.xxx.58739: Flags [S.], cksum 0xe83f
(correct), seq 1205108507, ack 3438900427, win 16384, options [mss
1380,nop,wscale 0,nop,nop,TS val 0 ecr 0,nop,nop,sackOK], length 0
01:34:18.257459 Out 00:06:5b:8d:2a:0a ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 64, id 20220, offset 0, flags [DF], proto TCP (6),
length 60)
01:34:18.257471 Out 00:06:5b:8d:2a:0a ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 64, id 20220, offset 0, flags [DF], proto TCP (6),
length 60)
01:34:18.258049   P 00:11:20:1b:74:40 ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 59, id 0, offset 0, flags [DF], proto TCP (6),
length 60)
01:34:18.258061 Out 00:11:20:1b:74:40 ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 59, id 0, offset 0, flags [DF], proto TCP (6),
length 60)
01:34:18.513928   P 00:13:20:8a:da:6c ethertype IPv4 (0x0800), length
62: (tos 0x0, ttl 128, id 34291, offset 0, flags [DF], proto TCP (6),
length 40)
    xxx.xxx.xxx.xxx.1812 > 72.233.89.199.80: Flags [R.], cksum 0xf2d0
(correct), seq 1202, ack 1, win 0, length 0
01:34:18.514026  In 00:13:20:8a:da:6c ethertype IPv4 (0x0800), length
62: (tos 0x0, ttl 128, id 34291, offset 0, flags [DF], proto TCP (6),
length 40)
    xxx.xxx.xxx.xxx.1812 > 72.233.89.199.80: Flags [R.], cksum 0xf2d0
(correct), seq 1202, ack 1, win 0, length 0
01:34:18.543303   P 00:11:20:1b:74:40 ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 59, id 0, offset 0, flags [DF], proto TCP (6),
length 60)
01:34:18.543314 Out 00:11:20:1b:74:40 ethertype IPv4 (0x0800), length
76: (tos 0x0, ttl 59, id 0, offset 0, flags [DF], proto TCP (6),
length 60)
01:34:18.555887   P 00:13:20:8a:da:6c ethertype IPv4 (0x0800), length
64: (tos 0x0, ttl 128, id 34297, offset 0, flags [DF], proto TCP (6),
length 48)
    xxx.xxx.xxx.xxx.1813 > 72.233.89.199.80: Flags [S], cksum 0x0c36
(correct), seq 3900663676, win 65535, options [mss
1460,nop,nop,sackOK], length 0
01:34:18.555979  In 00:13:20:8a:da:6c ethertype IPv4 (0x0800), length
64: (tos 0x0, ttl 128, id 34297, offset 0, flags [DF], proto TCP (6),
length 48)
    xxx.xxx.xxx.xxx.1813 > 72.233.89.199.80: Flags [S], cksum 0x0c36
(correct), seq 3900663676, win 65535, options [mss
1460,nop,nop,sackOK], length 0
01:34:18.556085 Out 00:06:5b:8d:2a:0a ethertype IPv4 (0x0800), length
64: (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto TCP (6),
length 48)
    72.233.89.199.80 > xxx.xxx.xxx.xxx.1813: Flags [S.], cksum 0x455d
(correct), seq 3705262877, ack 3900663677, win 5840, options [mss
1460,nop,nop,sackOK], length 0
01:34:18.556091 Out 00:06:5b:8d:2a:0a ethertype IPv4 (0x0800), length
64: (tos 0x0, ttl 64, id 0, offset 0, flags [DF], proto TCP (6),
length 48)
    72.233.89.199.80 > xxx.xxx.xxx.xxx.1813: Flags [S.], cksum 0x455d
(correct), seq 3705262877, ack 3900663677, win 5840, options [mss
1460,nop,nop,sackOK], length 0

in squid log i see

2009/10/02 01:39:32.697| comm_select(): got FD 13 events=1
monitoring=19 F->read_handler=1 F->write_handler=0
2009/10/02 01:39:32.697| comm_select(): Calling read handler on FD 13
2009/10/02 01:39:32.697| fd_open() FD 15 HTTP Request
2009/10/02 01:39:32.697| AcceptFD::acceptOne accepted: FD 13 newfd: 15
from: xxx.xxx.xxx.xxx:1814 handler: SomeCommAcceptHandler(FD -1,
data=0x837b248
                              )
2009/10/02 01:39:32.697| comm.cc(2339) will call
SomeCommAcceptHandler(FD 13, data=0x837b248, newFD 15) [call833]
2009/10/02 01:39:32.697| entering SomeCommAcceptHandler(FD 13,
data=0x837b248, newFD 15)
2009/10/02 01:39:32.697| AsyncCall.cc(32) make: make call
SomeCommAcceptHandler [call833]
2009/10/02 01:39:32.697| cbdataReferenceValid: 0x837b248
2009/10/02 01:39:32.697| comm_accept: FD 13 handler: 0x80c5260
2009/10/02 01:39:32.697| cbdataLock: 0x837b248=2
2009/10/02 01:39:32.697| cbdataLock: 0x837b248=3
2009/10/02 01:39:32.697| The AsyncCall SomeCommAcceptHandler
constructed, this=0x84983c8 [call1294]
2009/10/02 01:39:32.697| cbdataLock: 0x837b248=4
2009/10/02 01:39:32.697| cbdataUnlock: 0x837b248=3
2009/10/02 01:39:32.697| cbdataUnlock: 0x837b248=2
2009/10/02 01:39:32.697| comm_old_accept: FD 13: (11) Resource
temporarily unavailable
2009/10/02 01:39:32.697| comm.cc(2304) acceptOne: try later: FD 13
handler: SomeCommAcceptHandler(FD -1, data=0x837b248)
2009/10/02 01:39:32.697| commSetSelect(FD
13,type=1,handler=1,client_data=0,timeout=0)
2009/10/02 01:39:32.697| httpAccept: FD 15: accepted
2009/10/02 01:39:32.697| AsyncJob of type ConnStateData constructed,
this=0x85f9e14 [async9]
2009/10/02 01:39:32.697| cbdataLock: 0x837b248=3
2009/10/02 01:39:32.698| IpIntercept.cc(381) NatLookup: address BEGIN:
me= 72.233.89.199:80, client= 72.233.89.199:80, dst=
xxx.xxx.xxx.xxx:1814, peer
                                          = xxx.xxx.xxx.xxx:1814
2009/10/02 01:39:32.698| IpIntercept.cc(166) NetfilterTransparent:
address TPROXY: me= 72.233.89.199:80, client= xxx.xxx.xxx.xxx
2009/10/02 01:39:32.698| cbdataLock: 0x85f9d00=1
2009/10/02 01:39:32.698| cbdataLock: 0x85f9d00=2
2009/10/02 01:39:32.698| cbdataLock: 0x85f9d00=3
2009/10/02 01:39:32.698| cbdataUnlock: 0x85f9d00=2
2009/10/02 01:39:32.698| The AsyncCall ConnStateData::connStateClosed
constructed, this=0x8498448 [call1295]
2009/10/02 01:39:32.698| cbdataReferenceValid: 0x85f9d00
2009/10/02 01:39:32.698| cbdataLock: 0x85f9d00=3
2009/10/02 01:39:32.698| cbdataLock: 0x85f9d00=4
2009/10/02 01:39:32.698| cbdataUnlock: 0x85f9d00=3
2009/10/02 01:39:32.698| cbdataUnlock: 0x85f9d00=2
2009/10/02 01:39:32.698| comm_add_close_handler: FD 15, AsyncCall=0x8498448*1
2009/10/02 01:39:32.698| cbdataLock: 0x85f9d00=3
2009/10/02 01:39:32.698| cbdataLock: 0x85f9d00=4
2009/10/02 01:39:32.698| cbdataLock: 0x85f9d00=5
2009/10/02 01:39:32.698| cbdataUnlock: 0x85f9d00=4
2009/10/02 01:39:32.698| The AsyncCall ConnStateData::requestTimeout
constructed, this=0x849ae88 [call1296]
2009/10/02 01:39:32.698| cbdataReferenceValid: 0x85f9d00
2009/10/02 01:39:32.698| cbdataLock: 0x85f9d00=5
2009/10/02 01:39:32.698| cbdataLock: 0x85f9d00=6
2009/10/02 01:39:32.698| cbdataUnlock: 0x85f9d00=5
2009/10/02 01:39:32.698| cbdataUnlock: 0x85f9d00=4
2009/10/02 01:39:32.698| comm.cc(1200) commSetTimeout: FD 15 timeout 900
2009/10/02 01:39:32.698| cbdataLock: 0x8372ca0=1
2009/10/02 01:39:32.698| aclCheckFast: list: 0x8372ca0
2009/10/02 01:39:32.698| ACLChecklist::preCheck: 0xbfaf6768 checking
'ident_lookup_access deny all'
2009/10/02 01:39:32.698| ACLList::matches: checking all
2009/10/02 01:39:32.698| ACL::checklistMatches: checking 'all'
2009/10/02 01:39:32.698| aclIpAddrNetworkCompare: compare:
xxx.xxx.xxx.xxx:1814/[::] ([::]:1814)  vs [::]-[::]/[::]
2009/10/02 01:39:32.698| aclIpMatchIp: 'xxx.xxx.xxx.xxx:1814' found
2009/10/02 01:39:32.699| ACL::ChecklistMatches: result for 'all' is 1
2009/10/02 01:39:32.699| ACLList::matches: result is true
2009/10/02 01:39:32.699| aclmatchAclList: 0xbfaf6768 returning true
(AND list satisfied)
2009/10/02 01:39:32.699| ACLChecklist::markFinished: 0xbfaf6768
checklist processing finished
2009/10/02 01:39:32.699| cbdataUnlock: 0x8372ca0=0
2009/10/02 01:39:32.699| FilledChecklist.cc(162) ~ACLFilledChecklist:
ACLFilledChecklist destroyed 0xbfaf6768
2009/10/02 01:39:32.699| ACLChecklist::~ACLChecklist: destroyed 0xbfaf6768
2009/10/02 01:39:32.699| clientReadSomeData: FD 15: reading request...
2009/10/02 01:39:32.699| cbdataLock: 0x85f9d00=5
2009/10/02 01:39:32.699| cbdataLock: 0x85f9d00=6
2009/10/02 01:39:32.699| cbdataLock: 0x85f9d00=7
2009/10/02 01:39:32.699| cbdataUnlock: 0x85f9d00=6
2009/10/02 01:39:32.699| The AsyncCall
ConnStateData::clientReadRequest constructed, this=0x849aed8
[call1297]
2009/10/02 01:39:32.699| cbdataReferenceValid: 0x85f9d00
2009/10/02 01:39:32.699| cbdataLock: 0x85f9d00=7
2009/10/02 01:39:32.699| cbdataLock: 0x85f9d00=8
2009/10/02 01:39:32.699| cbdataUnlock: 0x85f9d00=7
2009/10/02 01:39:32.699| cbdataUnlock: 0x85f9d00=6
2009/10/02 01:39:32.699| comm_read, queueing read for FD 15; asynCall
0x849aed8*1
2009/10/02 01:39:32.699| commSetSelect(FD
15,type=1,handler=1,client_data=0xb646f480,timeout=0)
2009/10/02 01:39:32.699| leaving SomeCommAcceptHandler(FD 13,
data=0x837b248, newFD 15)
2009/10/02 01:39:32.699| cbdataUnlock: 0x837b248=2
2009/10/02 01:39:32.699| Engine 0xbfaf6abc is idle.
2009/10/02 01:39:32.699| Engine 0xbfaf6ad8 is idle.
2009/10/02 01:39:32.699| comm_select(): got FD 15 events=1
monitoring=19 F->read_handler=1 F->write_handler=0
2009/10/02 01:39:32.699| comm_select(): Calling read handler on FD 15
2009/10/02 01:39:32.699| comm_read_try: FD 15, size 4095, retval 1201, errno 0
2009/10/02 01:39:32.699| commio_finish_callback: called for FD 15 (0, 0)
2009/10/02 01:39:32.699| comm.cc(163) will call
ConnStateData::clientReadRequest(FD 15, data=0x85f9d00, size=1201,
buf=0xb60a6008) [call1297]
2009/10/02 01:39:32.700| entering ConnStateData::clientReadRequest(FD
15, data=0x85f9d00, size=1201, buf=0xb60a6008)
2009/10/02 01:39:32.700| AsyncCall.cc(32) make: make call
ConnStateData::clientReadRequest [call1297]
2009/10/02 01:39:32.700| cbdataReferenceValid: 0x85f9d00
2009/10/02 01:39:32.700| cbdataReferenceValid: 0x85f9d00
2009/10/02 01:39:32.700| cbdataReferenceValid: 0x85f9d00
2009/10/02 01:39:32.700| ConnStateData status in: [ job9]
2009/10/02 01:39:32.700| client_side.cc(2639) clientReadRequest:
clientReadRequest FD 15 size 1201
2009/10/02 01:39:32.700| cbdataReferenceValid: 0x85f9d00
2009/10/02 01:39:32.700| clientParseRequest: FD 15: attempting to parse
2009/10/02 01:39:32.700| httpParseInit: Request buffer is GET / HTTP/1.0
Accept: image/gif, image/jpeg, image/pjpeg, image/pjpeg,
application/x-shockwave-flash, application/vnd.ms-excel,
application/vnd.ms-powerpoint, appli
                                                    cation/msword,
application/xaml+xml, application/vnd.ms-xpsdocument,
application/x-ms-xbap, application/x-ms-application, */*
Accept-Language: en-US,he;q=0.5
User-Agent: Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1;
Trident/4.0; MRA 5.0 (build 02094); GTB6; InfoPath.2; .NET CLR
2.0.50727; .NET CLR 3.0.
                                        04506.30; .NET CLR
3.0.04506.648; .NET CLR 3.5.21022; .NET CLR 3.0.4506.2152; .NET CLR
3.5.30729)
Host: www.whatismyip.com
Connection: Keep-Alive
Cookie: ASPSESSIONIDSSQDDATA=PPCHOFDBFDOPKKJJIKKFIFDG;
ASPSESSIONIDQSSCBBSA=AAANIGMANJIBGGHDLHHNGMKO;
ASPSESSIONIDCSCDSBAR=PHFOAMFCHFMJEGFMGABBECFP; A

SPSESSIONIDSSQDDBSB=INHCAHBCNHNABPKCHJJOILBD;
__utma=18138879.1116318747.1254271923.1254433161.1254437183.5;
__utmc=18138879; __utmz=18138879.12542719

24.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none);
ASPSESSIONIDQADQSQSB=CGOBLHJBDLGBEDFJPLDPBICH;
ASPSESSIONIDQSQBBCSA=GEOMCGHBCDEBCKEIKFIFNHJP; AS

PSESSIONIDSQRDBCSA=AKNELGBCJKPGMFAJFIIEPPPC;
ASPSESSIONIDQAARRTTA=MLNBPEBCCEEAGPKKIDPALNNF

2009/10/02 01:39:32.700| httpParserParseReqLine: parsing GET / HTTP/1.0
Accept: image/gif, image/jpeg, image/pjpeg, image/pjpeg,
application/x-shockwave-flash, application/vnd.ms-excel,
application/vnd.ms-powerpoint, appli
                                                    cation/msword,
application/xaml+xml, application/vnd.ms-xpsdocument,
application/x-ms-xbap, application/x-ms-application, */*
Accept-Language: en-US,he;q=0.5
User-Agent: Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1;
Trident/4.0; MRA 5.0 (build 02094); GTB6; InfoPath.2; .NET CLR
2.0.50727; .NET CLR 3.0.
                                        04506.30; .NET CLR
3.0.04506.648; .NET CLR 3.5.21022; .NET CLR 3.0.4506.2152; .NET CLR
3.5.30729)
Host: www.whatismyip.com
Connection: Keep-Alive
Cookie: ASPSESSIONIDSSQDDATA=PPCHOFDBFDOPKKJJIKKFIFDG;
ASPSESSIONIDQSSCBBSA=AAANIGMANJIBGGHDLHHNGMKO;
ASPSESSIONIDCSCDSBAR=PHFOAMFCHFMJEGFMGABBECFP; A

SPSESSIONIDSSQDDBSB=INHCAHBCNHNABPKCHJJOILBD;
__utma=18138879.1116318747.1254271923.1254433161.1254437183.5;
__utmc=18138879; __utmz=18138879.12542719

24.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none);
ASPSESSIONIDQADQSQSB=CGOBLHJBDLGBEDFJPLDPBICH;
ASPSESSIONIDQSQBBCSA=GEOMCGHBCDEBCKEIKFIFNHJP; AS

PSESSIONIDSQRDBCSA=AKNELGBCJKPGMFAJFIIEPPPC;
ASPSESSIONIDQAARRTTA=MLNBPEBCCEEAGPKKIDPALNNF

2009/10/02 01:39:32.700| Parser: retval 1: from 0->15: method 0->2;
url 4->4; version 6->14 (1/1)
2009/10/02 01:39:32.700| parseHttpRequest: req_hdr = {Accept:
image/gif, image/jpeg, image/pjpeg, image/pjpeg,
application/x-shockwave-flash, applicat

ion/vnd.ms-excel, application/vnd.ms-powerpoint, application/msword,
application/xaml+xml, application/vnd.ms-xpsdocument,
application/x-ms-xbap, appl
                                           ication/x-ms-application,
*/*
Accept-Language: en-US,he;q=0.5
User-Agent: Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1;
Trident/4.0; MRA 5.0 (build 02094); GTB6; InfoPath.2; .NET CLR
2.0.50727; .NET CLR 3.0.
                                        04506.30; .NET CLR
3.0.04506.648; .NET CLR 3.5.21022; .NET CLR 3.0.4506.2152; .NET CLR
3.5.30729)
Accept-Encoding: gzip, deflate
Host: www.whatismyip.com
Connection: Keep-Alive
Cookie: ASPSESSIONIDSSQDDATA=PPCHOFDBFDOPKKJJIKKFIFDG;
ASPSESSIONIDQSSCBBSA=AAANIGMANJIBGGHDLHHNGMKO;
ASPSESSIONIDCSCDSBAR=PHFOAMFCHFMJEGFMGABBECFP; A

SPSESSIONIDSSQDDBSB=INHCAHBCNHNABPKCHJJOILBD;
__utma=18138879.1116318747.1254271923.1254433161.1254437183.5;
__utmc=18138879; __utmz=18138879.12542719

24.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none);
ASPSESSIONIDQADQSQSB=CGOBLHJBDLGBEDFJPLDPBICH;
ASPSESSIONIDQSQBBCSA=GEOMCGHBCDEBCKEIKFIFNHJP; AS

PSESSIONIDSQRDBCSA=AKNELGBCJKPGMFAJFIIEPPPC;
ASPSESSIONIDQAARRTTA=MLNBPEBCCEEAGPKKIDPALNNF

}
2009/10/02 01:39:32.700| parseHttpRequest: end = {
}
2009/10/02 01:39:32.700| parseHttpRequest: prefix_sz = 1201, req_line_sz = 16
2009/10/02 01:39:32.700| cbdataLock: 0x85f9d00=7
2009/10/02 01:39:32.700| cbdataLock: 0x86023b0=1
2009/10/02 01:39:32.700| cbdataLock: 0x860a3c8=1
2009/10/02 01:39:32.700| clientStreamInsertHead: Inserted node
0x860a410 with data 0xb60440a8 after head
2009/10/02 01:39:32.700| cbdataLock: 0x860a410=1
2009/10/02 01:39:32.700| parseHttpRequest: Request Header is
Accept: image/gif, image/jpeg, image/pjpeg, image/pjpeg,
application/x-shockwave-flash, application/vnd.ms-excel,
application/vnd.ms-powerpoint, appli
                                                    cation/msword,
application/xaml+xml, application/vnd.ms-xpsdocument,
application/x-ms-xbap, application/x-ms-application, */*
Accept-Language: en-US,he;q=0.5
User-Agent: Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1;
Trident/4.0; MRA 5.0 (build 02094); GTB6; InfoPath.2; .NET CLR
2.0.50727; .NET CLR 3.0.
                                        04506.30; .NET CLR
3.0.04506.648; .NET CLR 3.5.21022; .NET CLR 3.0.4506.2152; .NET CLR
3.5.30729)
Accept-Encoding: gzip, deflate
Host: www.whatismyip.com
Connection: Keep-Alive
Cookie: ASPSESSIONIDSSQDDATA=PPCHOFDBFDOPKKJJIKKFIFDG;
ASPSESSIONIDQSSCBBSA=AAANIGMANJIBGGHDLHHNGMKO;
ASPSESSIONIDCSCDSBAR=PHFOAMFCHFMJEGFMGABBECFP; A

SPSESSIONIDSSQDDBSB=INHCAHBCNHNABPKCHJJOILBD;
__utma=18138879.1116318747.1254271923.1254433161.1254437183.5;
__utmc=18138879; __utmz=18138879.12542719

24.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none);
ASPSESSIONIDQADQSQSB=CGOBLHJBDLGBEDFJPLDPBICH;
ASPSESSIONIDQSQBBCSA=GEOMCGHBCDEBCKEIKFIFNHJP; AS

PSESSIONIDSQRDBCSA=AKNELGBCJKPGMFAJFIIEPPPC;
ASPSESSIONIDQAARRTTA=MLNBPEBCCEEAGPKKIDPALNNF

2009/10/02 01:39:32.700| mime_get_header: looking for 'Host'
2009/10/02 01:39:32.700| mime_get_header: checking 'Host: www.whatismyip.com'
2009/10/02 01:39:32.700| mime_get_header: returning 'www.whatismyip.com'
2009/10/02 01:39:32.700| TRANSPARENT HOST REWRITE: 'http://www.whatismyip.com/'
2009/10/02 01:39:32.700| parseHttpRequest: Complete request received
2009/10/02 01:39:32.700| clientParseRequest: FD 15: parsed a request
2009/10/02 01:39:32.700| comm.cc(1189) commSetTimeout: FD 15 timeout 86400
2009/10/02 01:39:32.701| cbdataLock: 0x86023b0=2
2009/10/02 01:39:32.701| cbdataLock: 0x86023b0=3
2009/10/02 01:39:32.701| The AsyncCall SomeTimeoutHandler constructed,
this=0x84aaf90 [call1298]
2009/10/02 01:39:32.701| cbdataLock: 0x86023b0=4
2009/10/02 01:39:32.701| cbdataUnlock: 0x86023b0=3
2009/10/02 01:39:32.701| cbdataUnlock: 0x86023b0=2
2009/10/02 01:39:32.701| comm.cc(1200) commSetTimeout: FD 15 timeout 86400
2009/10/02 01:39:32.701| cbdataUnlock: 0x85f9d00=6
2009/10/02 01:39:32.701| cbdataUnlock: 0x85f9d00=5
2009/10/02 01:39:32.701| cbdataReferenceValid: 0x85f9d00
2009/10/02 01:39:32.701| cbdataReferenceValid: 0x85f9d00
2009/10/02 01:39:32.701| urlParse: Split URL
'http://www.whatismyip.com/' into proto='http',
host='www.whatismyip.com', port='80', path='/'
2009/10/02 01:39:32.701| init-ing hdr: 0x85cc1b4 owner: 2
2009/10/02 01:39:32.701| parsing hdr: (0x85cc1b4)
Accept: image/gif, image/jpeg, image/pjpeg, image/pjpeg,
application/x-shockwave-flash, application/vnd.ms-excel,
application/vnd.ms-powerpoint, appli
                                                    cation/msword,
application/xaml+xml, application/vnd.ms-xpsdocument,
application/x-ms-xbap, application/x-ms-application, */*
Accept-Language: en-US,he;q=0.5
User-Agent: Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1;
Trident/4.0; MRA 5.0 (build 02094); GTB6; InfoPath.2; .NET CLR
2.0.50727; .NET CLR 3.0.
                                        04506.30; .NET CLR
3.0.04506.648; .NET CLR 3.5.2102
2009/10/02 01:39:32.701| parsing HttpHeaderEntry: near 'Accept:
image/gif, image/jpeg, image/pjpeg, image/pjpeg,
application/x-shockwave-flash, applic

ation/vnd.ms-excel, application/vnd.ms-powerpoint, application/msword,
application/xaml+xml, application/vnd.ms-xpsdocument,
application/x-ms-xbap, ap
                                         plication/x-ms-application,
*/*'
2009/10/02 01:39:32.701| parsed HttpHeaderEntry: 'Accept: image/gif,
image/jpeg, image/pjpeg, image/pjpeg, application/x-shockwave-flash,
application/
                            vnd.ms-excel,
application/vnd.ms-powerpoint, application/msword,
application/xaml+xml, application/vnd.ms-xpsdocument,
application/x-ms-xbap, applicat
                                               ion/x-ms-application,
*/*'
2009/10/02 01:39:32.701| created HttpHeaderEntry 0x85daf48: 'Accept :
image/gif, image/jpeg, image/pjpeg, image/pjpeg,
application/x-shockwave-flash,

application/vnd.ms-excel, application/vnd.ms-powerpoint,
application/msword, application/xaml+xml,
application/vnd.ms-xpsdocument, application/x-ms-xb
                                                                   ap,
application/x-ms-application, */*
2009/10/02 01:39:32.701| 0x85cc1b4 adding entry: 0 at 0
2009/10/02 01:39:32.701| parsing HttpHeaderEntry: near
'Accept-Language: en-US,he;q=0.5'
2009/10/02 01:39:32.701| parsed HttpHeaderEntry: 'Accept-Language:
en-US,he;q=0.5'
2009/10/02 01:39:32.701| created HttpHeaderEntry 0x85daf64:
'Accept-Language : en-US,he;q=0.5
2009/10/02 01:39:32.701| 0x85cc1b4 adding entry: 3 at 1
2009/10/02 01:39:32.701| parsing HttpHeaderEntry: near 'User-Agent:
Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; MRA
5.0 (build 020
                              94); GTB6; InfoPath.2; .NET CLR
2.0.50727; .NET CLR 3.0.04506.30; .NET CLR 3.0.04506.648; .NET CLR
3.5.21022; .NET CLR 3.0.4506.2152; .NET CLR 3.5.307

29)'
2009/10/02 01:39:32.701| parsed HttpHeaderEntry: 'User-Agent:
Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1; Trident/4.0; MRA
5.0 (build 02094); G
                                    TB6; InfoPath.2; .NET CLR
2.0.50727; .NET CLR 3.0.04506.30; .NET CLR 3.0.04506.648; .NET CLR
3.5.21022; .NET CLR 3.0.4506.2152; .NET CLR 3.5.30729)'
2009/10/02 01:39:32.701| created HttpHeaderEntry 0x85daf80:
'User-Agent : Mozilla/4.0 (compatible; MSIE 8.0; Windows NT 5.1;
Trident/4.0; MRA 5.0 (bui
                                         ld 02094); GTB6; InfoPath.2;
.NET CLR 2.0.50727; .NET CLR 3.0.04506.30; .NET CLR 3.0.04506.648;
.NET CLR 3.5.21022; .NET CLR 3.0.4506.2152; .NET CLR 3

.5.30729)
2009/10/02 01:39:32.701| 0x85cc1b4 adding entry: 55 at 2
2009/10/02 01:39:32.702| parsing HttpHeaderEntry: near
'Accept-Encoding: gzip, deflate'
2009/10/02 01:39:32.702| parsed HttpHeaderEntry: 'Accept-Encoding:
gzip, deflate'
2009/10/02 01:39:32.702| created HttpHeaderEntry 0x85daf9c:
'Accept-Encoding : gzip, deflate
2009/10/02 01:39:32.702| 0x85cc1b4 adding entry: 2 at 3
2009/10/02 01:39:32.702| parsing HttpHeaderEntry: near 'Host:
www.whatismyip.com'
2009/10/02 01:39:32.702| parsed HttpHeaderEntry: 'Host: www.whatismyip.com'
2009/10/02 01:39:32.702| created HttpHeaderEntry 0x85dafb8: 'Host :
www.whatismyip.com
2009/10/02 01:39:32.702| 0x85cc1b4 adding entry: 24 at 4
2009/10/02 01:39:32.702| parsing HttpHeaderEntry: near 'Connection: Keep-Alive'
2009/10/02 01:39:32.702| parsed HttpHeaderEntry: 'Connection: Keep-Alive'
2009/10/02 01:39:32.702| created HttpHeaderEntry 0x85dafd4:
'Connection : Keep-Alive
2009/10/02 01:39:32.702| 0x85cc1b4 adding entry: 9 at 5
2009/10/02 01:39:32.702| parsing HttpHeaderEntry: near 'Cookie:
ASPSESSIONIDSSQDDATA=PPCHOFDBFDOPKKJJIKKFIFDG;
ASPSESSIONIDQSSCBBSA=AAANIGMANJIBGGHDLH
                                                       HNGMKO;
ASPSESSIONIDCSCDSBAR=PHFOAMFCHFMJEGFMGABBECFP;
ASPSESSIONIDSSQDDBSB=INHCAHBCNHNABPKCHJJOILBD;
__utma=18138879.1116318747.1254271923.1254433161

.1254437183.5; __utmc=18138879;
__utmz=18138879.1254271924.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none);
ASPSESSIONIDQADQSQSB=CGOBLHJBDLGBEDFJPLD
                                                        PBICH;
ASPSESSIONIDQSQBBCSA=GEOMCGHBCDEBCKEIKFIFNHJP;
ASPSESSIONIDSQRDBCSA=AKNELGBCJKPGMFAJFIIEPPPC; ASPSESSIONIDQAAR'
2009/10/02 01:39:32.702| parsed HttpHeaderEntry: 'Cookie:
ASPSESSIONIDSSQDDATA=PPCHOFDBFDOPKKJJIKKFIFDG;
ASPSESSIONIDQSSCBBSA=AAANIGMANJIBGGHDLHHNGMKO
                                                             ;
ASPSESSIONIDCSCDSBAR=PHFOAMFCHFMJEGFMGABBECFP;
ASPSESSIONIDSSQDDBSB=INHCAHBCNHNABPKCHJJOILBD;
__utma=18138879.1116318747.1254271923.1254433161.12544

37183.5; __utmc=18138879;
__utmz=18138879.1254271924.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none);
ASPSESSIONIDQADQSQSB=CGOBLHJBDLGBEDFJPLDPBICH;

ASPSESSIONIDQSQBBCSA=GEOMCGHBCDEBCKEIKFIFNHJP;
ASPSESSIONIDSQRDBCSA=AKNELGBCJKPGMFAJFIIEPPPC;
ASPSESSIONIDQAARRTTA=MLNBPEBCCEEAGPKKIDPALNNF'
2009/10/02 01:39:32.702| created HttpHeaderEntry 0x85daff0: 'Cookie :
ASPSESSIONIDSSQDDATA=PPCHOFDBFDOPKKJJIKKFIFDG;
ASPSESSIONIDQSSCBBSA=AAANIGMANJIB
                                                 GGHDLHHNGMKO;
ASPSESSIONIDCSCDSBAR=PHFOAMFCHFMJEGFMGABBECFP;
ASPSESSIONIDSSQDDBSB=INHCAHBCNHNABPKCHJJOILBD;
__utma=18138879.1116318747.1254271923.1254

433161.1254437183.5; __utmc=18138879;
__utmz=18138879.1254271924.1.1.utmcsr=(direct)|utmccn=(direct)|utmcmd=(none);
ASPSESSIONIDQADQSQSB=CGOBLHJBDLGBE
                                                  DFJPLDPBICH;
ASPSESSIONIDQSQBBCSA=GEOMCGHBCDEBCKEIKFIFNHJP;
ASPSESSIONIDSQRDBCSA=AKNELGBCJKPGMFAJFIIEPPPC;
ASPSESSIONIDQAARRTTA=MLNBPEBCCEEAGPKKIDPALN
                                                           NF
2009/10/02 01:39:32.702| 0x85cc1b4 adding entry: 19 at 6
2009/10/02 01:39:32.702| 0x85cc1b4 lookup for 51
2009/10/02 01:39:32.702| clientSetKeepaliveFlag: http_ver = 1.1
2009/10/02 01:39:32.702| clientSetKeepaliveFlag: method = GET
2009/10/02 01:39:32.702| 0x85cc1b4 lookup for 57
2009/10/02 01:39:32.702| 0x85cc1b4 lookup for 39
2009/10/02 01:39:32.702| 0x85cc1b4 lookup for 9
2009/10/02 01:39:32.702| 0x85cc1b4joining for id 9
2009/10/02 01:39:32.702| 0x85cc1b4: joined for id 9: Keep-Alive
2009/10/02 01:39:32.702| cbdataLock: 0x86023b0=3
2009/10/02 01:39:32.702| client_side_request.cc(136)
ClientRequestContext: 0x86124f8 ClientRequestContext constructed
2009/10/02 01:39:32.702| client_side_request.cc(1258) doCallouts:
Doing calloutContext->clientAccessCheck()
2009/10/02 01:39:32.702| 0x85cc1b4 lookup for 63
2009/10/02 01:39:32.702| cbdataReferenceValid: 0x85f9d00
2009/10/02 01:39:32.702| cbdataReferenceValid: 0x85f9d00
2009/10/02 01:39:32.702| cbdataLock: 0x8372e80=1
2009/10/02 01:39:32.703| cbdataLock: 0x85f9d00=6
2009/10/02 01:39:32.703| cbdataLock: 0x86124f8=1
2009/10/02 01:39:32.703| cbdataReferenceValid: 0x86124f8
2009/10/02 01:39:32.703| cbdataReferenceValid: 0x8372e80
2009/10/02 01:39:32.703| ACLChecklist::preCheck: 0x86165b8 checking
'http_access allow manager localhost'
2009/10/02 01:39:32.703| ACLList::matches: checking manager
2009/10/02 01:39:32.703| ACL::checklistMatches: checking 'manager'
2009/10/02 01:39:32.703| ACL::ChecklistMatches: result for 'manager' is 0
2009/10/02 01:39:32.703| ACLList::matches: result is false
2009/10/02 01:39:32.703| aclmatchAclList: 0x86165b8 returning false
(AND list entry failed to match)
2009/10/02 01:39:32.703| aclmatchAclList: async=0 nodeMatched=0
async_in_progress=0 lastACLResult() = 0 finished() = 0
2009/10/02 01:39:32.703| cbdataLock: 0x8372c60=1
2009/10/02 01:39:32.703| cbdataUnlock: 0x8372e80=0
2009/10/02 01:39:32.703| cbdataReferenceValid: 0x8372c60
2009/10/02 01:39:32.703| ACLChecklist::preCheck: 0x86165b8 checking
'http_access deny manager'
2009/10/02 01:39:32.703| ACLList::matches: checking manager
2009/10/02 01:39:32.703| ACL::checklistMatches: checking 'manager'
2009/10/02 01:39:32.703| ACL::ChecklistMatches: result for 'manager' is 0
2009/10/02 01:39:32.703| ACLList::matches: result is false
2009/10/02 01:39:32.703| aclmatchAclList: 0x86165b8 returning false
(AND list entry failed to match)
2009/10/02 01:39:32.703| aclmatchAclList: async=0 nodeMatched=0
async_in_progress=0 lastACLResult() = 0 finished() = 0
2009/10/02 01:39:32.703| cbdataLock: 0x8372e60=1
2009/10/02 01:39:32.703| cbdataUnlock: 0x8372c60=0
2009/10/02 01:39:32.703| cbdataReferenceValid: 0x8372e60
2009/10/02 01:39:32.703| ACLChecklist::preCheck: 0x86165b8 checking
'http_access allow purge localhost'
2009/10/02 01:39:32.703| ACLList::matches: checking purge
2009/10/02 01:39:32.703| ACL::checklistMatches: checking 'purge'
2009/10/02 01:39:32.703| ACL::ChecklistMatches: result for 'purge' is 0
2009/10/02 01:39:32.703| ACLList::matches: result is false
2009/10/02 01:39:32.703| aclmatchAclList: 0x86165b8 returning false
(AND list entry failed to match)
2009/10/02 01:39:32.703| aclmatchAclList: async=0 nodeMatched=0
async_in_progress=0 lastACLResult() = 0 finished() = 0
2009/10/02 01:39:32.703| cbdataLock: 0x8372e40=1
2009/10/02 01:39:32.704| cbdataUnlock: 0x8372e60=0
2009/10/02 01:39:32.704| cbdataReferenceValid: 0x8372e40
2009/10/02 01:39:32.704| ACLChecklist::preCheck: 0x86165b8 checking
'http_access deny purge'
2009/10/02 01:39:32.704| ACLList::matches: checking purge
2009/10/02 01:39:32.704| ACL::checklistMatches: checking 'purge'
2009/10/02 01:39:32.704| ACL::ChecklistMatches: result for 'purge' is 0
2009/10/02 01:39:32.704| ACLList::matches: result is false
2009/10/02 01:39:32.704| aclmatchAclList: 0x86165b8 returning false
(AND list entry failed to match)
2009/10/02 01:39:32.704| aclmatchAclList: async=0 nodeMatched=0
async_in_progress=0 lastACLResult() = 0 finished() = 0
2009/10/02 01:39:32.704| cbdataLock: 0x8372e00=1
2009/10/02 01:39:32.704| cbdataUnlock: 0x8372e40=0
2009/10/02 01:39:32.704| cbdataReferenceValid: 0x8372e00
2009/10/02 01:39:32.704| ACLChecklist::preCheck: 0x86165b8 checking
'http_access deny !Safe_ports'
2009/10/02 01:39:32.704| ACLList::matches: checking !Safe_ports
2009/10/02 01:39:32.704| ACL::checklistMatches: checking 'Safe_ports'
2009/10/02 01:39:32.704| ACL::ChecklistMatches: result for 'Safe_ports' is 1
2009/10/02 01:39:32.704| ACLList::matches: result is false
2009/10/02 01:39:32.704| aclmatchAclList: 0x86165b8 returning false
(AND list entry failed to match)
2009/10/02 01:39:32.704| aclmatchAclList: async=0 nodeMatched=0
async_in_progress=0 lastACLResult() = 0 finished() = 0
2009/10/02 01:39:32.704| cbdataLock: 0x8372de0=1
2009/10/02 01:39:32.704| cbdataUnlock: 0x8372e00=0
2009/10/02 01:39:32.704| cbdataReferenceValid: 0x8372de0
2009/10/02 01:39:32.704| ACLChecklist::preCheck: 0x86165b8 checking
'http_access deny CONNECT !SSL_ports'
2009/10/02 01:39:32.704| ACLList::matches: checking CONNECT
2009/10/02 01:39:32.704| ACL::checklistMatches: checking 'CONNECT'
2009/10/02 01:39:32.704| ACL::ChecklistMatches: result for 'CONNECT' is 0
2009/10/02 01:39:32.704| ACLList::matches: result is false
2009/10/02 01:39:32.704| aclmatchAclList: 0x86165b8 returning false
(AND list entry failed to match)
2009/10/02 01:39:32.704| aclmatchAclList: async=0 nodeMatched=0
async_in_progress=0 lastACLResult() = 0 finished() = 0
2009/10/02 01:39:32.704| cbdataLock: 0x8372dc0=1
2009/10/02 01:39:32.704| cbdataUnlock: 0x8372de0=0
2009/10/02 01:39:32.704| cbdataReferenceValid: 0x8372dc0
2009/10/02 01:39:32.704| ACLChecklist::preCheck: 0x86165b8 checking
'http_access allow localhost'
2009/10/02 01:39:32.705| ACLList::matches: checking localhost
2009/10/02 01:39:32.705| ACL::checklistMatches: checking 'localhost'
2009/10/02 01:39:32.705| aclIpAddrNetworkCompare: compare:
xxx.xxx.xxx.xxx/[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff]
(xxx.xxx.xxx.xxx)  vs 127.0.0.1-[

::]/[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff]
2009/10/02 01:39:32.705| aclIpMatchIp: 'xxx.xxx.xxx.xxx' NOT found
2009/10/02 01:39:32.705| ACL::ChecklistMatches: result for 'localhost' is 0
2009/10/02 01:39:32.705| ACLList::matches: result is false
2009/10/02 01:39:32.705| aclmatchAclList: 0x86165b8 returning false
(AND list entry failed to match)
2009/10/02 01:39:32.705| aclmatchAclList: async=0 nodeMatched=0
async_in_progress=0 lastACLResult() = 0 finished() = 0
2009/10/02 01:39:32.705| cbdataLock: 0x8372da0=1
2009/10/02 01:39:32.705| cbdataUnlock: 0x8372dc0=0
2009/10/02 01:39:32.705| cbdataReferenceValid: 0x8372da0
2009/10/02 01:39:32.705| ACLChecklist::preCheck: 0x86165b8 checking
'http_access allow Customers'
2009/10/02 01:39:32.705| ACLList::matches: checking Customers
2009/10/02 01:39:32.705| ACL::checklistMatches: checking 'Customers'
2009/10/02 01:39:32.705| aclIpAddrNetworkCompare: compare:
xxx.xxx.xxx.xxx/[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff]
(xxx.xxx.xxx.xxx)  vs 192.115.188

.100-[::]/[ffff:ffff:ffff:ffff:ffff:ffff:ffff:ffff]
2009/10/02 01:39:32.705| aclIpMatchIp: 'xxx.xxx.xxx.xxx' found
2009/10/02 01:39:32.705| ACL::ChecklistMatches: result for 'Customers' is 1
2009/10/02 01:39:32.705| ACLList::matches: result is true
2009/10/02 01:39:32.705| aclmatchAclList: 0x86165b8 returning true
(AND list satisfied)
2009/10/02 01:39:32.705| ACLChecklist::markFinished: 0x86165b8
checklist processing finished
2009/10/02 01:39:32.705| ACLChecklist::check: 0x86165b8 match found,
calling back with 1
2009/10/02 01:39:32.705| cbdataUnlock: 0x8372da0=0
2009/10/02 01:39:32.705| ACLFilledChecklist::checkCallback: 0x86165b8 answer=1
2009/10/02 01:39:32.705| ACLChecklist::checkCallback: 0x86165b8 answer=1
2009/10/02 01:39:32.705| cbdataReferenceValid: 0x86124f8
2009/10/02 01:39:32.705| cbdataUnlock: 0x86124f8=0
2009/10/02 01:39:32.705| cbdataReferenceValid: 0x86023b0
2009/10/02 01:39:32.705| The request GET http://www.whatismyip.com/ is
ALLOWED, because it matched 'Customers'
2009/10/02 01:39:32.705| cbdataReferenceValid: 0x85f9d00
2009/10/02 01:39:32.705| cbdataReferenceValid: 0x85f9d00
2009/10/02 01:39:32.705| client_side_request.cc(1287) doCallouts:
Doing clientInterpretRequestHeaders()
2009/10/02 01:39:32.706| 0x85cc1b4 lookup for 35
2009/10/02 01:39:32.706| 0x85cc1b4 lookup for 7
2009/10/02 01:39:32.706| cbdataReferenceValid: 0x85f9d00
2009/10/02 01:39:32.706| 0x85cc1b4 lookup for 7
2009/10/02 01:39:32.706| 0x85cc1b4 lookup for 38
2009/10/02 01:39:32.706| 0x85cc1b4 lookup for 57
2009/10/02 01:39:32.706| clientInterpretRequestHeaders: REQ_NOCACHE = NOT SET
2009/10/02 01:39:32.706| clientInterpretRequestHeaders: REQ_CACHABLE = SET
2009/10/02 01:39:32.706| clientInterpretRequestHeaders: REQ_HIERARCHICAL = SET
2009/10/02 01:39:32.706| client_side_request.cc(1296) doCallouts:
Doing calloutContext->checkNoCache()
2009/10/02 01:39:32.706| cbdataReferenceValid: 0x85f9d00
2009/10/02 01:39:32.706| cbdataReferenceValid: 0x85f9d00
2009/10/02 01:39:32.706| cbdataLock: 0x8372c80=1
2009/10/02 01:39:32.706| cbdataLock: 0x85f9d00=7
2009/10/02 01:39:32.706| cbdataLock: 0x86124f8=1
2009/10/02 01:39:32.706| cbdataReferenceValid: 0x86124f8
2009/10/02 01:39:32.706| cbdataReferenceValid: 0x8372c80
2009/10/02 01:39:32.706| ACLChecklist::preCheck: 0x86166a0 checking
'no_cache deny QUERY'
2009/10/02 01:39:32.706| ACLList::matches: checking QUERY
2009/10/02 01:39:32.706| ACL::checklistMatches: checking 'QUERY'
2009/10/02 01:39:32.706| aclRegexData::match: checking '/'
2009/10/02 01:39:32.706| aclRegexData::match: looking for 'cgi-bin'
2009/10/02 01:39:32.706| aclRegexData::match: looking for '\?'
2009/10/02 01:39:32.706| ACL::ChecklistMatches: result for 'QUERY' is 0
2009/10/02 01:39:32.706| ACLList::matches: result is false
2009/10/02 01:39:32.706| aclmatchAclList: 0x86166a0 returning false
(AND list entry failed to match)
2009/10/02 01:39:32.706| aclmatchAclList: async=0 nodeMatched=0
async_in_progress=0 lastACLResult() = 0 finished() = 0
2009/10/02 01:39:32.706| cbdataUnlock: 0x8372c80=0
2009/10/02 01:39:32.706| Checklist.cc(124) check: 0x86166a0 NO match
found, returning 1
2009/10/02 01:39:32.706| ACLFilledChecklist::checkCallback: 0x86166a0 answer=1
2009/10/02 01:39:32.706| ACLChecklist::checkCallback: 0x86166a0 answer=1
2009/10/02 01:39:32.706| cbdataReferenceValid: 0x86124f8
2009/10/02 01:39:32.707| cbdataUnlock: 0x86124f8=0
2009/10/02 01:39:32.707| cbdataReferenceValid: 0x86023b0
2009/10/02 01:39:32.707| cbdataReferenceValid: 0x85f9d00
2009/10/02 01:39:32.707| FilledChecklist.cc(162) ~ACLFilledChecklist:
ACLFilledChecklist destroyed 0xbfaf61c0
2009/10/02 01:39:32.707| ACLChecklist::~ACLChecklist: destroyed 0xbfaf61c0
2009/10/02 01:39:32.707| cbdataUnlock: 0x86023b0=2
2009/10/02 01:39:32.707| client_side_request.cc(127)
~ClientRequestContext: 0x86124f8 ClientRequestContext destructed
2009/10/02 01:39:32.707| cbdataFree: 0x86124f8
2009/10/02 01:39:32.707| cbdataFree: Freeing 0x86124f8
2009/10/02 01:39:32.707| client_side_request.cc(1322) doCallouts:
calling processRequest()
2009/10/02 01:39:32.707| clientProcessRequest: GET 'http://www.whatismyip.com/'
2009/10/02 01:39:32.707| ClientHttpRequest::httpStart: NONE for
'http://www.whatismyip.com/'
2009/10/02 01:39:32.707| clientStreamRead: Calling 1 with cbdata
0xb60220f8 from node 0x860a410
2009/10/02 01:39:32.707| cbdataReferenceValid: 0x860a3c8
2009/10/02 01:39:32.707| storeGet: looking up B59C974F6C68D46AC022EA13FF05023D
2009/10/02 01:39:32.707| clientProcessRequest2: StoreEntry is NULL -  MISS
2009/10/02 01:39:32.707| clientProcessMiss: 'GET http://www.whatismyip.com/'
2009/10/02 01:39:32.707| storeCreateEntry: 'http://www.whatismyip.com/'
2009/10/02 01:39:32.707| store.cc(370) StoreEntry: new StoreEntry 0xb6129890
2009/10/02 01:39:32.707| MemObject.cc(76) MemObject: new MemObject 0x85bf178
2009/10/02 01:39:32.707| init-ing hdr: 0x85c3454 owner: 3
2009/10/02 01:39:32.707| 0x85c3454 lookup for 39
2009/10/02 01:39:32.707| 0x85c3454 lookup for 9
2009/10/02 01:39:32.707| 0x85c3454 lookup for 22
2009/10/02 01:39:32.707| storeKeyPrivate: GET http://www.whatismyip.com/
2009/10/02 01:39:32.707| StoreEntry::hashInsert: Inserting Entry
0xb6129890 key 'BBFE1C7C79928B3B58688F1014E68F2E'
2009/10/02 01:39:32.707| store_client::copy:
BBFE1C7C79928B3B58688F1014E68F2E, from 0, for length 4096, cb 1,
cbdata 0xb6021094
2009/10/02 01:39:32.707| cbdataLock: 0xb6021094=1
2009/10/02 01:39:32.707| storeClientCopy2: BBFE1C7C79928B3B58688F1014E68F2E
2009/10/02 01:39:32.707| cbdataLock: 0x861b124=1
2009/10/02 01:39:32.708| store_client::doCopy: co: 0, hi: 0
2009/10/02 01:39:32.708| store_client::doCopy: Waiting for more
2009/10/02 01:39:32.708| cbdataUnlock: 0x861b124=0
2009/10/02 01:39:32.708| cbdataReferenceValid: 0x85f9d00
2009/10/02 01:39:32.708| cbdataReferenceValid: 0x85f9d00
2009/10/02 01:39:32.708| cbdataLock: 0x8372ea0=1
2009/10/02 01:39:32.708| aclCheckFast: list: 0x8372ea0
2009/10/02 01:39:32.708| ACLChecklist::preCheck: 0xbfaf5fec checking
'miss_access allow all'
2009/10/02 01:39:32.708| ACLList::matches: checking all
2009/10/02 01:39:32.708| ACL::checklistMatches: checking 'all'
2009/10/02 01:39:32.708| aclIpAddrNetworkCompare: compare:
xxx.xxx.xxx.xxx/[::] ([::])  vs [::]-[::]/[::]
2009/10/02 01:39:32.708| aclIpMatchIp: 'xxx.xxx.xxx.xxx' found
2009/10/02 01:39:32.708| ACL::ChecklistMatches: result for 'all' is 1
2009/10/02 01:39:32.708| ACLList::matches: result is true
2009/10/02 01:39:32.708| aclmatchAclList: 0xbfaf5fec returning true
(AND list satisfied)
2009/10/02 01:39:32.708| ACLChecklist::markFinished: 0xbfaf5fec
checklist processing finished
2009/10/02 01:39:32.708| cbdataUnlock: 0x8372ea0=0
2009/10/02 01:39:32.708| FilledChecklist.cc(162) ~ACLFilledChecklist:
ACLFilledChecklist destroyed 0xbfaf5fec
2009/10/02 01:39:32.708| ACLChecklist::~ACLChecklist: destroyed 0xbfaf5fec
2009/10/02 01:39:32.708| FwdState::start() 'http://www.whatismyip.com/'
2009/10/02 01:39:32.708| StoreEntry::lock: key
'BBFE1C7C79928B3B58688F1014E68F2E' count=2
2009/10/02 01:39:32.708| cbdataLock: 0x861f204=1
2009/10/02 01:39:32.708| peerSelect: http://www.whatismyip.com/
2009/10/02 01:39:32.708| cbdataLock: 0x861f204=2
2009/10/02 01:39:32.708| StoreEntry::lock: key
'BBFE1C7C79928B3B58688F1014E68F2E' count=3
2009/10/02 01:39:32.708| peerSelectFoo: 'GET www.whatismyip.com'
2009/10/02 01:39:32.708| peerSelectFoo: direct = DIRECT_MAYBE
2009/10/02 01:39:32.708| peerSelectIcpPing: http://www.whatismyip.com/
2009/10/02 01:39:32.708| neighborsCount: 0
2009/10/02 01:39:32.708| peerSelectIcpPing: counted 0 neighbors
2009/10/02 01:39:32.708| peerGetSomeParent: GET www.whatismyip.com
2009/10/02 01:39:32.709| getDefaultParent: returning NULL
2009/10/02 01:39:32.709| neighbors.cc(322) getRoundRobinParent: returning NULL
2009/10/02 01:39:32.709| getWeightedRoundRobinParent: returning NULL
2009/10/02 01:39:32.709| getFirstUpParent: returning NULL
2009/10/02 01:39:32.709| getAnyParent: returning NULL
2009/10/02 01:39:32.709| peerAddFwdServer: adding DIRECT HIER_DIRECT
2009/10/02 01:39:32.709| peerSelectCallback: http://www.whatismyip.com/
2009/10/02 01:39:32.709| cbdataReferenceValid: 0x861f204
2009/10/02 01:39:32.709| cbdataUnlock: 0x861f204=1
2009/10/02 01:39:32.709| fwdStartComplete: http://www.whatismyip.com/
2009/10/02 01:39:32.709| fwdConnectStart: http://www.whatismyip.com/
2009/10/02 01:39:32.709| PconnPool::key(www.whatismyip.com,80,(no
domain),xxx.xxx.xxx.xxxis {www.whatismyip.com:80-xxx.xxx.xxx.xxx}
2009/10/02 01:39:32.709| PconnPool::pop: lookup for key
{www.whatismyip.com:80-xxx.xxx.xxx.xxx} failed.
2009/10/02 01:39:32.709| FilledChecklist.cc(162) ~ACLFilledChecklist:
ACLFilledChecklist destroyed 0xbfaf5d38
2009/10/02 01:39:32.709| ACLChecklist::~ACLChecklist: destroyed 0xbfaf5d38
2009/10/02 01:39:32.709| fwdConnectStart: got outgoing addr
xxx.xxx.xxx.xxx, tos 0
2009/10/02 01:39:32.709| comm_openex: Attempt open socket for: xxx.xxx.xxx.xxx
2009/10/02 01:39:32.709| comm_openex: Opened socket FD 16 : family=2,
type=1, protocol=6
2009/10/02 01:39:32.709| comm_open: FD 16 is a new socket
2009/10/02 01:39:32.709| fd_open() FD 16 http://www.whatismyip.com/
2009/10/02 01:39:32.709| commBind: bind socket FD 16 to xxx.xxx.xxx.xxx
2009/10/02 01:39:32.709| fwdConnectStart: got TCP FD 16
2009/10/02 01:39:32.709| comm_add_close_handler: FD 16, handler=1,
data=0x861f204
2009/10/02 01:39:32.709| cbdataLock: 0x861f204=2
2009/10/02 01:39:32.709| cbdataLock: 0x861f204=3
2009/10/02 01:39:32.709| The AsyncCall SomeCloseHandler constructed,
this=0x84a84d0 [call1299]
2009/10/02 01:39:32.709| cbdataLock: 0x861f204=4
2009/10/02 01:39:32.709| cbdataUnlock: 0x861f204=3
2009/10/02 01:39:32.709| cbdataUnlock: 0x861f204=2
2009/10/02 01:39:32.709| comm_add_close_handler: FD 16, AsyncCall=0x84a84d0*1
2009/10/02 01:39:32.709| comm.cc(1189) commSetTimeout: FD 16 timeout 60
2009/10/02 01:39:32.710| cbdataLock: 0x861f204=3
2009/10/02 01:39:32.710| cbdataLock: 0x861f204=4
2009/10/02 01:39:32.710| The AsyncCall SomeTimeoutHandler constructed,
this=0x8637d98 [call1300]
2009/10/02 01:39:32.710| cbdataLock: 0x861f204=5
2009/10/02 01:39:32.710| cbdataUnlock: 0x861f204=4
2009/10/02 01:39:32.710| cbdataUnlock: 0x861f204=3
2009/10/02 01:39:32.710| comm.cc(1200) commSetTimeout: FD 16 timeout 60
2009/10/02 01:39:32.710| commConnectStart: FD 16, data 0x861f204,
www.whatismyip.com:80
2009/10/02 01:39:32.710| cbdataLock: 0x861f204=4
2009/10/02 01:39:32.710| cbdataLock: 0x861f204=5
2009/10/02 01:39:32.710| The AsyncCall SomeCommConnectHandler
constructed, this=0x849af30 [call1301]
2009/10/02 01:39:32.710| cbdataLock: 0x861f204=6
2009/10/02 01:39:32.710| cbdataUnlock: 0x861f204=5
2009/10/02 01:39:32.710| cbdataUnlock: 0x861f204=4
2009/10/02 01:39:32.710| commConnectStart: FD 16, cb 0x849af30*1,
www.whatismyip.com:80
2009/10/02 01:39:32.710| comm_add_close_handler: FD 16, handler=1,
data=0x862b4a4
2009/10/02 01:39:32.710| cbdataLock: 0x862b4a4=1
2009/10/02 01:39:32.710| cbdataLock: 0x862b4a4=2
2009/10/02 01:39:32.710| The AsyncCall SomeCloseHandler constructed,
this=0x860e330 [call1302]
2009/10/02 01:39:32.710| cbdataLock: 0x862b4a4=3
2009/10/02 01:39:32.710| cbdataUnlock: 0x862b4a4=2
2009/10/02 01:39:32.710| cbdataUnlock: 0x862b4a4=1
2009/10/02 01:39:32.710| comm_add_close_handler: FD 16, AsyncCall=0x860e330*1
2009/10/02 01:39:32.710| ipcache_nbgethostbyname: Name 'www.whatismyip.com'.
2009/10/02 01:39:32.710| ipcacheRelease: Releasing entry for
'www.whatismyip.com'
2009/10/02 01:39:32.710| ipcache_nbgethostbyname: MISS for 'www.whatismyip.com'
2009/10/02 01:39:32.710| cbdataLock: 0x862b4a4=2
2009/10/02 01:39:32.710| idnsALookup: buf is 36 bytes for
www.whatismyip.com, id = 0x2a64
2009/10/02 01:39:32.710| cbdataLock: 0x862f780=1

squid work fine with options transparent with iptable rule
iptables -t nat -A PREROUTING -i eth1 -p tcp --dport 80 -j REDIRECT
--to-port 3129

what problem ? it's problem in kernel, iptables or squid ? please help !!!

Thanks
Roman

[tproxy] Problem with options tproxy in squid 3.0

Snaiper