NFD

While I'm trying to make a simple scenario to reproduce the issue, here is a highly concerning logs from a simple test case from ndnSIM. It is a simple two node topology, with node 0 route for /prefix pointing to node 1 and node 1 has no data producer installed.

Look at the timing of operations:

+10.000000000s 0 nfd.InternalForwarderTransport:InternalForwarderTransport(): [INFO ] [id=0,local=ndnFace://0,remote=ndnFace://0] Creating transport
+10.000000000s 0 nfd.Forwarder:onIncomingInterest(): [DEBUG] onIncomingInterest face=258 interest=/prefix/someData
+10.000000000s 0 nfd.Forwarder:onContentStoreMiss(): [DEBUG] onContentStoreMiss interest=/prefix/someData
+10.000000000s 0 nfd.Forwarder:onOutgoingInterest(): [DEBUG] onOutgoingInterest face=256 interest=/prefix/someData
+10.000000000s 0 nfd.InternalForwarderTransport:receiveFromLink(): [LOGIC] [id=257,local=internal://,remote=internal://] receiveFromLink
+10.000000000s 0 nfd.InternalForwarderTransport:doSend(): [LOGIC] [id=1,local=internal://,remote=internal://] doSend
+10.014404296s 1 nfd.Forwarder:onIncomingInterest(): [DEBUG] onIncomingInterest face=256 interest=/prefix/someData
+10.014404296s 1 nfd.Forwarder:onContentStoreMiss(): [DEBUG] onContentStoreMiss interest=/prefix/someData
+10.014404296s 1 nfd.Forwarder:onOutgoingNack(): [DEBUG] onOutgoingNack face=256 nack=/prefix/someData~NoRoute OK
+10.014404296s 1 nfd.Forwarder:onInterestReject(): [DEBUG] onInterestReject interest=/prefix/someData
+10.031005858s 0 nfd.Forwarder:onIncomingNack(): [DEBUG] onIncomingNack face=256 nack=/prefix/someData~NoRoute OK
+10.031005858s 0 nfd.Forwarder:onOutgoingNack(): [DEBUG] onOutgoingNack face=258 nack=/prefix/someData~NoRoute OK
+10.031005858s 0 nfd.InternalForwarderTransport:doSend(): [LOGIC] [id=258,local=ndnFace://0,remote=ndnFace://0] doSend
+10.031005858s 0 test:operator()(): [DEBUG] got nack
+10.114404296s 1 nfd.Forwarder:onInterestFinalize(): [DEBUG] onInterestFinalize interest=/prefix/someData unsatisfied
+14.000000000s 0 nfd.Forwarder:onInterestUnsatisfied(): [DEBUG] onInterestUnsatisfied interest=/prefix/someData
+14.000000000s 0 nfd.Forwarder:onInterestFinalize(): [DEBUG] onInterestFinalize interest=/prefix/someData unsatisfied

Especially the last two. They should not have existed. Why PIT entry is not removed just after 10.031005858s?

I couldn't find any place where entry is moved to straggler timer after Strategy::sendNacks. Is it a bug or intentional?