Re: [squid-users] Squid not responding and 100% cpu

From: Nuno Fernandes <npf-mlists_at_eurotux.com>
Date: Fri, 07 Jun 2013 17:10:35 +0100

> Em Sexta, Junho de 7 de 2013 11:59 WEST, Amos Jeffries <squid3_at_treenet.co.nz> escreveu:
>
> > On 7/06/2013 10:55 p.m., Nuno Fernandes wrote:
> > >> Good. That should be preventing loops.
> > >>
> > >> The ALL,2 will include the details from 11,2 I mentioned. So your log
> > >> should contain the outgoing request details.
> > >>
> > >> Amos
> > >>
> > >
> > > Argg... i will have to check 4G of logfile :(
> > > I will try to replicate with a devel machine and post back later.
> >
> > If it helps the info contains the text "Server HTTP Request" and also
> > the 10.10.10.4 IP address. From there you can get the URL and outbound
> > headers, then find them when they enter Squid (earlier, or next in the loop)
> >
> > Amos

OK.. I think the problem starts here:

2013/06/06 09:14:07.619 kid1| clientNegotiateSSL: Error negotiating SSL connection on FD 50: error:14094412:SSL routines:SSL3_READ_BYTES:sslv3 alert bad certificate (1/0)
2013/06/06 09:14:07.668 kid1| TcpAcceptor.cc(197) doAccept: New connection on FD 29
2013/06/06 09:14:07.668 kid1| TcpAcceptor.cc(272) acceptNext: connection on local=0.0.0.0:3126 remote=[::] FD 29 flags=41
2013/06/06 09:14:07.668 kid1| forward.cc(121) FwdState: Forwarding client request local=10.10.10.254:3126 remote=10.10.10.4:46196 FD 50 flags=33, url=://10.10.10.254:3126
2013/06/06 09:14:07.669 kid1| peer_select.cc(289) peerSelectDnsPaths: Found sources for '://10.10.10.254:3126'
2013/06/06 09:14:07.669 kid1| peer_select.cc(290) peerSelectDnsPaths: always_direct = ALLOWED
2013/06/06 09:14:07.669 kid1| peer_select.cc(291) peerSelectDnsPaths: never_direct = DENIED
2013/06/06 09:14:07.669 kid1| peer_select.cc(295) peerSelectDnsPaths: DIRECT = local=0.0.0.0 remote=10.10.10.254:3126 flags=1
2013/06/06 09:14:07.669 kid1| peer_select.cc(304) peerSelectDnsPaths: timedout = 0
2013/06/06 09:14:07.669 kid1| TcpAcceptor.cc(197) doAccept: New connection on FD 29
2013/06/06 09:14:07.669 kid1| TcpAcceptor.cc(272) acceptNext: connection on local=0.0.0.0:3126 remote=[::] FD 29 flags=41
2013/06/06 09:14:07.669 kid1| forward.cc(121) FwdState: Forwarding client request local=10.10.10.254:3126 remote=10.10.10.254:57318 FD 148 flags=33, url=://10.10.10.254:3126
2013/06/06 09:14:07.669 kid1| peer_select.cc(289) peerSelectDnsPaths: Found sources for '://10.10.10.254:3126'
2013/06/06 09:14:07.669 kid1| peer_select.cc(290) peerSelectDnsPaths: always_direct = DENIED
2013/06/06 09:14:07.669 kid1| peer_select.cc(291) peerSelectDnsPaths: never_direct = DENIED
2013/06/06 09:14:07.669 kid1| peer_select.cc(295) peerSelectDnsPaths: DIRECT = local=0.0.0.0 remote=10.10.10.254:3126 flags=1
2013/06/06 09:14:07.669 kid1| peer_select.cc(304) peerSelectDnsPaths: timedout = 0
2013/06/06 09:14:07.670 kid1| TcpAcceptor.cc(197) doAccept: New connection on FD 29
2013/06/06 09:14:07.670 kid1| TcpAcceptor.cc(272) acceptNext: connection on local=0.0.0.0:3126 remote=[::] FD 29 flags=41
2013/06/06 09:14:07.670 kid1| forward.cc(121) FwdState: Forwarding client request local=10.10.10.254:3126 remote=10.10.10.254:57319 FD 162 flags=33, url=://10.10.10.254:3126
2013/06/06 09:14:07.670 kid1| peer_select.cc(289) peerSelectDnsPaths: Found sources for '://10.10.10.254:3126'
2013/06/06 09:14:07.670 kid1| peer_select.cc(290) peerSelectDnsPaths: always_direct = DENIED
2013/06/06 09:14:07.670 kid1| peer_select.cc(291) peerSelectDnsPaths: never_direct = DENIED
2013/06/06 09:14:07.670 kid1| peer_select.cc(295) peerSelectDnsPaths: DIRECT = local=0.0.0.0 remote=10.10.10.254:3126 flags=1
2013/06/06 09:14:07.670 kid1| peer_select.cc(304) peerSelectDnsPaths: timedout = 0
2013/06/06 09:14:07.670 kid1| TcpAcceptor.cc(197) doAccept: New connection on FD 29
2013/06/06 09:14:07.670 kid1| TcpAcceptor.cc(272) acceptNext: connection on local=0.0.0.0:3126 remote=[::] FD 29 flags=41

and it keeps on that until it uses all file descriptors.

Why on earth squid receives a connection from [::] (ipv6??). I don't have any configuration regarding IPV6...

The lines before that are:

----------
2013/06/06 09:14:07.432 kid1| client_side_request.cc(778) clientAccessCheckDone: The request HEAD http://truetwit.com/truetwit/validate/index.form?id=84394311 is ALLOWED, because it matched
'rede'
2013/06/06 09:14:07.432 kid1| client_side_request.cc(752) clientAccessCheck2: No adapted_http_access configuration. default: ALLOW
2013/06/06 09:14:07.432 kid1| client_side_request.cc(778) clientAccessCheckDone: The request HEAD http://truetwit.com/truetwit/validate/index.form?id=84394311 is ALLOWED, because it matched
'rede'
2013/06/06 09:14:07.432 kid1| forward.cc(121) FwdState: Forwarding client request local=71.5.110.141:80 remote=10.10.10.4:60840 FD 160 flags=33, url=http://truetwit.com/truetwit/validate/ind
ex.form?id=84394311
2013/06/06 09:14:07.432 kid1| peer_select.cc(289) peerSelectDnsPaths: Found sources for 'http://truetwit.com/truetwit/validate/index.form?id=84394311'
2013/06/06 09:14:07.433 kid1| peer_select.cc(290) peerSelectDnsPaths: always_direct = ALLOWED
2013/06/06 09:14:07.433 kid1| peer_select.cc(291) peerSelectDnsPaths: never_direct = DENIED
2013/06/06 09:14:07.433 kid1| peer_select.cc(295) peerSelectDnsPaths: DIRECT = local=0.0.0.0 remote=71.5.110.141:80 flags=1
2013/06/06 09:14:07.433 kid1| peer_select.cc(304) peerSelectDnsPaths: timedout = 0
2013/06/06 09:14:07.433 kid1| http.cc(2204) sendRequest: HTTP Server local=192.168.100.10:43443 remote=71.5.110.141:80 FD 161 flags=1
2013/06/06 09:14:07.433 kid1| http.cc(2205) sendRequest: HTTP Server REQUEST:
---------
HEAD /truetwit/validate/index.form?id=84394311 HTTP/1.1
Host: truetwit.com
User-Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/534.34 (KHTML, like Gecko) choqok/4.10.3 Safari/534.34
Accept: text/html, text/*;q=0.9, image/jpeg;q=0.9, image/png;q=0.9, image/*;q=0.9, */*;q=0.8
Accept-Encoding: gzip, deflate, x-gzip, x-deflate
Accept-Charset: utf-8,*;q=0.5
Accept-Language: en-US,en;q=0.9
Via: 1.1 etfw.eurotux.com (squid)
X-Forwarded-For: unknown
Cache-Control: max-age=0
Connection: keep-alive

----------
2013/06/06 09:14:07.483 kid1| TcpAcceptor.cc(197) doAccept: New connection on FD 27
2013/06/06 09:14:07.483 kid1| TcpAcceptor.cc(272) acceptNext: connection on local=0.0.0.0:3127 remote=[::] FD 27 flags=41
2013/06/06 09:14:07.487 kid1| client_side.cc(2316) parseHttpRequest: HTTP Client local=199.16.156.11:80 remote=10.10.10.4:48659 FD 122 flags=33
2013/06/06 09:14:07.487 kid1| client_side.cc(2317) parseHttpRequest: HTTP Client REQUEST:
---------
HEAD /M75a3wq HTTP/1.1
Host: t.co
User-Agent: Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/534.34 (KHTML, like Gecko) choqok/4.10.3 Safari/534.34
Accept: text/html, text/*;q=0.9, image/jpeg;q=0.9, image/png;q=0.9, image/*;q=0.9, */*;q=0.8
Accept-Encoding: gzip, deflate, x-gzip, x-deflate
Accept-Charset: utf-8,*;q=0.5
Accept-Language: en-US,en;q=0.9
Via: 1.1 etfw.eurotux.com (squid)
X-Forwarded-For: unknown
Cache-Control: max-age=259200
Connection: keep-alive

----------
2013/06/06 09:14:07.619 kid1| ctx: enter level 0: 'http://truetwit.com/truetwit/validate/index.form?id=84394311'
2013/06/06 09:14:07.619 kid1| http.cc(761) processReplyHeader: HTTP Server local=192.168.100.10:43443 remote=71.5.110.141:80 FD 161 flags=1
2013/06/06 09:14:07.619 kid1| http.cc(762) processReplyHeader: HTTP Server REPLY:
---------
HTTP/1.1 200 OK
Date: Thu, 06 Jun 2013 08:14:07 GMT
Server: Apache/2.4.3 (Unix) PHP/5.3.16 mod_jk/1.2.37
Content-Language: en
Keep-Alive: timeout=5, max=99
Connection: Keep-Alive
Content-Type: text/html;charset=ISO-8859-1

----------
2013/06/06 09:14:07.619 kid1| ctx: exit level 0
2013/06/06 09:14:07.619 kid1| client_side.cc(1377) sendStartOfMessage: HTTP Client local=71.5.110.141:80 remote=10.10.10.4:60840 FD 160 flags=33
2013/06/06 09:14:07.619 kid1| client_side.cc(1378) sendStartOfMessage: HTTP Client REPLY:
---------
HTTP/1.1 200 OK
Date: Thu, 06 Jun 2013 08:14:07 GMT
Server: Apache/2.4.3 (Unix) PHP/5.3.16 mod_jk/1.2.37
Content-Language: en
Content-Type: text/html;charset=ISO-8859-1
X-Cache: MISS from etfw.eurotux.com
X-Cache-Lookup: MISS from etfw.eurotux.com:3125
Via: 1.1 etfw.eurotux.com (squid)
Connection: keep-alive

----------

Are these sufficient?

Thanks,
Nuno Fernandes
Received on Fri Jun 07 2013 - 16:10:08 MDT

This archive was generated by hypermail 2.2.0 : Fri Jun 07 2013 - 12:00:06 MDT