[Nfd-dev] NLSR/NFD Issue on the Testbed

[Dehart, John]

I have flagged two more log messages of interest here:

HERE    Mar 12 00:50:10 insula nfd[1565]: 1552348210.739609 DEBUG: [nfd.Forwarder] onIncomingInterest face=292 interest=/ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B
HERE    Mar 12 00:50:10 insula nfd[1565]: 1552348210.739677 DEBUG: [nfd.Forwarder] onOutgoingInterest face=278 interest=/ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B
HERE    Mar 12 00:50:10 insula nfd[1565]: 1552348210.739709 DEBUG: [nfd.Forwarder] onIncomingInterest face=292 interest=/ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B
HERE    Mar 12 00:50:10 insula nfd[1565]: 1552348210.739737 DEBUG: [nfd.AsfStrategy] /ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B?ndn.Nonce=3346098500 from=292 suppressed
HERE    Mar 12 00:50:10 insula nfd[1565]: 1552348210.873764 DEBUG: [nfd.Forwarder] onIncomingData face=278 data=/ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B/NA/%FD%00%00%01in%84%2Ff
HERE    Mar 12 00:50:10 insula nfd[1565]: 1552348210.873781 DEBUG: [nfd.Forwarder] onDataUnsolicited face=278 data=/ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B/NA/%FD%00%00%01in%84%2Ff decision=drop


It appears that 100us after an interest arrives from NLSR another one arrives for the same data.
This second one AsfStrategy suppresses.
Is this rapid succession of interests and suppression causing the first one to not be registered in the PIT?

John

> On Mar 12, 2019, at 9:16 AM, Dehart, John <jdd at wustl.edu> wrote:
> 
> 
> All:
> 
> I have upgraded 6 nodes on the NDN Testbed to NFD 0.6.5 and NLSR 0.5.0 with PSync.
> I had an issue yesterday where it took a very long time for NLSR to sync the default routes
> for all 6 nodes. The nodes involved are: MEMPHIS, WU, URJC, BASEL, BERN and AAU.
> The connectivity is like this: 
> MEMPHIS--WU--URJC--BASEL and then BASEL, AAU and BERN are all connected to each other.
> 
> After 2-3 hours, URJC, BASEL, BERN and AAU had not learned MEMPHIS’s default route yet.
> All other routes had been updated.
> What I found was that they were having trouble validating because they were not able to retrieve
> MEMPHIS’s KEY. One example of what I am seeing is illustrated by these four NFD log messages
> from URJC (I’ve manually added the ‘HERE’ to the nfd.log file to give myself something easy to grep on)
> 
> HERE    Mar 12 00:50:10 insula nfd[1565]: 1552348210.739609 DEBUG: [nfd.Forwarder] onIncomingInterest face=292 interest=/ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B
> HERE    Mar 12 00:50:10 insula nfd[1565]: 1552348210.739677 DEBUG: [nfd.Forwarder] onOutgoingInterest face=278 interest=/ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B
> HERE    Mar 12 00:50:10 insula nfd[1565]: 1552348210.873764 DEBUG: [nfd.Forwarder] onIncomingData face=278 data=/ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B/NA/%FD%00%00%01in%84%2Ff
> HERE    Mar 12 00:50:10 insula nfd[1565]: 1552348210.873781 DEBUG: [nfd.Forwarder] onDataUnsolicited face=278 data=/ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B/NA/%FD%00%00%01in%84%2Ff decision=drop
> 
> I believe face=292 is NLSR and face=278 is WU. So, we see NLSR sending an interest to NFD for /ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B,
> NFD forwards that interest to WU. About 130ms later, data from WU returns that should satisfy that Interest but NFD indicates that
> it is unsolicted data and drops it.
> 
> So, why would NFD not have a PIT entry for the interest it forwarded 130ms earlier?
> 
> Below I will attach a snippet from the nfd.log file that includes a little before the messages above and then up to the
> onDataUnsolicited message. I can include more from before this if needed.
> 
> About 6 hours after the above messages, NLSR on URJC finally did get the KEY data it needed an validated
> the route update. I will be processing the log files around that event to see if there is anything telling that is different there.
> 
> Thanks,
> John
> 
> 
> <nfd.log.nlsr.snip_2>_______________________________________________
> Nfd-dev mailing list
> Nfd-dev at lists.cs.ucla.edu
> http://www.lists.cs.ucla.edu/mailman/listinfo/nfd-dev