<html>
<head>
<meta http-equiv="Content-Type" content="text/html; charset=Windows-1252">
</head>
<body style="word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space;" class="">
Hi Junxiao,
<div class=""><br class="">
</div>
<div class="">Thanks for your input!</div>
<div class="">I'm surprised to know that NFD2 was overloaded - this hub did not run any extraneous apps except MacOS Activity Monitor and NFD itself, however NFD1 and NFD3 were executing NDN-RTC code (consumer and producer respectively).</div>
<div class="">Besides that, NDN-RTC was running on lowest configuration (having one 8000-bytes segment per frame) so the number of interests was minimal (~30 interests/sec), which means for higher quality, the number of interests will increase.</div>
<div class=""><br class="">
</div>
<div class="">Thanks,</div>
<div class=""><br class="">
<div apple-content-edited="true" 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="">
peetonn_ (skype) </div>
<br class="">
<div>
<blockquote type="cite" class="">
<div class="">On Jan 21, 2015, at 11:03 PM, Burke, Jeff <<a href="mailto:jburke@remap.ucla.edu" class="">jburke@remap.ucla.edu</a>> wrote:</div>
<br class="Apple-interchange-newline">
<div class="">
<div style="word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space; font-size: 14px; font-family: Calibri, sans-serif;" class="">
<div class="">Hi Junxiao,</div>
<div class="">Thanks for looking at this. </div>
<div class="">Would this <50% CPU utilization target to apply to end-hosts as well?  (Seems hard to meet this while running media apps.)</div>
<div class="">Jeff</div>
<span id="OLK_SRC_BODY_SECTION" class="">
<div style="font-family: Calibri; font-size: 11pt; text-align: left; border-width: 1pt medium medium; border-style: solid none none; padding: 3pt 0in 0in; border-top-color: rgb(181, 196, 223);" class="">
<span style="font-weight:bold" class="">From: </span>Junxiao Shi <<a href="mailto:shijunxiao@email.arizona.edu" class="">shijunxiao@email.arizona.edu</a>><br class="">
<span style="font-weight:bold" class="">Date: </span>Wed, 21 Jan 2015 23:39:03 -0700<br class="">
<span style="font-weight:bold" class="">To: </span>"Gusev, Peter" <<a href="mailto:peter@remap.UCLA.EDU" class="">peter@remap.UCLA.EDU</a>><br class="">
<span style="font-weight:bold" class="">Cc: </span>"<<a href="mailto:nfd-dev@lists.cs.ucla.edu" class="">nfd-dev@lists.cs.ucla.edu</a>>" <<a href="mailto:nfd-dev@lists.cs.ucla.edu" class="">nfd-dev@lists.cs.ucla.edu</a>><br class="">
<span style="font-weight:bold" class="">Subject: </span>Re: [Nfd-dev] NDN-RTC: NFD processing logs<br class="">
</div>
<div class=""><br class="">
</div>
<blockquote id="MAC_OUTLOOK_ATTRIBUTION_BLOCKQUOTE" style="BORDER-LEFT: #b5c4df 5 solid; PADDING:0 0 0 5; MARGIN:0 0 0 5;" class="">
<div dir="ltr" class="">Hi Peter
<div class=""><br class="">
</div>
<div class="">It appears that NFD2 node is overloaded.</div>
<div class="">There is a big delay between NFD3 returns first Data and NFD2 receives that Data.</div>
<div class="">There is a big delay between NFD1 forwards second Interests and NFD receives that Interest.</div>
<div class=""><br class="">
</div>
<div class="">To determine whether a node is overloaded, look at its CPU utilization. If CPU utilization of any core is over 50%, reduce traffic rate.</div>
<div class=""><br class="">
</div>
<div class=""><br class="">
</div>
<div class="">It's expected for NFD2 not to return the second Data, because PIT entry has been satisfied by the first Data.</div>
<div class="">When the second Data arrives, PIT entry contains no downstream record, and therefore Data will not be returned to NFD1.</div>
<div class=""><br class="">
</div>
<div class=""><br class="">
</div>
<div class="">This experiment appears to be using an outdated NFD version (older than Sep 08, 2014).</div>
<div class="">For future reports, please use git-HEAD.</div>
<div class=""><br class="">
</div>
<div class="">Yours, Junxiao<br class="">
<div class="gmail_extra"><br class="">
<div class="gmail_quote">On Wed, Jan 21, 2015 at 1:32 PM, Gusev, Peter <span dir="ltr" class="">
<<a href="mailto:peter@remap.ucla.edu" target="_blank" class="">peter@remap.ucla.edu</a>></span> wrote:<br class="">
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex">
<div class="">
<div style="word-wrap:break-word" class="">Hi all,
<div class=""><br class="">
</div>
<div class="">I’ve been testing <a href="https://github.com/remap/ndnrtc/tree/issues/2283-retransmissions" target="_blank" class=""></a><a href="https://github.com/remap/ndnrtc/tree/issues/2283-retransmissions" target="_blank" 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 style="white-space:pre-wrap" class=""></span></u><span style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></span>^ 270ms</b></div>
<div class=""><i class=""><u class="">retransmission:</u></i><span style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></span><b class="">^ 286ms</b></div>
<div class=""><i class=""><u class="">data arrives:</u></i><span style="white-space:pre-wrap" class=""><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 style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></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 style="font-weight:bold" class=""><br class="">
</div>
<div class=""><b class="">NFD2 log:</b></div>
<div class="">
<div class=""><i class=""><u class="">initial interest:</u></i><span style="white-space:pre-wrap" class=""><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 style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></span><b class="">^ 545ms</b></div>
<div class=""><i class=""><u class="">retransmission:</u></i><span style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></span><b class="">^ 2ms</b></div>
<div class=""><i class=""><u class="">data arrives:</u></i><span style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></span><b class="">^ 13ms</b></div>
<div class=""><i class=""><u class="">data arrives 2:*</u></i><span style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></span><b class="">^271ms</b></div>
<div class=""><u class=""><i class="">data generated:</i></u><span style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></span><b class="">^273ms</b></div>
<div class=""><u class=""><i class="">retransmission:</i></u><span style="white-space:pre-wrap" class=""></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 style="white-space:pre-wrap" class=""></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>
<span class=""><font color="#888888" class="">
<div class=""><br class="">
</div>
<div class=""></div>
</font></span></div>
<span class=""><font color="#888888" class=""></font></span></div>
<span class=""><font color="#888888" class="">
<div style="word-wrap:break-word" class="">
<div class="">
<div class=""></div>
<div class=""><br class="">
<div class="">-- <br class="">
Peter Gusev<br class="">
<a href="mailto:peter@remap.ucla.edu" target="_blank" class="">peter@remap.ucla.edu</a><br class="">
<a href="tel:%2B1%20213%205872748" value="+12135872748" target="_blank" class="">+1 213 5872748</a> (USA)<br class="">
<a href="tel:%2B7%20916%204434826" value="+79164434826" target="_blank" class="">+7 916 4434826</a> (Russia)<br class="">
<a href="tel:%2B37%20259%20226448" value="+37259226448" target="_blank" class="">+37 259 226448</a> (in case any other number is unavailable)<br class="">
peetonn_ (skype)</div>
</div>
</div>
</div>
</font></span></div>
</blockquote>
</div>
</div>
</div>
</div>
_______________________________________________ Nfd-dev mailing list <a href="mailto:Nfd-dev@lists.cs.ucla.edu" class="">
Nfd-dev@lists.cs.ucla.edu</a> <a href="http://www.lists.cs.ucla.edu/mailman/listinfo/nfd-dev" class="">
http://www.lists.cs.ucla.edu/mailman/listinfo/nfd-dev</a> </blockquote>
</span></div>
</div>
</blockquote>
</div>
<br class="">
</div>
</body>
</html>