[squid-users] Too many ERROR: Collapsed forwarding queue overflow for kid2 at 1024 items

Sun Nov 21 19:27:47 UTC 2021

On 11/21/21 2:08 PM, Loučanský Lukáš wrote:
> Hello, I've replaced src/ipc/ReadWritelock.cc and ReadWriteLock.h with
> modified versions (with finalizeExclusive calls), but afeter some time I
> have got queue overflows agains.

After each bug fix, we have to restart the triage sequence from scratch:
Any assertions, crashes, FATAL messages or similar things leading to kid
deaths? If they are present, then they explain queue overflows.

> So I've downloaded squid-6.0.0-20211116-r90086c5a8 - run it with my v5
> configure and now I'm testing it. So far I get these:
> 2021/11/21 19:05:06 kid1| BUG: missing ENTRY_REQUIRES_COLLAPSING for

Noted. If you cannot reproduce this bug at will, then I recommend
focusing on other, easier-to-address problems first.

Alex.

> 2021/11/21 19:05:06 kid1| BUG: missing ENTRY_REQUIRES_COLLAPSING for
> e:tr6455=V/0x5642b8e67480*0
> 2021/11/21 19:05:07 kid1| BUG: missing ENTRY_REQUIRES_COLLAPSING for
> e:tr6455=V/0x5642b7af7b40*0
> 2021/11/21 19:05:07 kid1| BUG: missing ENTRY_REQUIRES_COLLAPSING for
> e:tr6455=V/0x5642b8993850*0
> 2021/11/21 19:05:08 kid1| BUG: missing ENTRY_REQUIRES_COLLAPSING for
> e:tr6455=V/0x5642b5269200*0
> 2021/11/21 19:05:08 kid1| BUG: missing ENTRY_REQUIRES_COLLAPSING for
> e:tr6455=V/0x5642b5269200*0
> 2021/11/21 19:05:18 kid1| BUG: missing ENTRY_REQUIRES_COLLAPSING for
> e:tr6455=V/0x5642b7c91210*0
> 2021/11/21 19:53:48 kid1| Bug: Missing MemObject::storeId value
> 2021/11/21 20:02:16 kid1| BUG: missing ENTRY_REQUIRES_COLLAPSING for
> e:tr11100=V/0x5642b4898050*0
> etc.
> 
> Regard the transient queue - could this be any interesting?
> 
> by kid1 {
> Transients queues:
>   kid1 receiving from kid1: { size: 0, capacity: 1024, other: 112,
> popIndex: 112 }
>   kid1 receiving from kid2: { size: 0, capacity: 1024, other: 1506,
> popIndex: 1506 }
> 
>   kid1 sending to kid1: { size: 0, capacity: 1024, pushIndex: 112,
> other: 112 }
>   kid1 sending to kid2: { size: 0, capacity: 1024, pushIndex: 3301,
> other: 3301 }
> 
> SMP disk I/O queues:
>   kid1 receiving from kid3: { size: 0, capacity: 1024, other: 339,
> popIndex: 339 }
>   kid1 receiving from kid4: { size: 0, capacity: 1024, other: 40,
> popIndex: 40 }
>   kid1 receiving from kid5: { size: 0, capacity: 1024, other: 589,
> popIndex: 589 }
>   kid1 receiving from kid6: { size: 0, capacity: 1024, other: 58192,
> popIndex: 58192 }
> 
>   kid1 sending to kid3: { size: 0, capacity: 1024, pushIndex: 339,
> other: 339 }
>   kid1 sending to kid4: { size: 0, capacity: 1024, pushIndex: 40, other:
> 40 }
>   kid1 sending to kid5: { size: 0, capacity: 1024, pushIndex: 589,
> other: 589 }
>   kid1 sending to kid6: { size: 0, capacity: 1024, pushIndex: 58192,
> other: 58192 }
> } by kid1
> 
> by kid2 {
> Transients queues:
>   kid2 receiving from kid1: { size: 0, capacity: 1024, other: 3301,
> popIndex: 3301 }
>   kid2 receiving from kid2: { size: 0, capacity: 1024, other: 97,
> popIndex: 97 }
> 
>   kid2 sending to kid1: { size: 0, capacity: 1024, pushIndex: 1506,
> other: 1506 }
>   kid2 sending to kid2: { size: 0, capacity: 1024, pushIndex: 97, other:
> 97 }
> 
> SMP disk I/O queues:
>   kid2 receiving from kid3: { size: 0, capacity: 1024, other: 604,
> popIndex: 604 }
>   kid2 receiving from kid4: { size: 0, capacity: 1024, other: 12,
> popIndex: 12 }
>   kid2 receiving from kid5: { size: 0, capacity: 1024, other: 144,
> popIndex: 144 }
>   kid2 receiving from kid6: { size: 0, capacity: 1024, other: 25132,
> popIndex: 25132 }
> 
>   kid2 sending to kid3: { size: 0, capacity: 1024, pushIndex: 604,
> other: 604 }
>   kid2 sending to kid4: { size: 0, capacity: 1024, pushIndex: 12, other:
> 12 }
>   kid2 sending to kid5: { size: 0, capacity: 1024, pushIndex: 144,
> other: 144 }
>   kid2 sending to kid6: { size: 0, capacity: 1024, pushIndex: 25132,
> other: 25132 }
> } by kid2
> 
> by kid3 {
> 
> SMP disk I/O queues:
>   kid3 receiving from kid1: { size: 0, capacity: 1024, other: 339,
> popIndex: 339 }
>   kid3 receiving from kid2: { size: 0, capacity: 1024, other: 604,
> popIndex: 604 }
> 
>   kid3 sending to kid1: { size: 0, capacity: 1024, pushIndex: 339,
> other: 339 }
>   kid3 sending to kid2: { size: 0, capacity: 1024, pushIndex: 604,
> other: 604 }
> } by kid3
> 
> by kid4 {
> 
> SMP disk I/O queues:
>   kid4 receiving from kid1: { size: 0, capacity: 1024, other: 40,
> popIndex: 40 }
>   kid4 receiving from kid2: { size: 0, capacity: 1024, other: 12,
> popIndex: 12 }
> 
>   kid4 sending to kid1: { size: 0, capacity: 1024, pushIndex: 40, other:
> 40 }
>   kid4 sending to kid2: { size: 0, capacity: 1024, pushIndex: 12, other:
> 12 }
> } by kid4
> 
> by kid5 {
> 
> SMP disk I/O queues:
>   kid5 receiving from kid1: { size: 0, capacity: 1024, other: 589,
> popIndex: 589 }
>   kid5 receiving from kid2: { size: 0, capacity: 1024, other: 144,
> popIndex: 144 }
> 
>   kid5 sending to kid1: { size: 0, capacity: 1024, pushIndex: 589,
> other: 589 }
>   kid5 sending to kid2: { size: 0, capacity: 1024, pushIndex: 144,
> other: 144 }
> } by kid5
> 
> by kid6 {
> 
> SMP disk I/O queues:
>   kid6 receiving from kid1: { size: 0, capacity: 1024, other: 58192,
> popIndex: 58192 }
>   kid6 receiving from kid2: { size: 0, capacity: 1024, other: 25132,
> popIndex: 25132 }
> 
>   kid6 sending to kid1: { size: 0, capacity: 1024, pushIndex: 58192,
> other: 58192 }
>   kid6 sending to kid2: { size: 0, capacity: 1024, pushIndex: 25132,
> other: 25132 }
> } by kid6
> 
> Seems like a new item in the cachemgr.cgi menu...
> 
> LL
> 
> 
> -----Původní zpráva-----
> Od: Alex Rousskov [mailto:rousskov at measurement-factory.com
> <mailto:rousskov at measurement-factory.com>]
> Odesláno: út 16.11.2021 19:09
> Komu: Loučanský Lukáš; Squid Users
> Předmět: Re: [squid-users] Too many ERROR: Collapsed forwarding queue
> overflow for kid2 at 1024 items
> 
> On 11/16/21 12:00 PM, Loučanský Lukáš wrote:
> 
>> I will try to backport it from that patch into the v5 tree I've
>> downloaded today. As we were using the mentioned build I came across
>> these new assertions:
> 
>> 2021/11/16 10:29:46 kid1| assertion failed: StoreMap.cc:241:
> "anchorAt(anchorId).reading()"
>> 2021/11/16 11:32:51 kid2| assertion failed: Transients.cc:221: "old == e"
>> 2021/11/16 14:29:41 kid2| assertion failed: store.cc:1108:
> "store_status == STORE_PENDING"
> 
> I hope that at least some of the above assertions are fixed by master/v6
> commit 5210df4.
> 
> 
>> 2021/11/16 17:40:21 kid1| assertion failed: cbdata.cc:372: "c->locks > 0"
>> 2021/11/16 17:40:44 kid1| assertion failed: cbdata.cc:115: "cookie ==
> ((long)this ^ Cookie)"
> 
> This is probably an unrelated bug. I recommend filing a bug report in
> Squid bugzilla and posting the corresponding "bt full" backtrace there.
> 
> 
> Alex.
> 
> 
>> -----Original Message-----
>> From: Alex Rousskov [mailto:rousskov at measurement-factory.com
> <mailto:rousskov at measurement-factory.com>]
>> Sent: Tuesday, November 16, 2021 3:42 PM
>> To: Loučanský Lukáš; Squid Users
>> Subject: Re: [squid-users] Too many ERROR: Collapsed forwarding queue
> overflow for kid2 at 1024 items
>>
>> On 11/16/21 4:38 AM, Loučanský Lukáš wrote:
>>> is it going to be patched only in the v6 version?
>>
>> I hope the existing fix applies to v5 cleanly, and I am ready to help
> with backporting if it does not. Beyond that, it is in the maintainer
> hands. I cannot predict whether or when the fix will be officially
> merged into v5 because I do not understand how
>  those decisions are made.
>>
>>
>>> Anyway - in the morning I run debug with 20,9 to see:
>>> ...
>>> 2021/11/16 09:02:06.496 kid2| assertion failed: Transients.cc:221:
> "old == e"
>>
>> Unfortunately, I cannot see the cause of the assertion in this
> short/partial trace -- the problematic actions happened before the trace
> or were not logged during the trace.
>>
>> Patching your Squid with commit 5210df4 is the best next step IMO. If
> that patch does not help, then there are probably other bugs that we
> need to fix in v5 (at least).
>>
>>
>> HTH,
>>
>> Alex.
>>
>>
> 
> 
> 