Re: [squid-users] Squid 3.1.0.17<--> Google/YouTube "(101) Network is unreachable",, error???

From: Jan Houtsma <list_at_houtsma.net>
Date: Tue, 09 Mar 2010 20:11:07 +0100

Op 9-3-2010 19:03, Kinkie schreef:
> On Tue, Mar 9, 2010 at 4:58 PM, Jan Houtsma <list_at_houtsma.net> wrote:
>
>> Hi,
>>
>> Squid has always been working fine. All websites, except Google, still
>> work fine! As far as i know nothing changed on my part, except the
>> weekly Fedora updates.
>>
>> My internal users get this "(101) Network is unreachable" error message
>> when they go through the proxy. My iptables allows ALL outgoing
>> connections.
>> When they hit "Reload" or ^R the page loads fine. But after a while when
>> they go to google again they get the same error. Hit ^R and it works again.
>> When bypassing the proxy, the connection also works fine!
>>
>> Only with Google! Other websites work fine!
>>
>> When i jump to the squid server and issue a wget to
>> http://www.google.com with and without the proxy i get following results:
>>
> Have you tied wget'ting from the server itself?
> Maybe there are intermittent network issues from that box..
> Google uses advanced load-balancing techniques, so it may also happen
> that the servers reached by the proxy are different from the ones
> reached by the client..
>

I increased the logging in squid.conf. Here is the relevant part where
it goes wrong in cache.log.......

.....
2010/03/09 15:26:44.432| peerSelectFoo: 'GET www.google.com'
2010/03/09 15:26:44.433| peerSelectFoo: direct = DIRECT_YES
2010/03/09 15:26:44.433| peerSelectCallback:
http://www.google.com/search?q=jan&ie=utf-8&oe=utf-8&aq=t&rls=org.mozilla:nl:official&client=firefox-a
2010/03/09 15:26:44.433| fwdStartComplete:
http://www.google.com/search?q=jan&ie=utf-8&oe=utf-8&aq=t&rls=org.mozilla:nl:official&client=firefox-a
2010/03/09 15:26:44.433| fwdConnectStart:
http://www.google.com/search?q=jan&ie=utf-8&oe=utf-8&aq=t&rls=org.mozilla:nl:official&client=firefox-a
2010/03/09 15:26:44.433| PconnPool::pop: lookup for key
{www.google.com:80} failed.
2010/03/09 15:26:44.433| fwdConnectStart: got outgoing addr [::], tos 0
2010/03/09 15:26:44.433| comm_openex: Attempt open socket for: [::]
2010/03/09 15:26:44.433| comm_openex: Opened socket FD 15 : family=10,
type=1, protocol=6
2010/03/09 15:26:44.433| fd_open() FD 15
http://www.google.com/search?q=jan&ie=utf-8&oe=utf-8&aq=t&rls=org.mozilla:nl:official&client=firefox-a
2010/03/09 15:26:44.433| fwdConnectStart: got TCP FD 15
2010/03/09 15:26:44.433| comm.cc(1183) commSetTimeout: FD 15 timeout 60
2010/03/09 15:26:44.433| comm.cc(1194) commSetTimeout: FD 15 timeout 60
2010/03/09 15:26:44.433| The AsyncCall SomeCommConnectHandler
constructed, this=0x7fd61aca3dd0 [call69644]
2010/03/09 15:26:44.433| commConnectStart: FD 15, cb 0x7fd61aca3dd0*1,
www.google.com:80
2010/03/09 15:26:44.434| ipcacheRelease: Releasing entry for
'www.google.com'
2010/03/09 15:26:44.434| idnsALookup: buf is 32 bytes for
www.google.com, id = 0x74e2
2010/03/09 15:26:44.434| comm_udp_sendto: Attempt to send UDP packet to
127.0.0.1:53 using FD 8 using Port 47672
2010/03/09 15:26:44.434| StoreEntry::unlock: key
'94F736A09A5A7137D48DF183AAEDEE91' count=2
2010/03/09 15:26:44.435| idnsRead: starting with FD 8
2010/03/09 15:26:44.435| idnsRead: FD 8: received 292 bytes from
127.0.0.1:53
2010/03/09 15:26:44.435| idnsGrokReply: ID 0x74e2, 7 answers
2010/03/09 15:26:44.435| idnsGrokReply: www.google.com AAAA query done.
Configured to retrieve A now also.
2010/03/09 15:26:44.435| comm_udp_sendto: Attempt to send UDP packet to
194.109.6.66:53 using FD 8 using Port 47672
2010/03/09 15:26:44.450| idnsRead: starting with FD 8
2010/03/09 15:26:44.450| idnsRead: FD 8: received 100 bytes from
194.109.6.66:53
2010/03/09 15:26:44.450| idnsGrokReply: ID 0xe7fe, 4 answers
2010/03/09 15:26:44.450| ipcacheParse: www.google.com #0
[2a00:1450:8002::67]
2010/03/09 15:26:44.450| ipcacheParse: www.google.com #1
[2a00:1450:8002::68]
2010/03/09 15:26:44.450| ipcacheParse: www.google.com #2
[2a00:1450:8002::69]
2010/03/09 15:26:44.451| ipcacheParse: www.google.com #3
[2a00:1450:8002::6a]
2010/03/09 15:26:44.451| ipcacheParse: www.google.com #4
[2a00:1450:8002::93]
2010/03/09 15:26:44.451| ipcacheParse: www.google.com #5
[2a00:1450:8002::63]
2010/03/09 15:26:44.451| ipcacheParse: www.google.com #6 74.125.79.99
2010/03/09 15:26:44.451| ipcacheParse: www.google.com #7 74.125.79.104
2010/03/09 15:26:44.451| ipcacheParse: www.google.com #8 74.125.79.147
2010/03/09 15:26:44.451| ipcacheMarkBadAddr: www.google.com
[2a00:1450:8002::67]:80
2010/03/09 15:26:44.451| ipcacheCycleAddr: www.google.com now at
[2a00:1450:8002::68] (2 of 9)
2010/03/09 15:26:44.451| ipcacheCycleAddr: www.google.com now at
[2a00:1450:8002::69] (3 of 9)
2010/03/09 15:26:44.451| ipcacheCycleAddr: www.google.com now at
[2a00:1450:8002::6a] (4 of 9)
2010/03/09 15:26:44.451| ipcacheCycleAddr: www.google.com now at
[2a00:1450:8002::93] (5 of 9)
2010/03/09 15:26:44.452| ipcacheCycleAddr: www.google.com now at
[2a00:1450:8002::63] (6 of 9)
2010/03/09 15:26:44.452| ipcacheCycleAddr: www.google.com now at
74.125.79.99 (7 of 9)
2010/03/09 15:26:44.452| ipcacheCycleAddr: www.google.com now at
74.125.79.104 (8 of 9)
2010/03/09 15:26:44.452| ipcacheCycleAddr: www.google.com now at
74.125.79.147 (9 of 9)
2010/03/09 15:26:44.452| ipcacheCycleAddr: www.google.com now at
[2a00:1450:8002::68] (2 of 9)
2010/03/09 15:26:44.453| ipcacheCycleAddr: www.google.com now at
[2a00:1450:8002::69] (3 of 9)
2010/03/09 15:26:44.453| commConnectCallback: FD 15
2010/03/09 15:26:44.453| comm.cc(1183) commSetTimeout: FD 15 timeout -1
2010/03/09 15:26:44.453| comm.cc(1194) commSetTimeout: FD 15 timeout -1
2010/03/09 15:26:44.453| comm.cc(928) will call
SomeCommConnectHandler(FD 15, errno=101, flag=-8, data=0x7fd61a5cdee8, )
[call69644]
2010/03/09 15:26:44.453| commConnectFree: FD 15
2010/03/09 15:26:44.453| entering SomeCommConnectHandler(FD 15,
errno=101, flag=-8, data=0x7fd61a5cdee8, )
2010/03/09 15:26:44.453| AsyncCall.cc(32) make: make call
SomeCommConnectHandler [call69644]
2010/03/09 15:26:44.453| forward.cc(279) fail: ERR_CONNECT_FAIL "Service
Unavailable"
   
http://www.google.com/search?q=jan&ie=utf-8&oe=utf-8&aq=t&rls=org.mozilla:nl:official&client=firefox-a
2010/03/09 15:26:44.454| comm_close: start closing FD 15
2010/03/09 15:26:44.454| comm.cc(1183) commSetTimeout: FD 15 timeout -1
2010/03/09 15:26:44.454| comm.cc(1194) commSetTimeout: FD 15 timeout -1
2010/03/09 15:26:44.454| leaving SomeCommConnectHandler(FD 15,
errno=101, flag=-8, data=0x7fd61a5cdee8, )
2010/03/09 15:26:44.454| fwdServerClosed: FD 15
http://www.google.com/search?q=jan&ie=utf-8&oe=utf-8&aq=t&rls=org.mozilla:nl:official&client=firefox-a
2010/03/09 15:26:44.454| fwdServerClosed: re-forwarding (1 tries, 0 secs)
2010/03/09 15:26:44.454| fd_close FD 15
http://www.google.com/search?q=jan&ie=utf-8&oe=utf-8&aq=t&rls=o
2010/03/09 15:26:44.504| fwdConnectStart:
http://www.google.com/search?q=jan&ie=utf-8&oe=utf-8&aq=t&rls=org.mozilla:nl:official&client=firefox-a
2010/03/09 15:26:44.504| PconnPool::pop: lookup for key
{www.google.com:80} failed.
2010/03/09 15:26:44.504| fwdConnectStart: got outgoing addr [::], tos 0
2010/03/09 15:26:44.504| comm_openex: Attempt open socket for: [::]
2010/03/09 15:26:44.505| comm_openex: Opened socket FD 15 : family=10,
type=1, protocol=6
2010/03/09 15:26:44.505| fd_open() FD 15
http://www.google.com/search?q=jan&ie=utf-8&oe=utf-8&aq=t&rls=org.mozilla:nl:official&client=firefox-a
2010/03/09 15:26:44.505| fwdConnectStart: got TCP FD 15
2010/03/09 15:26:44.505| comm.cc(1183) commSetTimeout: FD 15 timeout 60
2010/03/09 15:26:44.505| comm.cc(1194) commSetTimeout: FD 15 timeout 60
2010/03/09 15:26:44.505| The AsyncCall SomeCommConnectHandler
constructed, this=0x7fd61aca6020 [call69661]
2010/03/09 15:26:44.505| commConnectStart: FD 15, cb 0x7fd61aca6020*1,
www.google.com:80
2010/03/09 15:26:44.505| ipcacheMarkBadAddr: www.google.com
[2a00:1450:8002::69]:80
2010/03/09 15:26:44.505| ipcacheCycleAddr: www.google.com now at
[2a00:1450:8002::6a] (4 of 9)
2010/03/09 15:26:44.506| ipcacheCycleAddr: www.google.com now at
[2a00:1450:8002::93] (5 of 9)
2010/03/09 15:26:44.506| ipcacheCycleAddr: www.google.com now at
[2a00:1450:8002::63] (6 of 9)
2010/03/09 15:26:44.506| ipcacheCycleAddr: www.google.com now at
74.125.79.99 (7 of 9)
2010/03/09 15:26:44.506| ipcacheCycleAddr: www.google.com now at
74.125.79.104 (8 of 9)
2010/03/09 15:26:44.507| ipcacheCycleAddr: www.google.com now at
74.125.79.147 (9 of 9)
2010/03/09 15:26:44.507| ipcacheCycleAddr: www.google.com now at
[2a00:1450:8002::68] (2 of 9)
2010/03/09 15:26:44.507| ipcacheCycleAddr: www.google.com now at
[2a00:1450:8002::6a] (4 of 9)
2010/03/09 15:26:44.507| ipcacheCycleAddr: www.google.com now at
[2a00:1450:8002::93] (5 of 9)
2010/03/09 15:26:44.508| ipcacheCycleAddr: www.google.com now at
[2a00:1450:8002::63] (6 of 9)
2010/03/09 15:26:44.508| commConnectCallback: FD 15
2010/03/09 15:26:44.508| comm.cc(1183) commSetTimeout: FD 15 timeout -1
2010/03/09 15:26:44.508| comm.cc(1194) commSetTimeout: FD 15 timeout -1
2010/03/09 15:26:44.508| comm.cc(928) will call
SomeCommConnectHandler(FD 15, errno=101, flag=-8, data=0x7fd61a5cdee8, )
[call69661]
2010/03/09 15:26:44.508| commConnectFree: FD 15
2010/03/09 15:26:44.508| entering SomeCommConnectHandler(FD 15,
errno=101, flag=-8, data=0x7fd61a5cdee8, )
2010/03/09 15:26:44.508| AsyncCall.cc(32) make: make call
SomeCommConnectHandler [call69661]
2010/03/09 15:26:44.508| forward.cc(279) fail: ERR_CONNECT_FAIL "Service
Unavailable"
   
http://www.google.com/search?q=jan&ie=utf-8&oe=utf-8&aq=t&rls=org.mozilla:nl:official&client=firefox-a
2010/03/09 15:26:44.508| comm_close: start closing FD 15
2010/03/09 15:26:44.509| comm.cc(1183) commSetTimeout: FD 15 timeout -1
2010/03/09 15:26:44.509| comm.cc(1194) commSetTimeout: FD 15 timeout -1
2010/03/09 15:26:44.509| leaving SomeCommConnectHandler(FD 15,
errno=101, flag=-8, data=0x7fd61a5cdee8, )
2010/03/09 15:26:44.509| fwdServerClosed: FD 15
http://www.google.com/search?q=jan&ie=utf-8&oe=utf-8&aq=t&rls=org.mozilla:nl:official&client=firefox-a
2010/03/09 15:26:44.509| fwdServerClosed: re-forwarding (2 tries, 0 secs)
2010/03/09 15:26:44.509| fd_close FD 15
http://www.google.com/search?q=jan&ie=utf-8&oe=utf-8&aq=t&rls=o
2010/03/09 15:26:44.559| fwdConnectStart:
http://www.google.com/search?q=jan&ie=utf-8&oe=utf-8&aq=t&rls=org.mozilla:nl:official&client=firefox-a
2010/03/09 15:26:44.559| PconnPool::pop: lookup for key
{www.google.com:80} failed.
2010/03/09 15:26:44.559| fwdConnectStart: got outgoing addr [::], tos 0
2010/03/09 15:26:44.559| comm_openex: Attempt open socket for: [::]
2010/03/09 15:26:44.559| comm_openex: Opened socket FD 15 : family=10,
type=1, protocol=6
2010/03/09 15:26:44.559| fd_open() FD 15
http://www.google.com/search?q=jan&ie=utf-8&oe=utf-8&aq=t&rls=org.mozilla:nl:official&client=firefox-a
2010/03/09 15:26:44.560| fwdConnectStart: got TCP FD 15
2010/03/09 15:26:44.560| comm.cc(1183) commSetTimeout: FD 15 timeout 60
2010/03/09 15:26:44.560| comm.cc(1194) commSetTimeout: FD 15 timeout 60
2010/03/09 15:26:44.560| The AsyncCall SomeCommConnectHandler
constructed, this=0x7fd61ab6c210 [call69677]
2010/03/09 15:26:44.560| commConnectStart: FD 15, cb 0x7fd61ab6c210*1,
www.google.com:80
2010/03/09 15:26:44.560| ipcacheMarkBadAddr: www.google.com
[2a00:1450:8002::63]:80
2010/03/09 15:26:44.560| ipcacheCycleAddr: www.google.com now at
74.125.79.99 (7 of 9)
2010/03/09 15:26:44.560| ipcacheCycleAddr: www.google.com now at
74.125.79.104 (8 of 9)
2010/03/09 15:26:44.561| ipcacheCycleAddr: www.google.com now at
74.125.79.147 (9 of 9)
2010/03/09 15:26:44.561| ipcacheCycleAddr: www.google.com now at
[2a00:1450:8002::68] (2 of 9)
2010/03/09 15:26:44.561| ipcacheCycleAddr: www.google.com now at
[2a00:1450:8002::6a] (4 of 9)
2010/03/09 15:26:44.561| ipcacheCycleAddr: www.google.com now at
[2a00:1450:8002::93] (5 of 9)
2010/03/09 15:26:44.562| ipcacheCycleAddr: www.google.com now at
74.125.79.99 (7 of 9)
2010/03/09 15:26:44.562| ipcacheCycleAddr: www.google.com now at
74.125.79.104 (8 of 9)
2010/03/09 15:26:44.562| ipcacheCycleAddr: www.google.com now at
74.125.79.147 (9 of 9)
2010/03/09 15:26:44.562| ipcacheCycleAddr: www.google.com now at
[2a00:1450:8002::68] (2 of 9)
2010/03/09 15:26:44.562| commConnectCallback: FD 15
2010/03/09 15:26:44.562| comm.cc(1183) commSetTimeout: FD 15 timeout -1
2010/03/09 15:26:44.562| comm.cc(1194) commSetTimeout: FD 15 timeout -1
2010/03/09 15:26:44.563| comm.cc(928) will call
SomeCommConnectHandler(FD 15, errno=101, flag=-8, data=0x7fd61a5cdee8, )
[call69677]
2010/03/09 15:26:44.563| commConnectFree: FD 15
2010/03/09 15:26:44.563| entering SomeCommConnectHandler(FD 15,
errno=101, flag=-8, data=0x7fd61a5cdee8, )
2010/03/09 15:26:44.563| AsyncCall.cc(32) make: make call
SomeCommConnectHandler [call69677]
2010/03/09 15:26:44.563| forward.cc(279) fail: ERR_CONNECT_FAIL "Service
Unavailable"
   
http://www.google.com/search?q=jan&ie=utf-8&oe=utf-8&aq=t&rls=org.mozilla:nl:official&client=firefox-a
2010/03/09 15:26:44.563| comm_close: start closing FD 15
2010/03/09 15:26:44.563| comm.cc(1183) commSetTimeout: FD 15 timeout -1
2010/03/09 15:26:44.563| comm.cc(1194) commSetTimeout: FD 15 timeout -1
2010/03/09 15:26:44.563| leaving SomeCommConnectHandler(FD 15,
errno=101, flag=-8, data=0x7fd61a5cdee8, )
2010/03/09 15:26:44.563| fwdServerClosed: FD 15
http://www.google.com/search?q=jan&ie=utf-8&oe=utf-8&aq=t&rls=org.mozilla:nl:official&client=firefox-a
2010/03/09 15:26:44.564| forward.cc(159) ~FwdState: FwdState destructor
starting
2010/03/09 15:26:44.564| StoreEntry::lock: key
'94F736A09A5A7137D48DF183AAEDEE91' count=3
2010/03/09 15:26:44.564| fd_open() FD 16
/usr/share/squid/errors/nl/ERR_CONNECT_FAIL
2010/03/09 15:26:44.564| fd_close FD 16
/usr/share/squid/errors/nl/ERR_CONNECT_FAIL
2010/03/09 15:26:44.564| errorConvert: %%l --> '/*
 Stylesheet for Squid Error pages
 Adapted from design by Free CSS Templates
 http://www.freecsstemplates.org
 Released for free under a Creative Commons Attribution 2.5 License
*/

/* Page basics */
* {
    font-family: verdana, sans-serif;
}

html body {
    margin: 0;
    padding: 0;
    background: #efefef;
    font-size: 12px;
    color: #1e1e1e;
}

/* Page displayed title area */
#titles {
    margin-left: 15px;
    padding: 10px;
    padding-left: 100px;
    background: url('http://www.squid-cache.org/Artwork/SN.png')
no-repeat left;
}

/* initial title */
#titles h1 {
    color: #000000;
}
#titles h2 {
    color: #000000;
}

/* special event: FTP success page titles */
#titles ftpsuccess {
    background-color:#00ff00;
    width:100%;
}

/* Page displayed body content area */
#content {
    padding: 10px;
    background: #ffffff;
}

/* General text */
p {
}

/* error brief description */
#error p {
}

/* some data which may have caused the problem */
#data {
}

/* the error message received from the system or other software */
#sysmsg {
}

pre {
    font-family:sans-serif;
}

/* special event: FTP / Gopher directory listing */
#dirlisting tr.entry td.icon,td.filename,td.size,td.date {
    border-bottom: groove;
}
#dirlisting td.size {
    width: 50px;
    text-align: right;
    padding-right: 5px;
}

/* horizontal lines */
hr {
    margin: 0;
}

/* page displayed footer area */
#footer {
    font-size: 9px;
    padding-left: 10px;
}
'
2010/03/09 15:26:44.564| errorConvert: %%; --> '%;'
2010/03/09 15:26:44.565| errorConvert: %%U -->
'http://www.google.com/search?'
2010/03/09 15:26:44.565| errorConvert: %%U -->
'http://www.google.com/search?'
2010/03/09 15:26:44.565| errorConvert: %%I --> 'www.google.com'
2010/03/09 15:26:44.565| errorConvert: %%E --> '(101) Network is
unreachable'
2010/03/09 15:26:44.565| errorConvert: %%w --> 'webmaster_at_houtsma.net'
2010/03/09 15:26:44.565| errorConvert: %%W -->
'?subject=CacheErrorInfo%20-%20ERR_CONNECT_FAIL&body=CacheHost%3A%20pegasus.houtsma.net%0D%0AErrPage%3A%20ERR_CONNECT_FAIL%0D%0AErr%3A%20(101)%20Network%20is%20unreachable%0D%0ATimeStamp%3A%20Tue,%2009%20Mar%202010%2014%3A26%3A44%20GMT%0D%0A%0D%0AClientIP%3A%20192.168.1.16%0D%0AServerIP%3A%20www.google.com%0D%0A%0D%0AHTTP%20Request%3A%0D%0AGET%20%2Fsearch%3Fq%3Djan%26ie%3Dutf-8%26oe%3Dutf-8%26aq%3Dt%26rls%3Dorg.mozilla%3Anl%3Aofficial%26client%3Dfirefox-a%20HTTP%2F1.1%0AHost%3A%20www.google.com%0D%0AUser-Agent%3A%20Mozilla%2F5.0%20(Windows%3B%20U%3B%20Windows%20NT%206.1%3B%20nl%3B%20rv%3A1.9.2)%20Gecko%2F20100115%20Firefox%2F3.6%20(.NET%20CLR%203.5.30729)%0D%0AAccept%3A%20text%2Fhtml,application%2Fxhtml+xml,application%2Fxml%3Bq%3D0.9,*%2F*%3Bq%3D0.8%0D%0AAccept-Language%3A%20nl,en-us%3Bq%3D0.7,en%3Bq%3D0.3%0D%0AAccept-Encoding%3A%20gzip,deflate%0D%0AAccept-Charset%3A%20ISO-8859-1,utf-8%3Bq%3D0.7,*%3Bq%3D0.7%0D%0AKeep-Alive%3A%20115%0D%0AProxy-Connection%3A%20keep-alive%0D%0ACookie%3A%20SS%3DQ0%3Dc3F1aWQgZGlyZWN0IGFjY2Vzcw%3B%20PREF%3DID%3D5b8b04cfbb5ee02f%3AU%3Da8c7231519b047ef%3ATM%3D1268135191%3ALM%3D1268136619%3AS%3Dk-5CnkaR2AxYC7E_%3B%20NID%3D32%3DMGxFdbD7CbVr7WjNkhAUZIQl3JY_ox1KLivuNzZbFs68O3RUPAFxGhGNoLcGgmFBo9i2OWCZY3QghvbsDzWP9VI5ABvvjtRd9FDa4U3kV6q69ldvw2uh84grbKHAlCiI%0D%0A%0D%0A%0D%0A'
2010/03/09 15:26:44.566| errorConvert: %%w --> 'webmaster_at_houtsma.net'
2010/03/09 15:26:44.566| errorConvert: %%T --> 'Tue, 09 Mar 2010
14:26:44 GMT'
2010/03/09 15:26:44.566| errorConvert: %%h --> 'pegasus.houtsma.net'
2010/03/09 15:26:44.566| errorConvert: %%s --> 'squid/3.1.0.17'
2010/03/09 15:26:44.566| errorConvert: %%c --> 'ERR_CONNECT_FAIL'
....
Received on Tue Mar 09 2010 - 19:11:13 MST

This archive was generated by hypermail 2.2.0 : Wed Mar 10 2010 - 12:00:03 MST