[Nfd-dev] Help needed with debugging duplicate Nonce

[Lan Wang (lanwang)]

Junxiao,

I have some questions about the specifics of the example that are best clarified through the nfd call, but here are some high-order questions:

- Duplicate NACK is a problem because I think it will affect the pending interest information between the neighbors so their sync data packets won’t be able to propagate in time.  What does a node do to its PIT when it sends/receives a duplicate NACK?

- /localhop is fine for intradomain routing, because NLSR neighbors are one hop away from each other.  But we don’t have to do this if we don’t have the duplicate NACK problem in the first place.

- if we do have to use /localhop to remove the duplicate NACKs then we need to make sure that it only propagates one hop (not as implemented now).

Lan

On Jul 1, 2016, at 10:56 AM, Junxiao Shi <shijunxiao at email.arizona.edu<mailto:shijunxiao at email.arizona.edu>> wrote:

Hi Ashlesh

The unusual thing, as you tagged in sync-interest-trail, is “not sure what triggers A here”. I looked at A’s nfd.log and pieced together the changes on PIT entry.

From A’s point of view, face261 is the local app, face262 is B, face263 is C.
Incoming+outgoing Interests, and PIT entry contents are as follows:

52.39 from=C=4168 to=app
      PIT in=[C=4168 at 52.39] out=[app at 52.39]
52.72 from=B=6605
      PIT in=[C=4168 at 52.39,B=6605 at 52.72] out=[app at 52.39]
52.74 from=app=7385 to=B,C
      PIT in=[C=4168 at 52.39,B=6605 at 52.72,app=7385 at 52.74] out=[app at 52.39,B at 52.74,C at 52.74]
56.39 PIT in=[B=6605 at 52.72,app=7385 at 52.74]+expired[C=4168 at 52.39] out=[B at 52.74,C at 52.74]+expired[app at 52.39]
56.72 PIT in=[app=7385 at 52.74]+expired[C=4168 at 52.39,B=6605 at 52.72] out=[B at 52.74,C at 52.74]+expired[app at 52.39]
56.74 Interest unsatisfied, PIT erased

56.89 from=C=0641 to=app
      PIT in=[C=0641 at 56.89] out=[app at 56.89]
56.90 from=app=7567 to=B,C
      PIT in=[C=0641 at 56.89,app=7567 at 56.90] out=[app at 56.89,B at 56.90,C at 56.90]
57.06 from=B=1547
      PIT in=[C=0641 at 56.89,app=7567 at 56.90,B=1547 at 57.06] out=[app at 56.89,B at 56.90,C at 56.90]
60.89 PIT in=[app=7567 at 56.90,B=1547 at 57.06]+expired[C=0641 at 56.89] out=[B at 56.90,C at 56.90]+expired[app at 56.89]
60.90 PIT in=[B=1547 at 57.06]+expired[C=0641 at 56.89,app=7567 at 56.90] out=[]+expired[app at 56.89,B at 56.90,C at 56.90]

61.05 from=C=6600 to=app,B,C
      PIT in=[B=1547 at 57.06,C=6600 at 61.05]+expired[app=7567 at 56.90] out=[app at 61.05,B at 61.05,C at 61.05]

Time is represented with last two digits of integral part and first two digits of fractional part. Nonce is represented with last four digits. PIT in-record is represented as <downstream>=<nonce>@<time>. PIT out-record is represented as <upstream>@<time>.

The PIT entry has been erased at 56.74, so anything before that does not affect the later part.

At 61.05, an Interest with nonce 6600 is received from C. Before processing this Interest, the PIT entry has one unexpired in-record from B which has nonce 1547 and was created at 57.06; all out-records have been expired.
This Interest is forwarded with nonce 6600 to both app and B.
Since the PIT entry indicates B still wants the Data, the strategy also forwards the Interest with nonce 1547 (which came from B at 57.06) back to C.

While this may not be the best idea for multicast strategy, and using a nonce from non-local-app may be problematic with /localhop, this forwarding is valid in general: nonce 1547 has never been forwarded earlier, and downstream B still wants the Data, so the strategy can certainly forward the Interest to C using this nonce.

If all you see is Nack-Duplicate, but application can still retrieve Data normally, don’t worry about that. The root cause of having Nack-Duplicates is that the topology contains a cycle.
Also, in general case, ChronoSync should not use /localhop, because it’s possible that two participants are not directly connected.

Yours, Junxiao

From: Ashlesh Gawande (agawande)<mailto:agawande at memphis.edu>
Sent: Wednesday, June 29, 2016 13:24
To: Junxiao Shi<mailto:shijunxiao at email.arizona.edu>
Cc: Lan Wang (lanwang)<mailto:lanwang at memphis.edu>; nfd-dev at lists.cs.ucla.edu<mailto:nfd-dev at lists.cs.ucla.edu>
Subject: Re: [Nfd-dev] Help needed with debugging duplicate Nonce

Okay, so I performed a new experiment (i.e. just ran minindn and quit after some time) with FibManager and Forwarder DEBUG logs.

In this experiment, looked at the first Duplicate NACK on localhop prefix (Nonce: 567161547) and found the following:
1) b->a
2) b->c
3) a->c
4) c sends Duplicate NACK

This happens around 1467225861 - I don't see any FibManager messages around this time in NFD logs.

I have attached a sync interest trail where I grepped for the particular sync interest such as:
grep "/localhop/NLSR/sync/e4c858598a526f7f25d42f4da49cb51b7950cf352e26d5092bd35126b509101b?ndn.MustBeFresh=1&ndn.Nonce" */ndndump* | sort -t: -nk2 | awk '{split($NF,a,"Nonce="); $NF=""; print $0 " " a[2]}' > sync-interest-trail

(ndndump* includes localhost as well as interface)

Seems like before the NACK, a sends interests with two different Nonces - one to c (which resulted in the above NACK), one to b (resulted in another NACK).
This time I didn't see any local new interest for the sync on a  (which should be equivalent to b from the previous example).

Ashlesh

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.lists.cs.ucla.edu/pipermail/nfd-dev/attachments/20160708/a703c7af/attachment.html>