Matthew Toseland wrote:
> As I understand it this should only happen every 200ms or so (maybe more
> often because of other things happening, but it shouldn't tie up the
> CPU). Does it tie up the CPU?
>
No, it does not appear to be tying up the CPU, but it does appear that
at least the two events (for the same peer) included below were 10 ms
apart if I read the log format correctly. In any case, every 200 ms
would be 5 times a second I believe, which seems to be little bit often
based on what I've seen of the problem (messages queues growing into the
thousands because of the problem continuing for a long period (looking
into this problem is what led me to the no-packets-sent-when-backed-off
confusion)).
It does massively flood the logs at NORMAL level. Perhaps the messages
could be pruned from three to one per event and/or the log messages
could be limited even if the attempts are not?
If I understand correctly, the unack'd send pool is 128 messages(?) in
size, but the receive counterpart is 512 messages(?). (It's been a
couple days since I looked at that code.)
> On Tue, May 16, 2006 at 08:54:56AM -0500, David Sowder (Zothar) wrote:
>
>> Matthew Toseland wrote:
>>
>>> What is the stack trace? At what point in PacketSender are we trying to
>>> send the messages, or is it from somewhere else?
>>>
>>>
>> Here's a snippet from a stack trace I got after adding the exception
>> to the Logger call: [trimmed for reply]
>>
>> May 16, 2006 13:50:24:844 (freenet.node.PeerNode, PacketSender thread
>> for 0, NORMAL): Requeueing 83 messages on
>> freenet.node.PeerNode@[same_snipped_peer]
>> May 16, 2006 13:50:24:854 (freenet.node.PeerNode, PacketSender thread
>> for 0, NORMAL): Requeueing 83 messages on
>> freenet.node.PeerNode@[same_snipped_peer]
>>
>>
>>> On Mon, May 15, 2006 at 04:23:05PM -0500, David Sowder (Zothar) wrote:
>>>
>>>
>>>> Matthew Toseland wrote:
>>>>
>>>>> Check the stack trace. WouldBlockException is thrown when a peer
>>>>> is so
>>>>> backlogged that we can't allocate a new packet number. So we
>>>>> requeue the
>>>>> messages we need to send, since we have pulled them off the queue in
>>>>> order to send them, and we can't send them yet.=
>>>>>
>>>>>
>>>> OK, it seems I did understand what's going on and apparently
>>>> there's not bigger cause than the peer is backlogged, so it looks
>>>> like I didn't miss anything (which is good).
>>>>
>>>> What do you think of the waiting between queued message send retry
>>>> attempts idea?
>>>>
>>>>
>>>>> On Sun, May 14, 2006 at 01:32:27PM -0500, David Sowder (Zothar)
>>>>> wrote:
>>>>>
>>>>>
>>>>>> Perhaps we should wait a little bit before trying to resend
>>>>>> queued messages? Perhaps the wait time should be proportional to
>>>>>> the number of messages queued, up to some threshold (maybe
>>>>>> keepalive send frequency)?
>>>>>>
>>>>>> According to the source:
>>>>>>
>>>>>> public void requeueMessageItems(MessageItem[] messages, int
>>>>>> offset, int length, boolean dontLog) {
>>>>>> // Will usually indicate serious problems
>>>>>>
>>>>>> What could cause this? Failure to get acks from a peer for awhile?
>>>>>>
>>>>>>
>>>>>>
>>>>>> May 14, 2006 17:54:59:874
>>>>>> (freenet.support.LimitedRangeIntByteArrayMap, PacketSender thread
>>>>>> for 0, NORMAL):
>>>>>> freenet.support.LimitedRangeIntByteArrayMap at 1e64cca WOULD BLOCK:
>>>>>> lockNeverBlock(47574) - minValue = 47446, maxValue = 47446,
>>>>>> maxRange=128
>>>>>> May 14, 2006 17:54:59:874 (freenet.node.FNPPacketMangler,
>>>>>> PacketSender thread for 0, NORMAL): Caught
>>>>>> freenet.support.WouldBlockException while sending messages,
>>>>>> requeueing remaining messages
>>>>>>
