<html><head><meta http-equiv="content-type" content="text/html; charset=utf-8"></head><body dir="auto"><div>From what I can see, the most time was spent on verifying of the command interest and signing the response.<br><br>---<div>Alex</div></div><div><br>On Apr 28, 2014, at 6:45 PM, "Thompson, Jeff" <<a href="mailto:jefft0@remap.ucla.edu">jefft0@remap.ucla.edu</a>> wrote:<br><br></div><blockquote type="cite"><div>
<meta http-equiv="Content-Type" content="text/html; charset=Windows-1252">
<div>Below is the DEBUG trace of prefix registration on the Pi. I changed the timestamps to elapsed time from receiving the request (and trucated the interests). Of course with the terminal I/O, it now takes 2.7 seconds, but hopefully it is representative.</div>
<div><br>
</div>
<div>- Jeff T</div>
<div><br>
</div>
<div>
<div>0.000 DEBUG: [TcpChannel] [0.0.0.0:6363] << Connection from 127.0.0.1:45549</div>
<div>0.001 INFO: [FaceTable] Added face id=5 remote=tcp4://127.0.0.1:45549 local=tcp4://127.0.0.1:6363</div>
<div>0.324 DEBUG: [Forwarder] onIncomingData face=1 data=/localhost/nfd/faces/events/%04</div>
<div>0.335 DEBUG: [Forwarder] onIncomingData matching=/localhost/nfd/faces/events</div>
<div>0.340 DEBUG: [Strategy] beforeSatisfyPendingInterest pitEntry=/localhost/nfd/faces/events inFace=1 data=/localhost/nfd/faces/events/%04</div>
<div>0.350 DEBUG: [Forwarder] onOutgoingData face=4 data=/localhost/nfd/faces/events/%04</div>
<div>0.355 DEBUG: [FaceMonitor] onNotification: Interest sent: /localhost/nfd/faces/events/%05?ndn.InterestLifetime=60000 milliseconds&ndn.Nonce=2975392766</div>
<div>0.363 DEBUG: [Forwarder] onIncomingInterest face=5 interest=/localhost/nfd/rib/register/h%0C%07%0A%08%08testecho</div>
<div>0.451 DEBUG: [Forwarder] onOutgoingInterest face=4 interest=/localhost/nfd/rib/register/h%0C%07%0A%08%08testecho</div>
<div>0.544 DEBUG: [Forwarder] onIncomingInterest face=4 interest=/localhost/nfd/faces/events/%05</div>
<div>0.555 DEBUG: [Forwarder] onOutgoingInterest face=1 interest=/localhost/nfd/faces/events/%05</div>
<div>0.568 DEBUG: [InternalFace] 1398735087.459180 DEBUG: [RibManager] Parameters parsed OK</div>
<div>0.570 DEBUG: [RibManager] command result: processing verb: register: /localhost/nfd/faces/events/%05</div>
<div>0.581 DEBUG: [InternalFace] found Interest filter for /localhost/nfd/faces (previous match)</div>
<div>0.597 DEBUG: [FaceManager] command result: processing verb: events</div>
<div>0.908 DEBUG: [Forwarder] onIncomingInterest face=4 interest=/localhost/nfd/fib/add-nexthop/h%12%07%0A%08%08testechoi%01%05j%01%00/%00%00%01E%AB%1B%A7r</div>
<div>1.004 DEBUG: [Forwarder] onOutgoingInterest face=1 interest=/localhost/nfd/fib/add-nexthop/h%12%07%0A%08%08testechoi%01%05j%01%00/%00%00%01E%AB%1B%A7r</div>
<div>1.095 DEBUG: [InternalFace] received Interest: /localhost/nfd/fib/add-nexthop/h%12%07%0A%08%08testecho</div>
<div>1.944 DEBUG: [Forwarder] onOutgoingData face=4 data=/localhost/nfd/fib/add-nexthop/h%12%07%0A%08%08testechoi%01%05j%01%00/%00%00%01E%AB%1B%A7r</div>
<div>2.356 DEBUG: [Forwarder] onIncomingData face=4 data=/localhost/nfd/rib/register/h%0C%07%0A%08%08testecho/%01E%AB%1B%A2%93</div>
<div>2.443 DEBUG: [Forwarder] onIncomingData matching=/localhost/nfd/rib/register/h%0C%07%0A%08%08testecho/%01E%AB%1B%A2%93/%BF%15%EE%EE%FC%CDw%C5</div>
<div>2.528 DEBUG: [Strategy] beforeSatisfyPendingInterest pitEntry=/localhost/nfd/rib/register/h%0C%07%0A%08%08testecho/%01E%AB%1B%A2%93/%BF%15%EE%EE%FC%CDw%C5</div>
<div>2.691 DEBUG: [Forwarder] onOutgoingData face=5 data=/localhost/nfd/rib/register/h%0C%07%0A%08%08testecho/%01E%AB%1B%A2%93</div>
</div>
<div><br>
</div>
<span id="OLK_SRC_BODY_SECTION">
<div style="font-family:Calibri; font-size:11pt; text-align:left; color:black; BORDER-BOTTOM: medium none; BORDER-LEFT: medium none; PADDING-BOTTOM: 0in; PADDING-LEFT: 0in; PADDING-RIGHT: 0in; BORDER-TOP: #b5c4df 1pt solid; BORDER-RIGHT: medium none; PADDING-TOP: 3pt">
<span style="font-weight:bold">From: </span>Alex Afansyev <<a href="mailto:alexander.afanasyev@ucla.edu">alexander.afanasyev@ucla.edu</a>><br>
<span style="font-weight:bold">Date: </span>Monday, April 28, 2014 6:18 PM<br>
<span style="font-weight:bold">To: </span>Jeff Thompson <<a href="mailto:jefft0@remap.ucla.edu">jefft0@remap.ucla.edu</a>><br>
<span style="font-weight:bold">Cc: </span>Jeff Burke <<a href="mailto:jburke@remap.ucla.edu">jburke@remap.ucla.edu</a>>, nfd-dev <<a href="mailto:nfd-dev@lists.cs.ucla.edu">nfd-dev@lists.cs.ucla.edu</a>><br>
<span style="font-weight:bold">Subject: </span>Re: [Nfd-dev] Interest lifetime for NFD command interests<br>
</div>
<div><br>
</div>
<div>
<div style="word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space;">
it's in the config file. You can either change log level globally (the most verbose is TRACE) or do it per-module
<div><br>
</div>
<div>---</div>
<div>Alex</div>
<div><br>
<div>
<div>On Apr 28, 2014, at 6:16 PM, Thompson, Jeff <<a href="mailto:jefft0@remap.ucla.edu">jefft0@remap.ucla.edu</a>> wrote:</div>
<br class="Apple-interchange-newline">
<blockquote type="cite">
<div style="word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space; font-size: 14px; font-family: Calibri, sans-serif;">
<div>Does anyone know what is the command to increase the debug log level in NFD, so I can get a trace? (nfd --help doesn't seem to say.) </div>
<div><br>
</div>
<div>- Jeff T</div>
<div><br>
</div>
<span id="OLK_SRC_BODY_SECTION">
<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);">
<span style="font-weight:bold">From: </span><Burke>, Jeff Burke <<a href="mailto:jburke@remap.ucla.edu">jburke@remap.ucla.edu</a>><br>
<span style="font-weight:bold">Date: </span>Monday, April 28, 2014 6:07 PM<br>
<span style="font-weight:bold">To: </span>Jeff Thompson <<a href="mailto:jefft0@remap.ucla.edu">jefft0@remap.ucla.edu</a>>, Alex Afansyev <<a href="mailto:alexander.afanasyev@ucla.edu">alexander.afanasyev@ucla.edu</a>><br>
<span style="font-weight:bold">Cc: </span>nfd-dev <<a href="mailto:nfd-dev@lists.cs.ucla.edu">nfd-dev@lists.cs.ucla.edu</a>><br>
<span style="font-weight:bold">Subject: </span>Re: [Nfd-dev] Interest lifetime for NFD command interests<br>
</div>
<div><br>
</div>
<div>
<div style="word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space; font-size: 14px; font-family: Calibri, sans-serif;">
<div><br>
</div>
<div>Most of the redmine issue referenced by Alex deals with timeouts in the case of an unavailable remote node, failed dns lookup, etc., but in a successful registration—such as the one taking 1200ms on the PI— what are the dominant time components? </div>
<div><br>
</div>
<div>Jeff</div>
<div><br>
</div>
<span id="OLK_SRC_BODY_SECTION">
<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);">
<span style="font-weight:bold">From: </span>"Thompson, Jeff" <<a href="mailto:jefft0@remap.ucla.edu">jefft0@remap.ucla.edu</a>><br>
<span style="font-weight:bold">Date: </span>Tue, 29 Apr 2014 00:58:44 +0000<br>
<span style="font-weight:bold">To: </span>Alex Afanasyev <<a href="mailto:alexander.afanasyev@ucla.edu">alexander.afanasyev@ucla.edu</a>><br>
<span style="font-weight:bold">Cc: </span>nfd-dev <<a href="mailto:nfd-dev@lists.cs.ucla.edu">nfd-dev@lists.cs.ucla.edu</a>><br>
<span style="font-weight:bold">Subject: </span>Re: [Nfd-dev] Interest lifetime for NFD command interests<br>
</div>
<div><br>
</div>
<div>
<div style="word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space; font-size: 14px; font-family: Calibri, sans-serif;">
<div>Hi Alex,</div>
<div><br>
</div>
<div>Fair enough. But I just tested on the Raspberry Pi, and it takes NFD 1200 seconds to answer a prefix registration. For use on the Pi, we increased the command interest lifetime to 2000 milliseconds.</div>
<div><br>
</div>
<div>- Jeff T</div>
<div><br>
</div>
<span id="OLK_SRC_BODY_SECTION">
<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);">
<span style="font-weight:bold">From: </span>Alex Afansyev <<a href="mailto:alexander.afanasyev@ucla.edu">alexander.afanasyev@ucla.edu</a>><br>
<span style="font-weight:bold">Date: </span>Friday, April 18, 2014 2:10 PM<br>
<span style="font-weight:bold">To: </span>Jeff Thompson <<a href="mailto:jefft0@remap.ucla.edu">jefft0@remap.ucla.edu</a>><br>
<span style="font-weight:bold">Cc: </span>nfd-dev <<a href="mailto:nfd-dev@lists.cs.ucla.edu">nfd-dev@lists.cs.ucla.edu</a>><br>
<span style="font-weight:bold">Subject: </span>Re: [Nfd-dev] Interest lifetime for NFD command interests<br>
</div>
<div><br>
</div>
<div>
<div style="word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space;">
<div>Hi Jeff,</div>
<div><br>
</div>
<div>I agree completely with this for prefix registration commands. I would say, there is no much value/reason to make the lifetime longer than, say, a second. Could be shorter, but on some extremely busy systems (like our Jenkins slave), even a simple registration
may take some time.</div>
<div><br>
</div>
<div>For face creation, lifetime should be longer that 4 seconds since it can take some time to create some tunnels (e.g., TCP). We even have a redmine issue for that (<a href="http://redmine.named-data.net/issues/1455">http://redmine.named-data.net/issues/1455</a>)</div>
<div><br>
</div>
<div>---</div>
<div>Alex</div>
<br>
<div>
<div>On Apr 18, 2014, at 11:51 AM, Thompson, Jeff <<a href="mailto:jefft0@remap.ucla.edu">jefft0@remap.ucla.edu</a>> wrote:</div>
<br class="Apple-interchange-newline">
<blockquote type="cite">
<div style="word-wrap: break-word; -webkit-nbsp-mode: space; -webkit-line-break: after-white-space; font-size: 14px; font-family: Calibri, sans-serif;">
<div>For a command interest to NFD/NRD, is there a recommended InterestLifetime (used as a timeout)? Since it goes to the local host, can it safely be shorter than 4000 milliseconds?</div>
<div><br>
</div>
<div>Thank you,</div>
<div>- Jeff T</div>
</div>
</blockquote>
</div>
</div>
</div>
</span></div>
</div>
_______________________________________________ Nfd-dev mailing list <a href="mailto:Nfd-dev@lists.cs.ucla.edu">
Nfd-dev@lists.cs.ucla.edu</a> <a href="http://www.lists.cs.ucla.edu/mailman/listinfo/nfd-dev">
http://www.lists.cs.ucla.edu/mailman/listinfo/nfd-dev</a> </span></div>
</div>
</span></div>
</blockquote>
</div>
<br>
</div>
</div>
</div>
</span>
</div></blockquote></body></html>