<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=utf-8">
</head>
<body>
<div class="" style="word-wrap:break-word">
<div class="">Hi all,</div>
<div class=""><br class="">
</div>
<div class="">I’m doing tests and explorations on the reasons, why does NdnCon experience rebufferings (i.e. interruptions in video stream which lead to algorithm restart).</div>
<div class="">I would appreciate any help/suggestions/advices in debugging/analyzing NFD logs and NFD itself.</div>
<div class=""><br class="">
</div>
<div class="">More specifically, I’d like to hear your comments on the following case.</div>
<div class="">With the same configuration as before ([Consumer] <—> [<b class="">NFD1</b>] <==<i class="">Ethernet</i><i class="">_link</i>==> [<b class="">NFD2</b>] <==<i class="">Ethernet_link</i>==> [<b class="">NFD3</b>] <—> [Producer]) consumer experienced
interruption after getting frame 640. So I tracked down frame’s 641 interests and data in NFD logs:</div>
<div class=""><br class="">
</div>
<div class=""><b class="">NFD1 log: </b><i class="">($ cat consumer/nfd.log | grep "</i><i class="">/641/data/%00%00”)</i></div>
<div class=""><br class="">
</div>
<div class="">1422581555.423600 DEBUG: [Forwarder] onIncomingInterest face=265 interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00</div>
<div class="">1422581555.423943 DEBUG: [Forwarder] onOutgoingInterest face=259 interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00</div>
<div class="">1422581555.424205 DEBUG: [BestRouteStrategy2] /ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00?ndn.MustBeFresh=1&ndn.InterestLifetime=5000&ndn.Nonce=<b class="">1282205730</b> from=265 newPitEntry-to=259</div>
<div class=""><b class="">^ 294ms (retransmission, confirmed by consumer log)</b></div>
<div class="">1422581555.718095 DEBUG: [Forwarder] onIncomingInterest face=265 interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00</div>
<div class="">1422581555.718589 DEBUG: [Forwarder] onOutgoingInterest face=259 interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00</div>
<div class="">1422581555.718929 DEBUG: [BestRouteStrategy2] /ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00?ndn.MustBeFresh=1&ndn.InterestLifetime=5000&ndn.Nonce=589980969 from=265 retransmit-retry-to=259</div>
<div class=""><b class="">^ 232ms</b></div>
<div class="">1422581555.950466 DEBUG: [Forwarder] onIncomingData face=259 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00/5/664/22/0</div>
<div class="">1422581555.950763 DEBUG: [Forwarder] onIncomingData matching=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00</div>
<div class="">1422581555.950998 DEBUG: [Strategy] beforeSatisfyPendingInterest pitEntry=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00 inFace=259 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00/5/664/22/0</div>
<div class="">1422581555.951438 DEBUG: [Forwarder] onOutgoingData face=265 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00/5/664/22/0</div>
<div class=""><b class="">^ 5ms</b></div>
<div class="">1422581555.956230 DEBUG: [Forwarder] <b class="">onIncomingData</b> face=259 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00/5/664/22/0</div>
<div class="">1422581555.956496 DEBUG: [Forwarder] onIncomingData matching=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00</div>
<div class="">1422581555.956724 DEBUG: [Strategy] beforeSatisfyPendingInterest pitEntry=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00 inFace=259 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00/5/664/22/0</div>
<div class=""><br class="">
</div>
<div class=""><b class="">NFD2 log: </b><i class="">($ cat hub/nfd.log | grep "</i><i class="">/641/data/%00%00”)</i></div>
<div class=""><br class="">
</div>
<div class="">1422581521.773468 DEBUG: [Forwarder] onIncomingInterest face=266 interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00</div>
<div class="">1422581521.773947 DEBUG: [Forwarder] onOutgoingInterest face=264 interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00</div>
<div class="">1422581521.774352 DEBUG: [BestRouteStrategy2] /ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00?ndn.MustBeFresh=1&ndn.InterestLifetime=5000&ndn.Nonce=<b class="">1282205730</b> from=266 newPitEntry-to=264</div>
<div class=""><b class="">^ 522ms (??? where is the retransmission interest?)</b></div>
<div class="">1422581522.296967 DEBUG: [Forwarder] onIncomingData face=264 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00/5/664/22/0</div>
<div class="">1422581522.297347 DEBUG: [Forwarder] onIncomingData matching=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00</div>
<div class="">1422581522.297614 DEBUG: [Strategy] beforeSatisfyPendingInterest pitEntry=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00 inFace=264 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00/5/664/22/0</div>
<div class="">1422581522.298123 DEBUG: [Forwarder] onOutgoingData face=266 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00/5/664/22/0</div>
<div class=""><b class="">^ 5ms (ah, here it is… how?)</b></div>
<div class="">1422581522.303090 DEBUG: [Forwarder] onIncomingInterest face=266 interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00</div>
<div class="">1422581522.303430 DEBUG: [Forwarder] onOutgoingData face=266 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00/5/664/22/0</div>
<div class=""><br class="">
</div>
<div class=""><b class="">NFD3 log: </b><i class="">($ cat producer/nfd.log | grep "</i><i class="">/641/data/%00%00”)</i></div>
<div class=""><br class="">
</div>
<div class="">1422581555.255647 DEBUG: [Forwarder] onIncomingInterest face=266 interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00</div>
<div class="">1422581555.256007 DEBUG: [Forwarder] onOutgoingInterest face=269 interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00</div>
<div class="">1422581555.256334 DEBUG: [BestRouteStrategy2] /ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00?ndn.MustBeFresh=1&ndn.InterestLifetime=5000&ndn.Nonce=<b class="">1282205730</b> from=266 newPitEntry-to=269</div>
<div class=""><b class="">^ 47ms (!!! interest arrival was not late, data generation was not delayed)</b></div>
<div class="">1422581555.303275 DEBUG: [Forwarder] onIncomingData face=269 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00/5/664/22/0</div>
<div class="">1422581555.303640 DEBUG: [Forwarder] onIncomingData matching=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00</div>
<div class="">1422581555.303928 DEBUG: [Strategy] beforeSatisfyPendingInterest pitEntry=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00 inFace=269 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00/5/664/22/0</div>
<div class="">1422581555.304458 DEBUG: [Forwarder] onOutgoingData face=266 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/641/data/%00%00/5/664/22/0</div>
<div class=""> </div>
<div class=""><br class="">
</div>
<div class="">The questions here are:</div>
<div class="">1. How did the retransmission interest arrived on NFD2 ~220ms later than was expected and actually after the first interest was already answered?</div>
<div class="">2. If the data was generated and answered by NFD3 in timely manner, why did data arrived on NFD2 after 522ms but not after ~50ms?</div>
<div class=""><br class="">
</div>
<div class="">Some peculiar place of NFD2’s log:</div>
<div class="">
<div class="" style="margin:0px; font-size:11px; font-family:Menlo"><b class="">$ sed -n 38830,38840p hub/nfd.log </b></div>
</div>
<div class="" style="margin:0px; font-size:11px; font-family:Menlo"><b class=""><br class="">
</b></div>
<div class="">
<div class="">1422581521.916149 DEBUG: [Forwarder] onIncomingData face=264 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/638/data/%00%0A/14/661/22/0</div>
<div class="">1422581521.916515 DEBUG: [Forwarder] onIncomingData matching=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/638/data/%00%0A</div>
<div class="">1422581521.916799 DEBUG: [Strategy] beforeSatisfyPendingInterest pitEntry=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/638/data/%00%0A inFace=264 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/638/data/%00%0A/14/661/22/0</div>
<div class="">1422581521.917301 DEBUG: [Forwarder] onOutgoingData face=266 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/638/data/%00%0A/14/661/22/0</div>
<div class="">^ 360ms</div>
<div class="">1422581522.277620 DEBUG: [Forwarder] onInterestUnsatisfied interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/499/data/%00%06</div>
<div class="">1422581522.278080 DEBUG: [Strategy] beforeExpirePendingInterest pitEntry=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/499/data/%00%06</div>
<div class="">1422581522.278524 DEBUG: [Forwarder] onInterestUnsatisfied interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/500/data/%00%06</div>
<div class="">1422581522.278901 DEBUG: [Strategy] beforeExpirePendingInterest pitEntry=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/500/data/%00%06</div>
<div class="">1422581522.279352 DEBUG: [Forwarder] onInterestUnsatisfied interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/501/data/%00%05</div>
<div class="">1422581522.279742 DEBUG: [Strategy] beforeExpirePendingInterest pitEntry=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/501/data/%00%05</div>
<div class="">1422581522.280119 DEBUG: [Forwarder] onInterestUnsatisfied interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/top_cam/low/delta/501/data/%00%06</div>
</div>
<div class=""><br class="">
</div>
<div class=""><br class="">
</div>
<div class="">I would appreciate any help.</div>
<div class="">Looking forward for the insights of NFD developers,</div>
<br class="">
<div class="">
<div class="" style="color:rgb(0,0,0); letter-spacing:normal; orphans:auto; text-align:start; text-indent:0px; text-transform:none; white-space:normal; widows:auto; word-spacing:0px; word-wrap:break-word">
<div class="" style="color:rgb(0,0,0); letter-spacing:normal; orphans:auto; text-align:start; text-indent:0px; text-transform:none; white-space:normal; widows:auto; word-spacing:0px; word-wrap:break-word">
<div class="" style="color:rgb(0,0,0); letter-spacing:normal; orphans:auto; text-align:start; text-indent:0px; text-transform:none; white-space:normal; widows:auto; word-spacing:0px; word-wrap:break-word">
<div class="" style="color:rgb(0,0,0); font-family:Helvetica; font-style:normal; font-variant:normal; font-weight:normal; letter-spacing:normal; line-height:normal; orphans:2; text-indent:0px; text-transform:none; white-space:normal; widows:2; word-spacing:0px; word-wrap:break-word">
Thanks, </div>
<div class="" style="color:rgb(0,0,0); font-family:Helvetica; font-style:normal; font-variant:normal; font-weight:normal; letter-spacing:normal; line-height:normal; orphans:2; text-indent:0px; text-transform:none; white-space:normal; widows:2; word-spacing:0px; word-wrap:break-word">
<br class="">
</div>
<div class="" style="color:rgb(0,0,0); font-family:Helvetica; font-style:normal; font-variant:normal; font-weight:normal; letter-spacing:normal; line-height:normal; orphans:2; text-indent:0px; text-transform:none; white-space:normal; widows:2; word-spacing:0px; word-wrap:break-word">
PS. full logs are attached</div>
<div class="" style="color:rgb(0,0,0); font-family:Helvetica; font-style:normal; font-variant:normal; font-weight:normal; letter-spacing:normal; line-height:normal; orphans:2; text-indent:0px; text-transform:none; white-space:normal; widows:2; word-spacing:0px; word-wrap:break-word">
</div>
</div>
</div>
</div>
</div>
</div>
<div class="" style="word-wrap:break-word">
<div class="">
<div class="" style="color:rgb(0,0,0); letter-spacing:normal; orphans:auto; text-align:start; text-indent:0px; text-transform:none; white-space:normal; widows:auto; word-spacing:0px; word-wrap:break-word">
<div class="" style="color:rgb(0,0,0); letter-spacing:normal; orphans:auto; text-align:start; text-indent:0px; text-transform:none; white-space:normal; widows:auto; word-spacing:0px; word-wrap:break-word">
<div class="" style="color:rgb(0,0,0); letter-spacing:normal; orphans:auto; text-align:start; text-indent:0px; text-transform:none; white-space:normal; widows:auto; word-spacing:0px; word-wrap:break-word">
<div class="" style="color:rgb(0,0,0); font-family:Helvetica; font-style:normal; font-variant:normal; font-weight:normal; letter-spacing:normal; line-height:normal; orphans:2; text-indent:0px; text-transform:none; white-space:normal; widows:2; word-spacing:0px; word-wrap:break-word">
</div>
<div class="" style="color:rgb(0,0,0); font-family:Helvetica; font-style:normal; font-variant:normal; font-weight:normal; letter-spacing:normal; line-height:normal; orphans:2; text-indent:0px; text-transform:none; white-space:normal; widows:2; word-spacing:0px; word-wrap:break-word">
<br class="">
</div>
<div class="" style="color:rgb(0,0,0); font-family:Helvetica; font-style:normal; font-variant:normal; font-weight:normal; letter-spacing:normal; line-height:normal; orphans:2; text-indent:0px; text-transform:none; white-space:normal; widows:2; word-spacing:0px; word-wrap:break-word">
-- <br class="">
Peter Gusev</div>
<div class="" style="color:rgb(0,0,0); font-family:Helvetica; font-style:normal; font-variant:normal; font-weight:normal; letter-spacing:normal; line-height:normal; orphans:2; text-indent:0px; text-transform:none; white-space:normal; widows:2; word-spacing:0px; word-wrap:break-word">
Programmer/Analyst @ REMAP, UCLA</div>
<div class="" style="color:rgb(0,0,0); font-family:Helvetica; font-style:normal; font-variant:normal; font-weight:normal; letter-spacing:normal; line-height:normal; orphans:2; text-indent:0px; text-transform:none; white-space:normal; widows:2; word-spacing:0px; word-wrap:break-word">
<br class="">
<a href="mailto:peter@remap.ucla.edu" class="">peter@remap.ucla.edu</a><br class="">
+1 213 5872748<br class="">
peetonn_ (skype)</div>
</div>
</div>
</div>
</div>
<br class="">
<div>
<blockquote type="cite" class="">
<div class="">On Jan 21, 2015, at 12:32 PM, Gusev, Peter <<a href="mailto:peter@remap.ucla.edu" class="">peter@remap.ucla.edu</a>> wrote:</div>
<br class="x_Apple-interchange-newline">
<div class="">
<div class="">
<div class="" style="word-wrap:break-word">Hi all,
<div class=""><br class="">
</div>
<div class="">I’ve been testing <a href="https://github.com/remap/ndnrtc/tree/issues/2283-retransmissions" class=""></a><a href="https://github.com/remap/ndnrtc/tree/issues/2283-retransmissions" class="">N</a>DN-RTC with new consumer algorithm and exploring
the problem of rebufferings on consumer side (a state, when consumer is not getting data for some amount of time, flushes everything and starts over again). Consumer rebufferings are perceived as audio/video interruptions for 1-1.5sec by the user and decrease
overall user experience.</div>
<div class=""><br class="">
</div>
<div class="">I'll appreciate your insights on the analysis of the logs I retrieved from NFD.</div>
<div class=""><br class="">
</div>
<div class=""><u class="">Setup:</u></div>
<div class=""><br class="">
</div>
<div class="">[Consumer] <—> [<b class="">NFD1</b>] <==<i class="">WiFi_link</i>==> [<b class="">NFD2</b>] <==<i class="">Ethernet_link</i>==> [<b class="">NFD3</b>] <—> [Producer]</div>
<div class=""><br class="">
</div>
<div class=""><u class="">Case:</u></div>
<div class="">According to my logs, consumer starved for data after 2656 segment has arrived, so I tracked interests and data for
<b class="">2657</b> segment. According to my logs, consumer eventually received this data but too late and rebuffering was already inevitable.</div>
<div class=""><br class="">
</div>
<div class=""><b class="">NFD1 log:</b></div>
<div class="">
<div class=""><u class=""><i class="">initial interest:</i><span class="x_x_Apple-tab-span" style="white-space:pre">
</span></u><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.271931 DEBUG: [Forwarder] onIncomingInterest face=266 interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.272215 DEBUG: [Forwarder] onOutgoingInterest face=262 interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.272469 DEBUG: [BestRouteStrategy2] /ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00?ndn.MustBeFresh=1&ndn.InterestLifetime=5000&ndn.Nonce=108889115
from=266 newPitEntry-to=262</div>
<div class=""><b class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>^ 270ms</b></div>
<div class=""><i class=""><u class="">retransmission:</u></i><span class="x_x_Apple-tab-span" style="white-space:pre">
</span>1421288806.542289 DEBUG: [Forwarder] onIncomingInterest face=266 interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.542697 DEBUG: [Forwarder] onOutgoingInterest face=262 interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.543032 DEBUG: [BestRouteStrategy2] /ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00?ndn.MustBeFresh=1&ndn.InterestLifetime=5000&ndn.Nonce=562292066
from=266 retransmit-retry-to=262</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span><b class="">^ 286ms</b></div>
<div class=""><i class=""><u class="">data arrives:</u></i><span class="x_x_Apple-tab-span" style="white-space:pre"><i class=""><u class="">
</u></i></span>1421288806.829462 DEBUG: [Forwarder] onIncomingData face=262 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00/1/2749/91/0</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.829818 DEBUG: [Forwarder] onIncomingData matching=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.830042 DEBUG: [Strategy] beforeSatisfyPendingInterest pitEntry=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00 inFace=262 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00/1/2749/91/0</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.830449 DEBUG: [Forwarder] onOutgoingData face=266 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00/1/2749/91/0</div>
<div class="" style="font-weight:bold"><br class="">
</div>
<div class=""><b class="">NFD2 log:</b></div>
<div class="">
<div class=""><i class=""><u class="">initial interest:</u></i><span class="x_x_Apple-tab-span" style="white-space:pre"><u class="">
</u></span>1421288806.015075 DEBUG: [Forwarder] onIncomingInterest face=266 interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.015845 DEBUG: [Forwarder] onOutgoingInterest face=264 interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.016255 DEBUG: [BestRouteStrategy2] /ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00?ndn.MustBeFresh=1&ndn.InterestLifetime=5000&ndn.Nonce=108889115
from=266 newPitEntry-to=264</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span><b class="">^ 545ms</b></div>
<div class=""><i class=""><u class="">retransmission:</u></i><span class="x_x_Apple-tab-span" style="white-space:pre">
</span>1421288806.561516 DEBUG: [Forwarder] onIncomingInterest face=266 interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.562233 DEBUG: [Forwarder] onOutgoingInterest face=264 interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.562626 DEBUG: [BestRouteStrategy2] /ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00?ndn.MustBeFresh=1&ndn.InterestLifetime=5000&ndn.Nonce=562292066
from=266 retransmit-retry-to=264</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span><b class="">^ 2ms</b></div>
<div class=""><i class=""><u class="">data arrives:</u></i><span class="x_x_Apple-tab-span" style="white-space:pre">
</span>1421288806.564828 DEBUG: [Forwarder] onIncomingData face=264 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00/1/2749/91/0</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.565282 DEBUG: [Forwarder] onIncomingData matching=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.565594 DEBUG: [Strategy] beforeSatisfyPendingInterest pitEntry=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00 inFace=264 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00/1/2749/91/0</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.566213 DEBUG: [Forwarder] onOutgoingData face=266 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00/1/2749/91/0</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span><b class="">^ 13ms</b></div>
<div class=""><i class=""><u class="">data arrives 2:*</u></i><span class="x_x_Apple-tab-span" style="white-space:pre">
</span>1421288806.579547 DEBUG: [Forwarder] onIncomingData face=264 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00/1/2749/91/0</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.579915 DEBUG: [Forwarder] onIncomingData matching=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.580162 DEBUG: [Strategy] beforeSatisfyPendingInterest pitEntry=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00 inFace=264 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00/1/2749/91/0</div>
</div>
<div class=""><br class="">
</div>
<div class=""><b class="">*NOTE:</b> <i class="">no data was forwarded</i></div>
<div class=""><br class="">
</div>
<div class=""><br class="">
</div>
<div class=""><b class="">NFD3 log:</b></div>
<div class="">
<div class=""><u class=""><i class="">initial interest:</i></u><span class="x_x_Apple-tab-span" style="white-space:pre">
</span>1421288806.249712 DEBUG: [Forwarder] onIncomingInterest face=266 interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.250177 DEBUG: [Forwarder] onOutgoingInterest face=269 interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.250573 DEBUG: [BestRouteStrategy2] /ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00?ndn.MustBeFresh=1&ndn.InterestLifetime=5000&ndn.Nonce=108889115
from=266 newPitEntry-to=269</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span><b class="">^271ms</b></div>
<div class=""><u class=""><i class="">data generated:</i></u><span class="x_x_Apple-tab-span" style="white-space:pre">
</span>1421288806.521982 DEBUG: [Forwarder] onIncomingData face=269 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00/1/2749/91/0</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.522531 DEBUG: [Forwarder] onIncomingData matching=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.522844 DEBUG: [Strategy] beforeSatisfyPendingInterest pitEntry=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00 inFace=269 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00/1/2749/91/0</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.523363 DEBUG: [Forwarder] onOutgoingData face=266 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00/1/2749/91/0</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span><b class="">^273ms</b></div>
<div class=""><u class=""><i class="">retransmission:</i></u><span class="x_x_Apple-tab-span" style="white-space:pre">
</span>1421288806.796022 DEBUG: [Forwarder] onIncomingInterest face=266 interest=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00</div>
<div class=""><span class="x_x_Apple-tab-span" style="white-space:pre"></span>1421288806.796418 DEBUG: [Forwarder] onOutgoingData face=266 data=/ndn/edu/ucla/remap/ndnrtc/user/remap/streams/camera/low/delta/2657/data/%00%00/1/2749/91/0</div>
</div>
<div class=""><br class="">
</div>
<div class=""><br class="">
</div>
<div class=""><br class="">
</div>
<div class="">There are several questions arise:</div>
<div class="">1. Why do you think the delay b/w initial interest and retransmission for the NFD2 became 545ms (compared to 270ms with NFD1)? Could it be WiFi fault?</div>
<div class="">2. How come the delay b/w initial interest and data in NFD3 is 271ms and NFD3 forwards this data to NFD2, but NFD2 didn’t get this data and instead got retransmission interest after another 545-271=<b class="">274ms
</b>and later got the same data with 13ms difference? Could it be unreliable logging in NFD?</div>
<div class=""><br class="">
</div>
<div class="">I attached full NFD logs to this message.</div>
<div class=""><br class="">
</div>
<div class="">Thank you in advance.</div>
<div class="">All ideas and thoughts are welcome. </div>
<div class=""><br class="">
</div>
<div class="">Thanks,</div>
<div class=""><br class="">
</div>
<div class="">PS. Basically, such things block deployment of NDN-RTC (NdnCon) for the community as it delivers low-quality user experience (i.e. videoconference with interruptions =( ), so I really hope for the help and feedback.</div>
<div class=""><br class="">
</div>
<div class=""></div>
</div>
</div>
<div class="" style="word-wrap:break-word">
<div class="">
<div class=""></div>
<div class=""><br class="">
<div class="">-- <br class="">
Peter Gusev<br class="">
<a href="mailto:peter@remap.ucla.edu" class="">peter@remap.ucla.edu</a><br class="">
+1 213 5872748 (USA)<br class="">
+7 916 4434826 (Russia)<br class="">
+37 259 226448 (in case any other number is unavailable)<br class="">
peetonn_ (skype) </div>
<br class="">
</div>
</div>
</div>
</div>
<span id="x_cid:C0590A729FA81242A279143287A78C16@em.ucla.edu"><Archive.zip></span>_______________________________________________<br class="">
Nfd-dev mailing list<br class="">
<a href="mailto:Nfd-dev@lists.cs.ucla.edu" class="">Nfd-dev@lists.cs.ucla.edu</a><br class="">
http://www.lists.cs.ucla.edu/mailman/listinfo/nfd-dev<br class="">
</div>
</blockquote>
</div>
<br class="">
</div>
</body>
</html>