[squid-users] Squid 5.7 + bump ERR_READ_ERROR|WITH_SERVER
Alex Rousskov
rousskov at measurement-factory.com
Thu Oct 13 17:41:49 UTC 2022
On 10/13/22 03:05, David Touzeau wrote:
> I have pushed more previous data here:
>
> http://articatech.net/tmpf/cache.log.txt
As I suspected, a Squid worker (kid3) found no destinations that can be
used to forward this request:
> peer_select.cc(479) resolveSelected: PeerSelector43309 found all 0 destinations for categories.articatech.net:443
> FwdState.cc(209) stopAndDestroy: for path selection found no paths
> FwdState.cc(492) fail: ERR_READ_ERROR "Bad Gateway"
There were no destinations because Squid cache had a no-IPs DNS entry
for the above domain:
> ipcache.cc(647) ipcache_nbgethostbyname_: ... HIT for 'categories.articatech.net'
> ipcache.cc(231) finalCallback: ... lookup_err=No DNS records
AFAICT, the shared logs start _after_ the corresponding DNS cache entry
was created (or lost its IPs), so I cannot tell what actually happened
back then.
Later, the expired(?) no-IPs DNS cache entry is purged, and Squid is
able to resolve the same host name:
> ipcache.cc(532) addGood: categories.articatech.net #1 217.182.193.199
And similar transactions start to succeed from this point.
If you can share more/earlier logs, I may be able to tell what caused
the 'No DNS records' problem.
HTH,
Alex.
P.S. Please compress debugging logs when sharing.
> Le 13/10/2022 à 00:16, Alex Rousskov a écrit :
>> On 10/12/22 17:58, David Touzeau wrote:
>>
>>> We have put it in debug mode :
>>
>> Unfortunately, this log starts at GET request processing _after_
>> CONNECT request processing has already encountered and saved the
>> error. Thus, I cannot tell you why that error was encountered. I need
>> to see the lines before the lines you have shared. If you still have
>> the log file, searching for AFC90000000000002632000003000000 (above
>> the already shared lines) might help you find where the error message
>> was created.
>>
>> HTH,
>>
>> Alex.
>>
>>
>>> you can see :
>>>
>>>
>>> "2022/10/12 22:29:49.476 kid3| 4,3| Error.cc(22) update: recent:
>>> ERR_READ_ERROR/WITH_SERVER"
>>>
>>> As without ssl-bump, there is no issue.
>>>
>>> the full log can be downloaded here
>>> http://articatech.net/tmpf/cache.log.txt*
>>> *
>>>
>>> }
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(85) assign: assigning
>>> SBuf15905084 from SBuf15905303
>>> 2022/10/12 22:29:49.475 kid3| 11,2| client_side.cc(1357)
>>> parseHttpRequest: HTTP Client conn214046 local=192.168.1.190:3128
>>> remote=192.168.1.13:62858 FD 21 flags=1
>>> 2022/10/12 22:29:49.475 kid3| 11,2| client_side.cc(1361)
>>> parseHttpRequest: HTTP Client REQUEST:
>>> ---------
>>> GET /fw.ping.php?_=1665576594826 HTTP/1.1
>>> Host: categories.articatech.net
>>> User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:105.0)
>>> Gecko/20100101 Firefox/105.0
>>> Accept: */*
>>> Accept-Language: fr,fr-FR;q=0.8,en-US;q=0.5,en;q=0.3
>>> Accept-Encoding: gzip, deflate, br
>>> Referer: https://categories.articatech.net/index
>>> X-Requested-With: XMLHttpRequest
>>> Connection: keep-alive
>>> Cookie: _ga=GA1.2.1172828951.1642984448;
>>> PHPSESSID=28871210b5b031a7b034981e9704a4ac
>>> Sec-Fetch-Dest: empty
>>> Sec-Fetch-Mode: cors
>>> Sec-Fetch-Site: same-origin
>>>
>>>
>>> ----------
>>> 2022/10/12 22:29:49.475 kid3| 33,3| client_side.cc(1393)
>>> parseHttpRequest: complete request received. prefix_sz = 542,
>>> request-line-size=43, mime-header-size=499, mime header block:
>>> Host: categories.articatech.net
>>> User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:105.0)
>>> Gecko/20100101 Firefox/105.0
>>> Accept: */*
>>> Accept-Language: fr,fr-FR;q=0.8,en-US;q=0.5,en;q=0.3
>>> Accept-Encoding: gzip, deflate, br
>>> Referer: https://categories.articatech.net/index
>>> X-Requested-With: XMLHttpRequest
>>> Connection: keep-alive
>>> Cookie: _ga=GA1.2.1172828951.1642984448;
>>> PHPSESSID=28871210b5b031a7b034981e9704a4ac
>>> Sec-Fetch-Dest: empty
>>> Sec-Fetch-Mode: cors
>>> Sec-Fetch-Site: same-origin
>>>
>>>
>>> ----------
>>> 2022/10/12 22:29:49.475 kid3| 93,5| AsyncJob.cc(34) AsyncJob:
>>> AsyncJob constructed, this=0x56260e3814b8 type=ClientHttpRequest
>>> [job199106]
>>> 2022/10/12 22:29:49.475 kid3| 1,5| CodeContext.cc(60) Entering: ALE
>>> w/o master
>>> 2022/10/12 22:29:49.475 kid3| 87,3| clientStream.cc(140)
>>> clientStreamInsertHead: clientStreamInsertHead: Inserted node
>>> 0x56260e6d26f8 with data 0x56260e0fa280 after head
>>> 2022/10/12 22:29:49.475 kid3| 33,5| client_side.cc(1413)
>>> parseHttpRequest: Prepare absolute URL from
>>> 2022/10/12 22:29:49.475 kid3| 25,5| Parser.cc(228)
>>> getHostHeaderField: looking for Host
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(763) findFirstNotOf:
>>> first not of characterset non-LF in id SBuf15905340
>>> 2022/10/12 22:29:49.475 kid3| 24,5| Tokenizer.cc(27) consume:
>>> consuming 32 bytes
>>> 2022/10/12 22:29:49.475 kid3| 24,5| Tokenizer.cc(27) consume:
>>> consuming 1 bytes
>>> 2022/10/12 22:29:49.475 kid3| 25,5| Parser.cc(249)
>>> getHostHeaderField: checking Host: categories.articatech.net
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(763) findFirstNotOf:
>>> first not of characterset WSP in id SBuf15905345
>>> 2022/10/12 22:29:49.475 kid3| 24,5| Tokenizer.cc(27) consume:
>>> consuming 1 bytes
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(85) assign: assigning
>>> SBuf15905339 from SBuf15905345
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(763) findFirstNotOf:
>>> first not of characterset host in id SBuf15905339
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(771) findFirstNotOf: not
>>> found
>>> 2022/10/12 22:29:49.475 kid3| 25,5| Parser.cc(267)
>>> getHostHeaderField: returning categories.articatech.net
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(85) assign: assigning
>>> SBuf15905347 from SBuf183
>>> 2022/10/12 22:29:49.475 kid3| 33,5| client_side.cc(1294)
>>> prepareTlsSwitchingURL: TLS switching host rewrite:
>>> https://categories.articatech.net/fw.ping.php?_=1665576594826
>>> 2022/10/12 22:29:49.475 kid3| 33,5| client_side.cc(1981)
>>> clientParseRequests: conn214046 local=192.168.1.190:3128
>>> remote=192.168.1.13:62858 FD 21 flags=1: done parsing a request
>>> 2022/10/12 22:29:49.475 kid3| 5,4| AsyncCall.cc(30) AsyncCall: The
>>> AsyncCall ConnStateData::lifetimeTimeout constructed,
>>> this=0x56260e5afd50 [call1972958]
>>> 2022/10/12 22:29:49.475 kid3| 5,3| comm.cc(571) commSetConnTimeout:
>>> conn214046 local=192.168.1.190:3128 remote=192.168.1.13:62858 FD 21
>>> flags=1 timeout 86400
>>> 2022/10/12 22:29:49.475 kid3| 55,7| HttpHeader.cc(194) clean:
>>> cleaning hdr: 0x56260e392c18 owner: 3
>>> 2022/10/12 22:29:49.475 kid3| 55,7| HttpHeader.cc(194) clean:
>>> cleaning hdr: 0x56260e392c18 owner: 3
>>> 2022/10/12 22:29:49.475 kid3| 33,3| client_side.cc(1806) add:
>>> 0x56260e0f9210*3 to 0/1
>>> 2022/10/12 22:29:49.475 kid3| 33,3| Pipeline.cc(24) add: Pipeline
>>> 0x56260e6cd470 add request 2 0x56260e0f9210*4
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905349
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 61 for SBuf15905349
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905349 new store capacity: 128
>>> 2022/10/12 22:29:49.475 kid3| 55,7| HttpHeader.cc(155) HttpHeader:
>>> init-ing hdr: 0x56260e4038f8 owner: 2
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(763) findFirstNotOf:
>>> first not of characterset special in id SBuf15905363
>>> 2022/10/12 22:29:49.475 kid3| 24,5| Tokenizer.cc(27) consume:
>>> consuming 5 bytes
>>> 2022/10/12 22:29:49.475 kid3| 24,5| Tokenizer.cc(27) consume:
>>> consuming 1 bytes
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(85) assign: assigning
>>> SBuf15905367 from SBuf183
>>> 2022/10/12 22:29:49.475 kid3| 24,5| Tokenizer.cc(27) consume:
>>> consuming 2 bytes
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 1 for SBuf15905371
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(167) rawSpace:
>>> SBuf15905371 not growing
>>> 2022/10/12 22:29:49.475 kid3| 23,3| Uri.cc(441) parse: Split URL
>>> 'https://categories.articatech.net/fw.ping.php?_=1665576594826' into
>>> proto='https', host='categories.articatech.net', port='443',
>>> path='/fw.ping.php?_=1665576594826'
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(85) assign: assigning
>>> SBuf15905351 from SBuf15905361
>>> 2022/10/12 22:29:49.475 kid3| 24,6| SBuf.cc(99) assign: SBuf15905353
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905353
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 28 for SBuf15905353
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905353 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 14,3| Address.cc(389) lookupHostIP:
>>> Given Non-IP 'categories.articatech.net': Name or service not known
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905373
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 0 for SBuf15905373
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(167) rawSpace:
>>> SBuf15905373 not growing
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(85) assign: assigning
>>> SBuf15905352 from SBuf15905373
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(85) assign: assigning
>>> SBuf15905350 from SBuf15905305
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 1 for SBuf15905374
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(167) rawSpace:
>>> SBuf15905374 not growing
>>> 2022/10/12 22:29:49.475 kid3| 55,7| HttpHeader.cc(390) parse: parsing
>>> hdr: (0x56260e4038f8)
>>> Host: categories.articatech.net
>>> User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:105.0)
>>> Gecko/20100101 Firefox/105.0
>>> Accept: */*
>>> Accept-Language: fr,fr-FR;q=0.8,en-US;q=0.5,en;q=0.3
>>> Accept-Encoding: gzip, deflate, br
>>> Referer: https://categories.articatech.net/index
>>> X-Requested-With: XMLHttpRequest
>>> Connection: keep-alive
>>> Cookie: _ga=GA1.2.1172828951.1642984448;
>>> PHPSESSID=28871210b5b031a7b034981e9704a4ac
>>> Sec-Fetch-Dest: empty
>>> Sec-Fetch-Mode: cors
>>> Sec-Fetch-Site: same-origin
>>>
>>> 2022/10/12 22:29:49.475 kid3| 24,6| SBuf.cc(99) assign: SBuf15905375
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905375
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 4 for SBuf15905375
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905375 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 24,6| SBuf.cc(99) assign: SBuf15905376
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905376
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 4 for SBuf15905376
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905376 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e4038f8 adding entry: Host[30] at 0
>>> 2022/10/12 22:29:49.475 kid3| 24,6| SBuf.cc(99) assign: SBuf15905377
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905377
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 10 for SBuf15905377
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905377 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 24,6| SBuf.cc(99) assign: SBuf15905378
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905378
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 10 for SBuf15905378
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905378 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e4038f8 adding entry: User-Agent[67] at 1
>>> 2022/10/12 22:29:49.475 kid3| 24,6| SBuf.cc(99) assign: SBuf15905379
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905379
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 6 for SBuf15905379
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905379 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 24,6| SBuf.cc(99) assign: SBuf15905380
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905380
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 6 for SBuf15905380
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905380 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e4038f8 adding entry: Accept[0] at 2
>>> 2022/10/12 22:29:49.475 kid3| 24,6| SBuf.cc(99) assign: SBuf15905381
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905381
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 15 for SBuf15905381
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905381 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 24,6| SBuf.cc(99) assign: SBuf15905382
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905382
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 15 for SBuf15905382
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905382 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e4038f8 adding entry: Accept-Language[3] at 3
>>> 2022/10/12 22:29:49.475 kid3| 24,6| SBuf.cc(99) assign: SBuf15905383
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905383
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 15 for SBuf15905383
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905383 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 24,6| SBuf.cc(99) assign: SBuf15905384
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905384
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 15 for SBuf15905384
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905384 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e4038f8 adding entry: Accept-Encoding[2] at 4
>>> 2022/10/12 22:29:49.475 kid3| 24,6| SBuf.cc(99) assign: SBuf15905385
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905385
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 7 for SBuf15905385
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905385 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 24,6| SBuf.cc(99) assign: SBuf15905386
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905386
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 7 for SBuf15905386
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905386 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e4038f8 adding entry: Referer[54] at 5
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905387
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 16 for SBuf15905387
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905387 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(85) assign: assigning
>>> SBuf15905388 from SBuf15905387
>>> 2022/10/12 22:29:49.475 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e4038f8 adding entry: Other:[87] at 6
>>> 2022/10/12 22:29:49.475 kid3| 24,6| SBuf.cc(99) assign: SBuf15905389
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905389
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 10 for SBuf15905389
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905389 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 24,6| SBuf.cc(99) assign: SBuf15905390
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905390
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 10 for SBuf15905390
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905390 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e4038f8 adding entry: Connection[12] at 7
>>> 2022/10/12 22:29:49.475 kid3| 24,6| SBuf.cc(99) assign: SBuf15905391
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905391
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 6 for SBuf15905391
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905391 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 24,6| SBuf.cc(99) assign: SBuf15905392
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905392
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 6 for SBuf15905392
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905392 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e4038f8 adding entry: Cookie[22] at 8
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905393
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 14 for SBuf15905393
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905393 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(85) assign: assigning
>>> SBuf15905394 from SBuf15905393
>>> 2022/10/12 22:29:49.475 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e4038f8 adding entry: Other:[87] at 9
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905395
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 14 for SBuf15905395
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905395 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(85) assign: assigning
>>> SBuf15905396 from SBuf15905395
>>> 2022/10/12 22:29:49.475 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e4038f8 adding entry: Other:[87] at 10
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905397
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 14 for SBuf15905397
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905397 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(85) assign: assigning
>>> SBuf15905398 from SBuf15905397
>>> 2022/10/12 22:29:49.475 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e4038f8 adding entry: Other:[87] at 11
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905355
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 25 for SBuf15905355
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905355 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(85) assign: assigning
>>> SBuf15905354 from SBuf15905355
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 6 for SBuf15905355
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(167) rawSpace:
>>> SBuf15905355 not growing
>>> 2022/10/12 22:29:49.475 kid3| 33,5| Http1Server.cc(193)
>>> buildHttpRequest: normalize 1 Host header using
>>> categories.articatech.net
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 1 for SBuf15905399
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905399 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 24,6| SBuf.cc(99) assign: SBuf15905401
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905401
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 4 for SBuf15905401
>>> 2022/10/12 22:29:49.475 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905401 new store capacity: 40
>>> 2022/10/12 22:29:49.475 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e4038f8 adding entry: Host[30] at 12
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905356 new store capacity: 16384
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 5 for SBuf15905356
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(167) rawSpace:
>>> SBuf15905356 not growing
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905356
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 1 for SBuf15905356
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(167) rawSpace:
>>> SBuf15905356 not growing
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905356
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 2 for SBuf15905356
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(167) rawSpace:
>>> SBuf15905356 not growing
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 25 for SBuf15905356
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(167) rawSpace:
>>> SBuf15905356 not growing
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 28 for SBuf15905356
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(167) rawSpace:
>>> SBuf15905356 not growing
>>> 2022/10/12 22:29:49.476 kid3| 33,3| client_side.cc(699)
>>> clientSetKeepaliveFlag: http_ver = HTTP/1.1
>>> 2022/10/12 22:29:49.476 kid3| 33,3| client_side.cc(700)
>>> clientSetKeepaliveFlag: method = GET
>>> 2022/10/12 22:29:49.476 kid3| 55,6| HttpHeader.cc(850) getList:
>>> 0x56260e4038f8: joined for id Connection[12]: 0x7ffc7248c400
>>> 2022/10/12 22:29:49.476 kid3| 33,4| client_side.cc(1510)
>>> quitAfterError: Will close after error: conn214046
>>> local=192.168.1.190:3128 remote=192.168.1.13:62858 FD 21 flags=1
>>> 2022/10/12 22:29:49.476 kid3| 33,5| client_side.cc(1531)
>>> serveDelayedError: Responding with delated error for
>>> https://categories.articatech.net/fw.ping.php?_=1665576594826
>>> 2022/10/12 22:29:49.476 kid3| 20,3| store.cc(443) lock:
>>> clientReplyContext::setReplyToStoreEntry locked key
>>> AFC90000000000002632000003000000 e:=sp2XIV/0x56260e1b8290*2
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Checklist.cc(70) preCheck:
>>> 0x7ffc7248c000 checking fast rules
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Checklist.cc(343) fastCheck:
>>> aclCheckFast: list: 0x56260c88d7a8
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking
>>> delay_access
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Checklist.cc(398) bannedAction:
>>> Action 'ALLOWED/0' is not banned
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking
>>> delay_access#1
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking Group2
>>> 2022/10/12 22:29:49.476 kid3| 28,3| DomainData.cc(110) match:
>>> aclMatchDomainList: checking 'categories.articatech.net'
>>> 2022/10/12 22:29:49.476 kid3| 28,3| DomainData.cc(115) match:
>>> aclMatchDomainList: 'categories.articatech.net' NOT found
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked:
>>> Group2 = 0
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked:
>>> delay_access#1 = 0
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Checklist.cc(398) bannedAction:
>>> Action 'DENIED/0' is not banned
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking
>>> delay_access#2
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking all
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Ip.cc(538) match: aclIpMatchIp:
>>> '192.168.1.13:62858' found
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked: all
>>> = 1
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked:
>>> delay_access#2 = 1
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked:
>>> delay_access = 1
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Checklist.cc(63) markFinished:
>>> 0x7ffc7248c000 answer DENIED for match
>>> 2022/10/12 22:29:49.476 kid3| 28,4| FilledChecklist.cc(67)
>>> ~ACLFilledChecklist: ACLFilledChecklist destroyed 0x7ffc7248c000
>>> 2022/10/12 22:29:49.476 kid3| 28,4| Checklist.cc(197) ~ACLChecklist:
>>> ACLChecklist::~ACLChecklist: destroyed 0x7ffc7248c000
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Checklist.cc(70) preCheck:
>>> 0x7ffc7248c000 checking fast rules
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Checklist.cc(343) fastCheck:
>>> aclCheckFast: list: 0x56260c8c46a8
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking
>>> delay_access
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Checklist.cc(398) bannedAction:
>>> Action 'ALLOWED/0' is not banned
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking
>>> delay_access#1
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking Group2
>>> 2022/10/12 22:29:49.476 kid3| 28,3| DomainData.cc(110) match:
>>> aclMatchDomainList: checking 'categories.articatech.net'
>>> 2022/10/12 22:29:49.476 kid3| 28,3| DomainData.cc(115) match:
>>> aclMatchDomainList: 'categories.articatech.net' NOT found
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked:
>>> Group2 = 0
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked:
>>> delay_access#1 = 0
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Checklist.cc(398) bannedAction:
>>> Action 'DENIED/0' is not banned
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking
>>> delay_access#2
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking all
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Ip.cc(538) match: aclIpMatchIp:
>>> '192.168.1.13:62858' found
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked: all
>>> = 1
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked:
>>> delay_access#2 = 1
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked:
>>> delay_access = 1
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Checklist.cc(63) markFinished:
>>> 0x7ffc7248c000 answer DENIED for match
>>> 2022/10/12 22:29:49.476 kid3| 28,4| FilledChecklist.cc(67)
>>> ~ACLFilledChecklist: ACLFilledChecklist destroyed 0x7ffc7248c000
>>> 2022/10/12 22:29:49.476 kid3| 28,4| Checklist.cc(197) ~ACLChecklist:
>>> ACLChecklist::~ACLChecklist: destroyed 0x7ffc7248c000
>>> *2022/10/12 22:29:49.476 kid3| 4,3| Error.cc(22) update: recent:
>>> ERR_READ_ERROR/WITH_SERVER*
>>> 2022/10/12 22:29:49.476 kid3| 33,5| Stream.cc(117) pullData: 0
>>> written 0 into conn214046 local=192.168.1.190:3128
>>> remote=192.168.1.13:62858 FD 21 flags=1
>>> 2022/10/12 22:29:49.476 kid3| 33,5| Stream.cc(141)
>>> getNextRangeOffset: range: 0; http offset 0; reply 0
>>> 2022/10/12 22:29:49.476 kid3| 87,3| clientStream.cc(180)
>>> clientStreamRead: clientStreamRead: Calling 1 with cbdata
>>> 0x56260e0d2ba8 from node 0x56260e6d26f8
>>> 2022/10/12 22:29:49.476 kid3| 90,3| store_client.cc(246) copy:
>>> store_client::copy: AFC90000000000002632000003000000, from 0, for
>>> length 4096, cb 1, cbdata 0x56260e0d1ad8
>>> 2022/10/12 22:29:49.476 kid3| 20,3| store.cc(443) lock:
>>> store_client::copy locked key AFC90000000000002632000003000000
>>> e:=sp2XIV/0x56260e1b8290*3
>>> 2022/10/12 22:29:49.476 kid3| 90,3| store_client.cc(338)
>>> storeClientCopy2: storeClientCopy2: AFC90000000000002632000003000000
>>> 2022/10/12 22:29:49.476 kid3| 33,5| store_client.cc(368) doCopy:
>>> store_client::doCopy: co: 0, hi: 506665
>>> 2022/10/12 22:29:49.476 kid3| 90,3| store_client.cc(472)
>>> scheduleMemRead: store_client::doCopy: Copying normal from memory
>>> 2022/10/12 22:29:49.476 kid3| 19,6| stmem.cc(230) copy: memCopy:
>>> 0x56260db339f8 [0,4096)
>>> 2022/10/12 22:29:49.476 kid3| 88,5| client_side_reply.cc(2213)
>>> sendMoreData: conn214046 local=192.168.1.190:3128
>>> remote=192.168.1.13:62858 FD 21 flags=1
>>> 'categories.articatech.net:443' out.offset=0
>>> 2022/10/12 22:29:49.476 kid3| 88,5| client_side_reply.cc(2241)
>>> sendMoreData: clientReplyContext::sendMoreData:
>>> https://categories.articatech.net/fw.ping.php?_=1665576594826, 4096
>>> bytes (4096 new bytes)
>>> 2022/10/12 22:29:49.476 kid3| 55,7| HttpHeader.cc(155) HttpHeader:
>>> init-ing hdr: 0x56260e392c18 owner: 3
>>> 2022/10/12 22:29:49.476 kid3| 55,7| HttpHeader.cc(243) append:
>>> appending hdr: 0x56260e392c18 += 0x56260db7a728
>>> 2022/10/12 22:29:49.476 kid3| 24,6| SBuf.cc(99) assign: SBuf15905409
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905409
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 6 for SBuf15905409
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905409 new store capacity: 40
>>> 2022/10/12 22:29:49.476 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e392c18 adding entry: Server[57] at 0
>>> 2022/10/12 22:29:49.476 kid3| 24,6| SBuf.cc(99) assign: SBuf15905410
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905410
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 12 for SBuf15905410
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905410 new store capacity: 40
>>> 2022/10/12 22:29:49.476 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e392c18 adding entry: Mime-Version[43] at 1
>>> 2022/10/12 22:29:49.476 kid3| 24,6| SBuf.cc(99) assign: SBuf15905411
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905411
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 4 for SBuf15905411
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905411 new store capacity: 40
>>> 2022/10/12 22:29:49.476 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e392c18 adding entry: Date[24] at 2
>>> 2022/10/12 22:29:49.476 kid3| 24,6| SBuf.cc(99) assign: SBuf15905412
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905412
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 12 for SBuf15905412
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905412 new store capacity: 40
>>> 2022/10/12 22:29:49.476 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e392c18 adding entry: Content-Type[21] at 3
>>> 2022/10/12 22:29:49.476 kid3| 24,6| SBuf.cc(99) assign: SBuf15905413
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905413
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 14 for SBuf15905413
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905413 new store capacity: 40
>>> 2022/10/12 22:29:49.476 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e392c18 adding entry: Content-Length[17] at 4
>>> 2022/10/12 22:29:49.476 kid3| 24,6| SBuf.cc(99) assign: SBuf15905414
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905414
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 13 for SBuf15905414
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905414 new store capacity: 40
>>> 2022/10/12 22:29:49.476 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e392c18 adding entry: X-Squid-Error[76] at 5
>>> 2022/10/12 22:29:49.476 kid3| 66,7| HttpHeaderTools.cc(156)
>>> httpHeaderParseOffset: offset 506470 parsed as 506470
>>> 2022/10/12 22:29:49.476 kid3| 66,7| HttpHeaderTools.cc(156)
>>> httpHeaderParseOffset: offset 506470 parsed as 506470
>>> 2022/10/12 22:29:49.476 kid3| 24,6| SBuf.cc(99) assign: SBuf15905416
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905416
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 7 for SBuf15905416
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905416 new store capacity: 40
>>> 2022/10/12 22:29:49.476 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e392c18 adding entry: X-Cache[72] at 6
>>> 2022/10/12 22:29:49.476 kid3| 33,2| client_side_reply.cc(1585)
>>> buildReplyHeader: clientBuildReplyHeader: Connection Keep-Alive not
>>> requested by admin or client
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 16 for SBuf15905417
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905417 new store capacity: 40
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 96 for SBuf15905417
>>> 2022/10/12 22:29:49.476 kid3| 24,7| MemBlob.cc(130) syncSize: 0 was: 0
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905417 new store capacity: 128
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(85) assign: assigning
>>> SBuf15905418 from SBuf15905417
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 1 for SBuf15905418
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(167) rawSpace:
>>> SBuf15905418 not growing
>>> 2022/10/12 22:29:49.476 kid3| 24,6| SBuf.cc(99) assign: SBuf15905420
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905420
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 3 for SBuf15905420
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905420 new store capacity: 40
>>> 2022/10/12 22:29:49.476 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e392c18 adding entry: Via[69] at 7
>>> 2022/10/12 22:29:49.476 kid3| 24,6| SBuf.cc(99) assign: SBuf15905422
>>> from c-string, n=4294967295)
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(209) append: from
>>> c-string to id SBuf15905422
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(160) rawSpace: reserving
>>> 10 for SBuf15905422
>>> 2022/10/12 22:29:49.476 kid3| 24,7| SBuf.cc(866) reAlloc:
>>> SBuf15905422 new store capacity: 40
>>> 2022/10/12 22:29:49.476 kid3| 55,7| HttpHeader.cc(786) addEntry:
>>> 0x56260e392c18 adding entry: Connection[12] at 8
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Checklist.cc(70) preCheck:
>>> 0x7ffc7248bb70 checking fast rules
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Checklist.cc(343) fastCheck:
>>> aclCheckFast: list: 0x56260c8adf68
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking
>>> http_header_access Server
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Checklist.cc(398) bannedAction:
>>> Action 'DENIED/0' is not banned
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking
>>> http_header_access Server#1
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking all
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Ip.cc(538) match: aclIpMatchIp:
>>> '192.168.1.13:62858' found
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked: all
>>> = 1
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked:
>>> http_header_access Server#1 = 1
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked:
>>> http_header_access Server = 1
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Checklist.cc(63) markFinished:
>>> 0x7ffc7248bb70 answer DENIED for match
>>> 2022/10/12 22:29:49.476 kid3| 66,7| HttpHeaderTools.cc(308)
>>> httpHdrMangle: checklist denied, we have no replacement. Pass
>>> 2022/10/12 22:29:49.476 kid3| 28,4| FilledChecklist.cc(67)
>>> ~ACLFilledChecklist: ACLFilledChecklist destroyed 0x7ffc7248bb70
>>> 2022/10/12 22:29:49.476 kid3| 28,4| Checklist.cc(197) ~ACLChecklist:
>>> ACLChecklist::~ACLChecklist: destroyed 0x7ffc7248bb70
>>> 2022/10/12 22:29:49.476 kid3| 66,7| HttpHeaderTools.cc(286)
>>> httpHdrMangle: couldn't find mangler or access list. Allowing
>>> 2022/10/12 22:29:49.476 kid3| 66,7| HttpHeaderTools.cc(286)
>>> httpHdrMangle: couldn't find mangler or access list. Allowing
>>> 2022/10/12 22:29:49.476 kid3| 66,7| HttpHeaderTools.cc(286)
>>> httpHdrMangle: couldn't find mangler or access list. Allowing
>>> 2022/10/12 22:29:49.476 kid3| 66,7| HttpHeaderTools.cc(286)
>>> httpHdrMangle: couldn't find mangler or access list. Allowing
>>> 2022/10/12 22:29:49.476 kid3| 66,7| HttpHeaderTools.cc(286)
>>> httpHdrMangle: couldn't find mangler or access list. Allowing
>>> 2022/10/12 22:29:49.476 kid3| 66,7| HttpHeaderTools.cc(286)
>>> httpHdrMangle: couldn't find mangler or access list. Allowing
>>> 2022/10/12 22:29:49.476 kid3| 66,7| HttpHeaderTools.cc(286)
>>> httpHdrMangle: couldn't find mangler or access list. Allowing
>>> 2022/10/12 22:29:49.476 kid3| 66,7| HttpHeaderTools.cc(286)
>>> httpHdrMangle: couldn't find mangler or access list. Allowing
>>> 2022/10/12 22:29:49.476 kid3| 55,7| HttpHeader.cc(769) refreshMask:
>>> refreshing the mask in hdr 0x56260e392c18
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Checklist.cc(70) preCheck:
>>> 0x7ffc7248bcb0 checking fast rules
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Checklist.cc(343) fastCheck:
>>> aclCheckFast: list: 0x56260c88d7a8
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking
>>> delay_access
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Checklist.cc(398) bannedAction:
>>> Action 'ALLOWED/0' is not banned
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking
>>> delay_access#1
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking Group2
>>> 2022/10/12 22:29:49.476 kid3| 28,3| DomainData.cc(110) match:
>>> aclMatchDomainList: checking 'categories.articatech.net'
>>> 2022/10/12 22:29:49.476 kid3| 28,3| DomainData.cc(115) match:
>>> aclMatchDomainList: 'categories.articatech.net' NOT found
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked:
>>> Group2 = 0
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked:
>>> delay_access#1 = 0
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Checklist.cc(398) bannedAction:
>>> Action 'DENIED/0' is not banned
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking
>>> delay_access#2
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking all
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Ip.cc(538) match: aclIpMatchIp:
>>> '192.168.1.13:62858' found
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked: all
>>> = 1
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked:
>>> delay_access#2 = 1
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked:
>>> delay_access = 1
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Checklist.cc(63) markFinished:
>>> 0x7ffc7248bcb0 answer DENIED for match
>>> 2022/10/12 22:29:49.476 kid3| 28,4| FilledChecklist.cc(67)
>>> ~ACLFilledChecklist: ACLFilledChecklist destroyed 0x7ffc7248bcb0
>>> 2022/10/12 22:29:49.476 kid3| 28,4| Checklist.cc(197) ~ACLChecklist:
>>> ACLChecklist::~ACLChecklist: destroyed 0x7ffc7248bcb0
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Checklist.cc(70) preCheck:
>>> 0x7ffc7248bcb0 checking fast rules
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Checklist.cc(343) fastCheck:
>>> aclCheckFast: list: 0x56260c8c46a8
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking
>>> delay_access
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Checklist.cc(398) bannedAction:
>>> Action 'ALLOWED/0' is not banned
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking
>>> delay_access#1
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking Group2
>>> 2022/10/12 22:29:49.476 kid3| 28,3| DomainData.cc(110) match:
>>> aclMatchDomainList: checking 'categories.articatech.net'
>>> 2022/10/12 22:29:49.476 kid3| 28,3| DomainData.cc(115) match:
>>> aclMatchDomainList: 'categories.articatech.net' NOT found
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked:
>>> Group2 = 0
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked:
>>> delay_access#1 = 0
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Checklist.cc(398) bannedAction:
>>> Action 'DENIED/0' is not banned
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking
>>> delay_access#2
>>> 2022/10/12 22:29:49.476 kid3| 28,5| Acl.cc(124) matches: checking all
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Ip.cc(538) match: aclIpMatchIp:
>>> '192.168.1.13:62858' found
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked: all
>>> = 1
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked:
>>> delay_access#2 = 1
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Acl.cc(151) matches: checked:
>>> delay_access = 1
>>> 2022/10/12 22:29:49.476 kid3| 28,3| Checklist.cc(63) markFinished:
>>> 0x7ffc7248bcb0 answer DENIED for match
>>> 2022/10/12 22:29:49.476 kid3| 28,4| FilledChecklist.cc(67)
>>> ~ACLFilledChecklist: ACLFilledChecklist destroyed 0x7ffc7248bcb0
>>> 2022/10/12 22:29:49.477 kid3| 28,4| Checklist.cc(197) ~ACLChecklist:
>>> ACLChecklist::~ACLChecklist: destroyed 0x7ffc7248bcb0
>>> 2022/10/12 22:29:49.477 kid3| 28,3| Checklist.cc(70) preCheck:
>>> 0x7ffc7248bc10 checking fast ACLs
>>> 2022/10/12 22:29:49.477 kid3| 28,5| Acl.cc(124) matches: checking
>>> reply_body_max_size -1
>>> 2022/10/12 22:29:49.477 kid3| 28,5| Acl.cc(124) matches: checking
>>> (reply_body_max_size -1 line)
>>> 2022/10/12 22:29:49.477 kid3| 28,3| Acl.cc(151) matches: checked:
>>> (reply_body_max_size -1 line) = 1
>>> 2022/10/12 22:29:49.477 kid3| 28,3| Acl.cc(151) matches: checked:
>>> reply_body_max_size -1 = 1
>>> 2022/10/12 22:29:49.477 kid3| 28,3| Checklist.cc(63) markFinished:
>>> 0x7ffc7248bc10 answer ALLOWED for match
>>> 2022/10/12 22:29:49.477 kid3| 58,4| HttpReply.cc(564)
>>> calcMaxBodySize: bodySizeMax=-1
>>> 2022/10/12 22:29:49.477 kid3| 28,4| FilledChecklist.cc(67)
>>> ~ACLFilledChecklist: ACLFilledChecklist destroyed 0x7ffc7248bc10
>>> 2022/10/12 22:29:49.477 kid3| 28,4| Checklist.cc(197) ~ACLChecklist:
>>> ACLChecklist::~ACLChecklist: destroyed 0x7ffc7248bc10
>>> 2022/10/12 22:29:49.477 kid3| 58,7| HttpReply.cc(528)
>>> expectedBodyTooLarge: bodySizeMax=-1
>>> 2022/10/12 22:29:49.477 kid3| 88,2| client_side_reply.cc(2090)
>>> processReplyAccessResult: The reply for GET
>>> https://categories.articatech.net/fw.ping.php?_=1665576594826 is
>>> ALLOWED, because it matched (reply_body_max_size -1 line)
>>> 2022/10/12 22:29:49.477 kid3| 20,3| store.cc(443) lock:
>>> ClientHttpRequest::loggingEntry locked key
>>> AFC90000000000002632000003000000 e:=sp2XIV/0x56260e1b8290*4
>>> 2022/10/12 22:29:49.477 kid3| 88,3| client_side_reply.cc(2128)
>>> processReplyAccessResult: clientReplyContext::sendMoreData: Appending
>>> 3901 bytes after 195 bytes of headers
>>> 2022/10/12 22:29:49.477 kid3| 87,3| clientStream.cc(158)
>>> clientStreamCallback: clientStreamCallback: Calling 1 with cbdata
>>> 0x56260e0fa280 from node 0x56260e5c0ab8
>>> 2022/10/12 22:29:49.477 kid3| 33,3| Pipeline.cc(35) front: Pipeline
>>> 0x56260e6cd470 front 0x56260e0f9210*4
>>> 2022/10/12 22:29:49.477 kid3| 33,3| Pipeline.cc(35) front: Pipeline
>>> 0x56260e6cd470 front 0x56260e0f9210*4
>>> 2022/10/12 22:29:49.477 kid3| 55,7| HttpHeader.cc(589) packInto:
>>> 0x56260e392c18 into 0x56260e26ebe8
>>> 2022/10/12 22:29:49.477 kid3| 11,2| Stream.cc(279)
>>> sendStartOfMessage: HTTP Client conn214046 local=192.168.1.190:3128
>>> remote=192.168.1.13:62858 FD 21 flags=1
>>> 2022/10/12 22:29:49.477 kid3| 11,2| Stream.cc(280)
>>> sendStartOfMessage: HTTP Client REPLY:
>>> ---------
>>> HTTP/1.1 502 Bad Gateway
>>> Mime-Version: 1.0
>>> Date: Wed, 12 Oct 2022 20:29:49 GMT
>>> Content-Type: text/html;charset=utf-8
>>> Content-Length: 506470
>>> X-Squid-Error: ERR_READ_ERROR 0
>>> X-Cache: MISS from proxy-190.articatech.int
>>> Via: 1.1 789aaa51-a1eb-eb48-639b-000070877aed (squid)
>>> Connection: close
>>>
>>>
>>> Le 12/10/2022 à 20:00, Alex Rousskov a écrit :
>>>> On 10/12/22 12:45, David Touzeau wrote:
>>>>> Hi
>>>>>
>>>>> We using squid 5.7 after adding ssl-bump we have sometimes several
>>>>> 502 error with extended error ERR_READ_ERROR|WITH_SERVER
>>>>>
>>>>> 1665589818.831 11 192.168.1.13 NONE_NONE/502 192616 OPTIONS
>>>>> https://www2.deepl.com/jsonrpc?method=LMT_split_text -
>>>>> HIER_NONE/-:- text/html mac="68:54:5a:94:e7:56" -
>>>>> exterr="ERR_READ_ERROR|WITH_SERVER"
>>>>> 1665589839.288 11 192.168.1.13 NONE_NONE/502 506759 POST
>>>>> https://pollserver.lastpass.com/poll_server.php - HIER_NONE/-:-
>>>>> text/html mac="68:54:5a:94:e7:56" -
>>>>> exterr="ERR_READ_ERROR|WITH_SERVER"
>>>>> 1665589719.879 44 192.168.1.13 NONE_NONE/502 506954 GET
>>>>> https://contile.services.mozilla.com/v1/tiles - HIER_NONE/-:-
>>>>> text/html mac="68:54:5a:94:e7:56" -
>>>>> exterr="ERR_READ_ERROR|WITH_SERVER"
>>>>
>>>>> What does it means.
>>>>
>>>> 502 with ERR_READ_ERROR|WITH_SERVER may mean several things
>>>> (unfortunately). Given HIER_NONE, I would suspect that Squid could
>>>> not find a valid destination for the request. There is a similar
>>>> recent squid-users thread at
>>>> http://lists.squid-cache.org/pipermail/squid-users/2022-October/025289.html
>>>>
>>>>
>>>>
>>>>> how can we fix it ?
>>>>
>>>> The first step is to identify what causes these errors.
>>>>
>>>> Can you reproduce this problem at will? Perhaps by trying going to
>>>> https://dnslabeldoesnotexist.com mentioned at the above thread? If
>>>> you can, consider sharing (a pointer to) a compressed debugging
>>>> cache.log from a test box that does not expose any internal secrets,
>>>> as detailed at
>>>> https://wiki.squid-cache.org/SquidFaq/BugReporting#Debugging_a_single_transaction
>>>>
>>>>
>>>>
>>>> HTH,
>>>>
>>>> Alex.
>>>> _______________________________________________
>>>> squid-users mailing list
>>>> squid-users at lists.squid-cache.org
>>>> http://lists.squid-cache.org/listinfo/squid-users
>>
> --
> Technical Support
>
>
> *David Touzeau*
> Orgerus, Yvelines, France
> *Artica Tech*
>
> P: +33 6 58 44 69 46
> www: wiki.articatech.com <https://wiki.articatech.com>
> www: articatech.net <http://articatech.net>
>
More information about the squid-users
mailing list