ethereumjs
uTP calls `returnContent` twice
When a uTP content stream wraps up, it appears that we call returnContent twice, either because the sending node is sending 2 FIN packets or the FIN packet handler is being called more than once.
7c20:Portal:uTP:RECEIVED:ST_STATE || seqNr: 2164 || +0ms
f7c20:Portal:uTP:RECEIVED:ST_STATE || ackNr: 2162 || +0ms
f7c20:Portal:uTP:writeSocket:17440 AckNr's received (50/51): 2113...2160,2161,2162 +2ms
f7c20:Portal:uTP:writeSocket:17440 AckNr's needed (1/51): 2163
f7c20:Portal:uTP:writeSocket:17440 +0ms
f7c20:Portal:uTP:writeSocket:17440:WRITING Sending ST_FIN packet. +2ms
f7c20:Portal:uTP:writeSocket:17440:SEND:ST_FIN || pktId: 17440 +0ms
f7c20:Portal:uTP:writeSocket:17440:SEND:ST_FIN || seqNr: 2163 +0ms
f7c20:Portal:uTP:writeSocket:17440:SEND:ST_FIN || ackNr: 2113 +0ms
8a470:Portal:uTP:RECEIVED:ST_FIN || pktId: 17440 || +0ms
8a470:Portal:uTP:RECEIVED:ST_FIN || seqNr: 2163 || +0ms
8a470:Portal:uTP:RECEIVED:ST_FIN || ackNr: 2113 || +0ms
8a470:Portal:uTP:readSocket:17441 Connection State: GotFin: 2163 +1ms
8a470:Portal:uTP:readSocket:17441 all data packets received. +0ms
8a470:Portal:uTP:readSocket:17441 Packet payloads compiled into 25619 bytes. Sending FIN-ACK +1ms
8a470:Portal:uTP:readSocket:17441:SEND:ST_STATE || pktId: 17441 +0ms
8a470:Portal:uTP:readSocket:17441:SEND:ST_STATE || seqNr: 2165 +0ms
8a470:Portal:uTP:readSocket:17441:SEND:ST_STATE || ackNr: 2163 +0ms
8a470:Portal:uTP Decompressing stream into 1 pieces of content +76ms
8a470:Portal:uTP:FINISHED 1/1 -- (25619 bytes) sending BlockHeader to database +0ms
8a470:Portal:uTP:RECEIVED:ST_FIN || pktId: 17440 || +0ms
8a470:Portal:uTP:RECEIVED:ST_FIN || seqNr: 2163 || +0ms
8a470:Portal:uTP:RECEIVED:ST_FIN || ackNr: 2113 || +0ms
8a470:Portal:uTP:readSocket:17441 Connection State: GotFin: 2163 +5ms
8a470:Portal:uTP Decompressing stream into 1 pieces of content +5s
8a470:Portal:uTP:FINISHED 1/1 -- (0 bytes) sending BlockHeader to database +0ms
8a470:Portal:uTP:FINISHED Missing content... +0ms
We should investigate and ensure this duplicate action doesn't occur.
This is still happening and the logging is weird.
We need something in the handleFinPacket method that closes the socket so if we get a dup FIN packet we don't call returnContent a second time. Seems like both Trin and Fluffy do funny things with sending FIN packets and it clutters up the logs with nonsensical stuff like above.
I dunno if this is still an issue or not. @ScottyPoi has made plenty of progress on uTP improvements so I'm guessing this is no longer an issue.