<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=utf-8">
</head>
<body style="word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space;" class="">
<div class=""><br class="">
</div>
Junxiao,
<div class=""><br class="">
</div>
<div class="">Interesting, thanks for the added details.</div>
<div class="">face=276 is BASEL, just to add to the info.</div>
<div class=""><br class="">
</div>
<div class="">John</div>
<div class=""><br class="">
<div>
<blockquote type="cite" class="">
<div class="">On Mar 12, 2019, at 10:04 AM, Junxiao Shi <<a href="mailto:shijunxiao@email.arizona.edu" class="">shijunxiao@email.arizona.edu</a>> wrote:</div>
<br class="Apple-interchange-newline">
<div class="">
<div dir="ltr" class="">
<div dir="ltr" class="">
<div dir="ltr" class="">
<div dir="ltr" class="">
<div dir="ltr" class="">
<div dir="ltr" class="">
<div dir="ltr" class="">Hi John
<div class=""><br class="">
</div>
<div class="">The log entries related to this Interest are: (timestamp changed to relative in microseconds)</div>
<div class="">
<div class="">
<div class=""><font face="monospace, monospace" class="">0 DEBUG: [nfd.Forwarder] onIncomingInterest face=292 interest=/ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B</font></div>
<div class=""><font face="monospace, monospace" class="">29 DEBUG: [nfd.ContentStore] find /ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B L</font></div>
<div class=""><font face="monospace, monospace" class="">53 DEBUG: [nfd.Forwarder] onContentStoreMiss interest=/ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B</font></div>
<div class=""><font face="monospace, monospace" class="">63 DEBUG: [nfd.Forwarder] onContentStoreMiss interest=/ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B nexthop-faceid=278</font></div>
<div class=""><font face="monospace, monospace" class="">68 DEBUG: [nfd.Forwarder] onOutgoingInterest face=278 interet=/ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B</font></div>
<div class=""><font face="monospace, monospace" class="">100 DEBUG: [nfd.Forwarder] onIncomingInterest face=292 interest=/ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B</font></div>
<div class=""><font face="monospace, monospace" class="">115 DEBUG: [nfd.Forwarder] onContentStoreMiss interest=/ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B</font></div>
<div class=""><font face="monospace, monospace" class="">128 DEBUG: [nfd.AsfStrategy] /ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B?ndn.Nonce=3346098500 from=292 suppressed</font></div>
<div class=""><font face="monospace, monospace" class="">36064 DEBUG: [nfd.Forwarder] onIncomingInterest face=276 interest=/ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B</font></div>
<div class=""><font face="monospace, monospace" class="">36086 DEBUG: [nfd.Forwarder] onContentStoreMiss interest=/ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B</font></div>
<div class=""><font face="monospace, monospace" class="">36104 DEBUG: [nfd.AsfStrategy] /ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B?ndn.Nonce=3569453214 from=276 noNextHop</font></div>
<div class=""><font face="monospace, monospace" class="">36113 DEBUG: [nfd.Forwarder] onOutgoingNack face=276 nack=/ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B~NoRoute OK</font></div>
<div class=""><font face="monospace, monospace" class="">36155 DEBUG: [nfd.Forwarder] onInterestFinalize interest=/ndn/edu/memphis/%C1.Router/titan/nlsr/KEY/%C96%5B%D6%03Y%C2B unsatisfied</font></div>
<div class=""><font face="monospace, monospace" class="">134155 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</font></div>
<div class=""><font face="monospace, monospace" class="">134172 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</font></div>
</div>
</div>
<div class=""><br class="">
</div>
<div class="">Events happened:</div>
<div class="">
<ol class="">
<li class="">Interest arrives from face 292. It goes out to face 278.</li><li class="">100us later, retransmission arrives from face 292. Strategy suppresses it.</li><li class="">36ms later, another Interest with same name arrives from face 276. Strategy determines there's no available nexthop so it responds with a Nack, and then deletes the PIT entry.</li><li class="">134ms later, Data arrives and is dropped because there's no PIT entry.</li></ol>
</div>
<div class=""><br class="">
</div>
<div class="">ASF strategy has two code path that can lead to Nack, both in <a href="https://github.com/named-data/NFD/blob/NFD-0.6.5/daemon/fw/asf-strategy.cpp#L125-L140" class="">
AsfStrategy::afterReceiveInterest function</a>:</div>
<div class="">
<div class=""><font face="monospace, monospace" class=""> const fib::Entry& fibEntry = this->lookupFib(*pitEntry);</font></div>
<div class=""><font face="monospace, monospace" class=""> const fib::NextHopList& nexthops = fibEntry.getNextHops();</font></div>
<div class=""><font face="monospace, monospace" class=""> if (nexthops.size() == 0) {</font></div>
<div class=""><font face="monospace, monospace" class=""> sendNoRouteNack(ingress, interest, pitEntry);</font></div>
<div class=""><font face="monospace, monospace" class=""> this->rejectPendingInterest(pitEntry);</font></div>
<div class=""><font face="monospace, monospace" class=""> return;</font></div>
<div class=""><font face="monospace, monospace" class=""> }</font></div>
<div class=""><font face="monospace, monospace" class=""><br class="">
</font></div>
<div class=""><font face="monospace, monospace" class=""> Face* faceToUse = getBestFaceForForwarding(fibEntry, interest, ingress.face);</font></div>
<div class=""><font face="monospace, monospace" class=""> if (faceToUse == nullptr) {</font></div>
<div class=""><font face="monospace, monospace" class=""> sendNoRouteNack(ingress, interest, pitEntry);</font></div>
<div class=""><font face="monospace, monospace" class=""> this->rejectPendingInterest(pitEntry);</font></div>
<div class=""><font face="monospace, monospace" class=""> return;</font></div>
<div class=""><font face="monospace, monospace" class=""> }</font></div>
</div>
<div class=""><br class="">
</div>
<div class="">The first condition, <span style="font-family:monospace,monospace" class="">nexthops.size() == 0</span> , is not possible here.</div>
<div class="">The second condition <a href="https://github.com/named-data/NFD/blob/c70794810592a90847656a97caf27f0326668240/daemon/fw/asf-strategy.cpp#L264" class="">AsfStrategy::getBestFaceForForwarding</a> returning nullptr, only happens if the ingress face
is the only nexthop, but ingress face 276 is not nexthop 278.</div>
<div class="">Thus, I do not understand which condition is triggering the Nack.</div>
<div class=""><br class="">
</div>
<div class="">After sending a Nack, ASF strategy invokes <a href="https://github.com/named-data/NFD/blob/NFD-0.6.5/daemon/fw/strategy.hpp#L266-L276" class="">Strategy::rejectPendingInterest</a> that schedules the PIT entry for immediate deletion. A strategy
should invoke this function when it concludes that the Interest cannot be forwarded and it does not want to wait for responses from existing upstream nodes.</div>
<div class="">Since the Interest is already forwarded to face 278, I do not understand why ASF believes it would not be satisfied and the PIT entry should be deleted.</div>
<div class=""><br class="">
</div>
<div class="">Also, I do not understand why NLSR decides to retransmit its Interest just 100us after the initial transmission. It should know that the response would not come this fast.</div>
<div class="">However, rapid retransmission would not cause "the first one not registered in PIT" because the forwarder is single threaded.</div>
<div class=""><br class="">
</div>
<div class="">Yours, Junxiao</div>
</div>
<br class="">
<div class="gmail_quote">
<div dir="ltr" class="gmail_attr">On Tue, Mar 12, 2019 at 10:16 AM Dehart, John <<a href="mailto:jdd@wustl.edu" class="">jdd@wustl.edu</a>> wrote:<br class="">
</div>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<br class="">
I have upgraded 6 nodes on the NDN Testbed to NFD 0.6.5 and NLSR 0.5.0 with PSync.<br class="">
I had an issue yesterday where it took a very long time for NLSR to sync the default routes<br class="">
for all 6 nodes. The nodes involved are: MEMPHIS, WU, URJC, BASEL, BERN and AAU.<br class="">
The connectivity is like this: <br class="">
MEMPHIS--WU--URJC--BASEL and then BASEL, AAU and BERN are all connected to each other.<br class="">
<br class="">
After 2-3 hours, URJC, BASEL, BERN and AAU had not learned MEMPHIS’s default route yet.<br class="">
All other routes had been updated.<br class="">
What I found was that they were having trouble validating because they were not able to retrieve<br class="">
MEMPHIS’s KEY. One example of what I am seeing is illustrated by these four NFD log messages<br class="">
from URJC (I’ve manually added the ‘HERE’ to the nfd.log file to give myself something easy to grep on)<br class="">
<br class="">
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,<br class="">
NFD forwards that interest to WU. About 130ms later, data from WU returns that should satisfy that Interest but NFD indicates that<br class="">
it is unsolicted data and drops it.<br class="">
<br class="">
So, why would NFD not have a PIT entry for the interest it forwarded 130ms earlier?<br class="">
<br class="">
About 6 hours after the above messages, NLSR on URJC finally did get the KEY data it needed an validated<br class="">
the route update. I will be processing the log files around that event to see if there is anything telling that is different there.<br class="">
<br class="">
</blockquote>
<div class="gmail_quote">
<div dir="ltr" class="gmail_attr">On Tue, Mar 12, 2019 at 10:48 AM Dehart, John <<a href="mailto:jdd@wustl.edu" class="">jdd@wustl.edu</a>> wrote:<br class="">
</div>
<blockquote class="gmail_quote" style="margin:0px 0px 0px 0.8ex;border-left:1px solid rgb(204,204,204);padding-left:1ex">
<br class="">
It appears that 100us after an interest arrives from NLSR another one arrives for the same data.<br class="">
This second one AsfStrategy suppresses.<br class="">
Is this rapid succession of interests and suppression causing the first one to not be registered in the PIT?<br class="">
</blockquote>
</div>
<div class=""> </div>
</div>
</div>
</div>
</div>
</div>
</div>
</div>
</div>
</blockquote>
</div>
<br class="">
</div>
</body>
</html>