On 24/02/16 17:01, Martin Byrenheid wrote:
> On Wednesday, February 24, 2016 04:13:42 PM Matthew Toseland wrote:
>> On Wed, Feb 24, 2016 at 03:39:05PM +0100, Martin Byrenheid wrote:
>>> On Tuesday, February 23, 2016 09:18:17 PM Martin Byrenheid wrote:
>>>> On Tuesday, February 23, 2016 06:45:46 PM Matthew Toseland wrote:
>>>>> Bandwidth limiting, message priorities, something of that nature. The
>>>>> point is it shouldn't actually complete the AnnounceSender and close
>>>>> the
>>>>> connection until existing transfers have completed. Which is why
>>>>> complete() waits for all transfers to finish. Unfortunately we don't
>>>>> call complete() in the case of an RNF! AFAICS the solution is to copy
>>>>> the wait loop from complete() into rnf(). Patches welcome. :)
>>>> Okay, I will try it out! Thanks!
>>> I've changed the code but came across another similar problem :-/
>>>
>>> The scenario again is that an Opennet node O sent an announce request to a
>>> seed node S. S wants O as an opennet peer and therefore sends an announce
>>> reply followed by three packets carrying its noderef. However, the first
>>> packet of the noderef-transfer gets processed too early so that it gets
>>> fed to the dispatcher and dropped as not routable. Although the rest of
>>> the packets gets received correctly, the noderef-transfer fails. Excerpts
>>> from the corresponding log file of the opennet node O:
>>>
>>> O receives the announce reply and the first packet from the
>>> noderef-transfer:
>>>
>>> Feb 24, 2016 14:02:47:295 (freenet.node.NewPacketFormat, UdpSocketHandler
>>> for port 14834(1), MINOR): Decoded messages: 3 Feb 24, 2016 14:02:47:295
>>> (freenet.io.comm.Message, UdpSocketHandler for port 14834(1), MINOR):
>>> Returning message: FNPBulkReceivedAll {uid=5291246903919677492} from
>>> freenet.node.SeedServerPeerNode@[email protected]:14833@9d09a2e706d48
>>> e25b685cc5413ebd3ee47638c20d62a0817a70d7c3323321e01@29b23591 Feb 24, 2016
>>> 14:02:47:296 (freenet.io.comm.Message, UdpSocketHandler for port
>>> 14834(1), MINOR): Returning message: FNPOpennetAnnounceReply
>>> {uid=77823964067048 33260, noderefLength=503, paddedLength=3072,
>>> transferUID=8684549569896827466} from
>>> freenet.node.SeedServerPeerNode@[email protected]:14833@9d09a2e706d48
>>> e2 5b685cc5413ebd3ee47638c20d62a0817a70d7c3323321e01@29b23591
>>> Feb 24, 2016 14:02:47:296 (freenet.io.comm.Message, UdpSocketHandler for
>>> port 14834(1), MINOR): Returning message: FNPBulkPacketSend
>>> {uid=8684549569896827466,>
>>> data=Buffer {1024}, packetNo=0} from
>>> freenet.node.SeedServerPeerNode@[email protected]:14833@9d09a2e706d4
>>> 8e25b685cc5413ebd3ee47638c20d62a0817a70d7c332332>
>>> 1e01@29b23591
>>>
>>> O starts to process the announce reply:
>>>
>>> Feb 24, 2016 14:02:47:296 (freenet.io.comm.MessageCore, Announcer to
>>> freenet.node.SeedServerPeerNode@[email protected]:14833@9d09a2e706d48
>>> e25b685cc5413ebd 3ee47638c20d62a0817a70d7c3323321e01@29b23591(7), MINOR):
>>> Returning FNPOpennetAnnounceReply {uid=7782396406704833260,
>>> noderefLength=503, paddedLength=3072, tra nsferUID=8684549569896827466}
>>> from freenet.io.comm.MessageFilter@4d392d4e:FNPOpennetAnnounceCompleted
>>>
>>> Shortly before O finished processing the reply, the first noderef-packet
>>> is fed to the dispatcher and dropped:
>>>
>>> Feb 24, 2016 14:02:47:296 (freenet.io.comm.MessageCore, UdpSocketHandler
>>> for port 14834(1), MINOR): Feeding to dispatcher: FNPBulkPacketSend
>>> {uid=8684549569896827466, data=Buffer {1024}, packetNo=0} Feb 24, 2016
>>> 14:02:47:296 (freenet.node.AnnounceSender, Announcer to
>>> freenet.node.SeedServerPeerNode@[email protected]:14833@9d09a2e706d48
>>> e25b685cc5413ebd3ee47638c20d62a0817a70d7c3323321e01@29b23591(7), DUD):
>>> second part got FNPOpennetAnnounceReply {uid=7782396406704833260,
>>> noderefLength=503, paddedLength=3072, transferUID=8684549569896827466}Feb
>>> 24, 2016 14:02:47:296 (freenet.node.NodeDispatcher, UdpSocketHandler for
>>> port 14834(1), MINOR): Dispatching FNPBulkPacketSend
>>> {uid=8684549569896827466, data=Buffer {1024}, packetNo=0} from
>>> freenet.node.SeedServerPeerNode@[email protected]:14833@9d09a2e706d48
>>> e25b685cc5413ebd3ee47638c20d62a0817a70d7c3323321e01@29b23591 Feb 24, 2016
>>> 14:02:47:296 (freenet.node.NodeDispatcher, UdpSocketHandler for port
>>> 14834(1), DEBUG): Not routable
>>>
>>> O then actually starts waiting for noderef packets:
>>>
>>> Feb 24, 2016 14:02:47:296 (freenet.node.OpennetManager, <noname>(16),
>>> MINOR): Receiving noderef (reply=false) as bulk transfer for request uid
>>> 7782396406704833260 with transfer 8684549569896827466 from
>>> freenet.node.SeedServerPeerNode@[email protected]:14833@9d09a2e706d48
>>> e25b685cc5413ebd3ee47638c20d62a0817a70d7c3323321e01@29b23591
>>>
>>> ... receives the second and third packet:
>>>
>>> Feb 24, 2016 14:02:49:659 (freenet.io.comm.MessageCore, <noname>(16),
>>> MINOR): Returning FNPBulkPacketSend {uid=8684549569896827466, data=Buffer
>>> {1024}, packet No=1} from
>>> freenet.io.comm.MessageFilter@58390365:FNPBulkSendAborted Feb 24, 2016
>>> 14:02:54:867 (freenet.io.comm.MessageCore, <noname>(16), MINOR):
>>> Returning FNPBulkPacketSend {uid=8684549569896827466, data=Buffer {1024},
>>> packetNo=2} from freenet.io.comm.MessageFilter@d1947d5:FNPBulkSendAborted
>>>
>>> and finally aborts because of timeout:
>>>
>>> Feb 24, 2016 14:03:54:868 (freenet.io.comm.MessageCore, <noname>(16),
>>> MINOR): Returning null from
>>> freenet.io.comm.MessageFilter@1125ce48:FNPBulkSendAborted Feb 24, 2016
>>> 14:03:54:868 (freenet.io.comm.MessageCore, <noname>(16), DEBUG):
>>> Returning in 60001ms Feb 24, 2016 14:03:54:868
>>> (freenet.node.SeedServerPeerNode, <noname>(16), MINOR): Sending async:
>>> FNPBulkReceiveAborted {uid=8684549569896827466} : null on
>>> freenet.node.SeedServerPeerNode@[email protected]:14833@9d09a2e706d48
>>> e25b685cc5413ebd3ee47638c20d62a0817a70d7c3323321e01@29b23591 for 34464
>>> priority 2
>> The message should have been matched anyway: Unmatched messages (in
>> MessageCore are added to a data structure and we check before timing out the
>> waitFor()). Possibly a concurrency issue, I thought I'd debugged all such
>> problems ages ago. :(
>>
>> Try this:
>> https://github.com/freenet/fred/pull/504
> I tried it but the problem still persists :-/Well debug it yourself then. I don't have time at the moment, though I'll try to get back to it eventually. It seems unlikely that a race condition like that would happen reliably, so I don't know what is happening here. > Martin
signature.asc
Description: OpenPGP digital signature
_______________________________________________ Devl mailing list [email protected] https://emu.freenetproject.org/cgi-bin/mailman/listinfo/devl
