Search squid archive

Re: Squid 5.2 Peer parent TCP connection to x.x.x.x/x failed

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 

Hi,

Take time to enable the debug log an parsing the 10GB of logs

Here the piece of code:

2021/11/01 16:50:48.786 kid1| 33,5| AsyncCall.cc(30) AsyncCall: The AsyncCall Server::clientWriteDone constructed, this=0x55849cb132b0 [call252226641]
2021/11/01 16:50:48.786 kid1| 5,5| Write.cc(37) Write: conn9813869 local=10.33.50.22:3128 remote=10.33.50.109:50157 FD 95 flags=1: sz 4529: asynCall 0x55849cb132b0*1
2021/11/01 16:50:48.786 kid1| 5,5| ModEpoll.cc(118) SetSelect: FD 95, type=2, handler=1, client_data=0x7f1caaa1a2d0, timeout=0
2021/11/01 16:50:48.786 kid1| 20,3| store.cc(467) unlock: store_client::copy unlocking key 115EFC00000000009915000001000000 e:=sXIV/0x55849dfec190*4
2021/11/01 16:50:48.786 kid1| 20,3| store.cc(467) unlock: ClientHttpRequest::doCallouts-sslBumpNeeded unlocking key 115EFC00000000009915000001000000 e:=sXIV/0x55849dfec190*3
2021/11/01 16:50:48.786 kid1| 28,4| FilledChecklist.cc(67) ~ACLFilledChecklist: ACLFilledChecklist destroyed 0x55849316fc88
2021/11/01 16:50:48.786 kid1| 28,4| Checklist.cc(197) ~ACLChecklist: ACLChecklist::~ACLChecklist: destroyed 0x55849316fc88
2021/11/01 16:50:48.786 kid1| 84,5| helper.cc(1319) StatefulGetFirstAvailable: StatefulGetFirstAvailable: Running servers 4
2021/11/01 16:50:48.786 kid1| 84,5| helper.cc(1344) StatefulGetFirstAvailable: StatefulGetFirstAvailable: returning srv-Hlpr469
2021/11/01 16:50:48.786 kid1| 5,4| AsyncCall.cc(30) AsyncCall: The AsyncCall helperStatefulHandleRead constructed, this=0x55848ad88730 [call252226642]
2021/11/01 16:50:48.786 kid1| 5,5| Read.cc(58) comm_read_base: comm_read, queueing read for conn9811325 local=[::] remote=[::] FD 49 flags=1; asynCall 0x55848ad88730*1
2021/11/01 16:50:48.786 kid1| 5,5| ModEpoll.cc(118) SetSelect: FD 49, type=1, handler=1, client_data=0x7f1caaa18a20, timeout=0
2021/11/01 16:50:48.786 kid1| 5,4| AsyncCallQueue.cc(61) fireNext: leaving helperStatefulHandleRead(conn9811325 local=[::] remote=[::] FD 49 flags=1, data="" size=300, buf=0x558498dde700)
2021/11/01 16:50:48.786 kid1| 1,5| CodeContext.cc(60) Entering: master25501192
2021/11/01 16:50:48.786 kid1| 5,3| IoCallback.cc(112) finish: called for conn9812727 local=127.0.0.1:23408 remote=127.0.0.1:2320 FIRSTUP_PARENT FD 85 flags=1 (0, 0)
2021/11/01 16:50:48.786 kid1| 93,3| AsyncCall.cc(97) ScheduleCall: IoCallback.cc(131) will call Http::Tunneler::handleReadyRead(conn9812727 local=127.0.0.1:23408 remote=127.0.0.1:2320 FIRSTUP_PARENT FD 85 flags=1, data="" [call252202273]
2021/11/01 16:50:48.786 kid1| 5,5| Write.cc(69) HandleWrite: conn9813869 local=10.33.50.22:3128 remote=10.33.50.109:50157 FD 95 flags=1: off 0, sz 4529.
2021/11/01 16:50:48.786 kid1| 5,5| Write.cc(89) HandleWrite: write() returns 4529
2021/11/01 16:50:48.787 kid1| 5,3| IoCallback.cc(112) finish: called for conn9813869 local=10.33.50.22:3128 remote=10.33.50.109:50157 FD 95 flags=1 (0, 0)
2021/11/01 16:50:48.787 kid1| 33,5| AsyncCall.cc(97) ScheduleCall: IoCallback.cc(131) will call Server::clientWriteDone(conn9813869 local=10.33.50.22:3128 remote=10.33.50.109:50157 FD 95 flags=1, data="" [call252226641]
2021/11/01 16:50:48.787 kid1| 1,5| CodeContext.cc(60) Entering: master25501192
2021/11/01 16:50:48.787 kid1| 93,3| AsyncCallQueue.cc(59) fireNext: entering Http::Tunneler::handleReadyRead(conn9812727 local=127.0.0.1:23408 remote=127.0.0.1:2320 FIRSTUP_PARENT FD 85 flags=1, data=""> 2021/11/01 16:50:48.787 kid1| 93,3| AsyncCall.cc(42) make: make call Http::Tunneler::handleReadyRead [call252202273]
2021/11/01 16:50:48.787 kid1| 93,3| AsyncJob.cc(123) callStart: Http::Tunneler status in: [state:w FD 85 job26507207]
2021/11/01 16:50:48.787 kid1| 5,3| Read.cc(93) ReadNow: conn9812727 local=127.0.0.1:23408 remote=127.0.0.1:2320 FIRSTUP_PARENT FD 85 flags=1, size 65535, retval 7782, errno 0
2021/01 16:50:48.787 kid1| 24,5| Tokenizer.cc(27) consume: consuming 1 bytes
2021/11/01 16:50:48.787 kid1| 24,5| Tokenizer.cc(27) consume: consuming 3 bytes
2021/11/01 16:50:48.787 kid1| 24,5| Tokenizer.cc(27) consume: consuming 1 bytes
2021/11/01 16:50:48.787 kid1| 24,5| Tokenizer.cc(27) consume: consuming 19 bytes
2021/11/01 16:50:48.787 kid1| 24,5| Tokenizer.cc(27) consume: consuming 2 bytes
2021/11/01 16:50:48.787 kid1| 74,5| ResponseParser.cc(224) parse: status-line: retval 1
2021/11/01 16:50:48.787 kid1| 74,5| ResponseParser.cc(225) parse: status-line: proto HTTP/1.1
2021/11/01 16:50:48.787 kid1| 74,5| ResponseParser.cc(226) parse: status-line: status-code 503
2021/11/01 16:50:48.787 kid1| 74,5| ResponseParser.cc(227) parse: status-line: reason-phrase Service Unavailable
2021/11/01 16:50:48.787 kid1| 74,5| ResponseParser.cc(228) parse: Parser: bytes processed=34
2021/11/01 16:50:48.787 kid1| 74,5| Parser.cc(192) grabMimeBlock: mime header (0-171) {Server: squid^M
Mime-Version: 1.0^M
Date: Mon, 01 Nov 2021 15:50:48 GMT^M
Content-Type: text/html;charset=utf-8^M
Content-Length: 7577^M
X-Squid-Error: ERR_CONNECT_FAIL 110^M
^M
}
2021/11/01 16:50:48.787 kid1| 11,2| HttpTunneler.cc(323) handleResponse: Tunnel Server conn9812727 local=127.0.0.1:23408 remote=127.0.0.1:2320 FIRSTUP_PARENT FD 85 flags=1
2021/11/01 16:50:48.787 kid1| 11,2| HttpTunneler.cc(326) handleResponse: Tunnel Server RESPONSE:
---------
<!DOCTYPE HTML>
<html>
<head>
<title>ERROR: The requested URL could not be retrieved</title>
<script type="text/_javascript_" language="_javascript_" src=""></s----------
2021/11/01 16:50:48.787 kid1| 83,3| HttpTunneler.cc(345) bailOnResponseError: unsupported CONNECT response status code [state:w FD 85 job26507207]
2021/11/01 16:50:48.787 kid1| TCP connection to 127.0.0.1/2320 failed
    current master transaction: master25501192
2021/11/01 16:50:48.787 kid1| 83,5| HttpTunneler.cc(404) callBack: conn9812727 local=127.0.0.1:23408 remote=127.0.0.1:2320 FIRSTUP_PARENT FD 85 flags=1 [state:w FD 85 job26507207]
2021/11/01 16:50:48.787 kid1| 5,4| AsyncCall.cc(97) ScheduleCall: HttpTunneler.cc(409) will call TunnelStateData::tunnelEstablishmentDone([SquidErr:46 503]) [call252202269]
2021/11/01 16:50:48.787 kid1| 5,5| comm.cc(1042) comm_remove_close_handler: comm_remove_close_handler: FD 85, AsyncCall=0x558485cc45e0*2
2021/11/01 16:50:48.787 kid1| 9,5| AsyncCall.cc(60) cancel: will not call Http::Tunneler::handleConnectionClosure [call252202270] because comm_remove_close_handler
2021/11/01 16:50:48.787 kid1| 5,3| comm.cc(595) commUnsetConnTimeout: Remove timeout for conn9812727 local=127.0.0.1:23408 remote=127.0.0.1:2320 FIRSTUP_PARENT FD 85 flags=1
2021/11/01 16:50:48.787 kid1| 5,3| comm.cc(569) commSetConnTimeout: conn9812727 local=127.0.0.1:23408 remote=127.0.0.1:2320 FIRSTUP_PARENT FD 85 flags=1 timeout -1
2021/11/01 16:50:48.787 kid1| 5,3| comm.cc(871) _comm_close: start closing FD 85 by Connection.cc:89
2021/11/01 16:50:48.787 kid1| 5,3| comm.cc(556) commUnsetFdTimeout: Remove timeout for FD 85
2021/11/01 16:50:48.787 kid1| 5,5| comm.cc(737) commCallCloseHandlers: commCallCloseHandlers: FD 85
2021/11/01 16:50:48.787 kid1| 5,4| AsyncCall.cc(30) AsyncCall: The AsyncCall comm_close_complete constructed, this=0x558484c02d30 [call252226643]
2021/11/01 16:50:48.787 kid1| 5,4| AsyncCall.cc(97) ScheduleCall: comm.cc(942) will call comm_close_complete(FD 85) [call252226643]
2021/11/01 16:50:48.803 kid1| 93,5| AsyncJob.cc(139) callEnd: Http::Tunneler::handleReadyRead(conn9812727 local=127.0.0.1:23408 remote=127.0.0.1:2320 FIRSTUP_PARENT flags=1, data="" ends job [state:wx job26507207]
2021/11/01 16:50:48.803 kid1| 83,5| HttpTunneler.cc(52) ~Tunneler: Http::Tunneler destructed, this=0x55849b747e18
2021/11/01 16:50:48.803 kid1| 93,5| AsyncJob.cc(40) ~AsyncJob: AsyncJob destructed, this=0x55849b747ec8 type=Http::Tunneler [job26507207]
2021/11/01 16:50:48.803 kid1| 93,3| AsyncCallQueue.cc(61) fireNext: leaving Http::Tunneler::handleReadyRead(conn9812727 local=127.0.0.1:23408 remote=127.0.0.1:2320 FIRSTUP_PARENT flags=1, data="">

Le 01/11/2021 à 15:53, Alex Rousskov a écrit :
On 11/1/21 7:55 AM, David Touzeau wrote:


The Squid uses the loopback as a parent.

The same problem occurs:
06:19:47 kid1| TCP connection to 127.0.0.1/2320 failed
06:15:13 kid1| TCP connection to 127.0.0.1/2320 failed
06:14:41 kid1| TCP connection to 127.0.0.1/2320 failed
06:14:38 kid1| TCP connection to 127.0.0.1/2320 failed
06:13:15 kid1| TCP connection to 127.0.0.1/2320 failed
06:11:23 kid1| TCP connection to 127.0.0.1/2320 failed


      

        
cache_peer 127.0.0.1 parent 2320 0 name=Peer11 no-query default
connect-timeout=3 connect-fail-limit=5 no-tproxy


      

      
It is impossible to tell for sure what is going on because Squid does
not (unfortunately; yet) report the exact reason behind these connection
establishment failures or even the context in which a failure has
occurred. You may be able to tell more by collecting/analyzing packet
captures. Developers may be able to tell more if you share, say, ALL,5
debugging logs that show what led to the failure report.

Alex.


    

    

  

_______________________________________________
squid-users mailing list
squid-users@xxxxxxxxxxxxxxxxxxxxx
http://lists.squid-cache.org/listinfo/squid-users






















[Index of Archives]
 
 
[Linux Audio Users]
 
 
[Samba]
 
 
[Big List of Linux Books]
 
 
[Linux USB]
 
 
[Yosemite News]


















 
Powered by Linux