[Nfd-dev] RTT delay caused by RIB registration commands

[Junxiao Shi]

Hi Vince

This is similar to #1589 and #2174. Ubuntu could affected by those issues,
but it's less severe than OSX.


When you do prefix registration with nfdc using a FaceId, the following
signing operations are involved:

   1. nfdc connects to NFD: NFD signs face status change notification
   2. nfdc sends registration command to RIB: nfdc signs the command
   3. RIB answers registration command to nfdc: RIB signs the answer
   4. RIB sends FIB update(s) to NFD: RIB signs FIB update command(s)
   5. NFD answers FIB update(s): NFD signs the answer(s)
   6. nfdc disconnects from NFD: NFD signs face status change notification

There are at least 6 signing operations, assuming the registration triggers
only one FIB update.
At least 4 signing operations are within NFD thread.
If using RSA, they will take 78ms with osx-keychain TPM, and 10ms with file
TPM on Ubuntu (see #1589 note-1 benchmark).

The log shows 13ms extra RTT when processing a registration command. This
is in line with the calculation above.
10ms is spent for RSA signing, and 3ms is spent for other processing (eg.
step 6 also causes NFD to enumerate the FIB to erase NextHopRecords that
points to the failing face).


To either confirm or reject this hypothesis, please try doing the prefix
registration with FaceUri of an non-existing UDP face.
This should cause nfdc to send a face query request followed by a face
creation command, and make NFD to sign two more answers.
If the RTT is further increased by about 5ms, the hypothesis is confirmed.

Yours, Junxiao


On Thu, Apr 23, 2015 at 4:15 PM, Vince Lehman (vslehman) <
vslehman at memphis.edu> wrote:

>
>  I am able to replicate this result on my laptop from the command line.
> When I run an ndnping server and ndnping on my laptop, I see consistent
> RTTs. But, when I send
> nfdc register commands at a relatively slow interval (0.5 s) at the same
> time, I see a large jump in the RTT.
>
>  Below is an example. I started the RIB registrations right after the
> ping with reference 810245465.
>
> Content From /ndn - Ping Reference = 810245463   - Round Trip Time =
> 1.271 ms
> Content From /ndn - Ping Reference = 810245464   - Round Trip Time =
> 1.436 ms
> Content From /ndn - Ping Reference = 810245465   - Round Trip Time =
> 1.328 ms
> Content From /ndn - Ping Reference = 810245466   - Round Trip Time = 1.22
> ms
> Content From /ndn - Ping Reference = 810245467   - Round Trip Time =
> 14.618 ms
> Content From /ndn - Ping Reference = 810245468   - Round Trip Time =
> 1.255 ms
> Content From /ndn - Ping Reference = 810245469   - Round Trip Time =
> 1.211 ms
>
>  I used this simple bash script to send the registration commands:
> for i in `seq 1 25`; do
>   nfdc register /a 258
>   sleep 0.5
> done
>
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.lists.cs.ucla.edu/pipermail/nfd-dev/attachments/20150424/fbe27c19/attachment.html>