[Nfd-dev] Help needed with ASF measurement

[Lan Wang (lanwang)]

Would this have anything to do with virtualization (since you are using min-NDN)? Another possibility: the time was not converted properly to nanoseconds?

Lan

On Oct 24, 2016, at 1:40 PM, Ashlesh Gawande (agawande) <agawande at memphis.edu<mailto:agawande at memphis.edu>> wrote:

I haven't found anything suspicious. There doesn't seem to be a code path that generates an out record without updating last renewed field.

Even if there was a bug in the forwarding pipeline and it is not updated somewhere, I think we should not get a negative value:


1477331706.109322 ERROR: [AsfMeasurements] Recording RTT for inFace: 311

1477331706.109335 ERROR: [AsfMeasurements] steady clock now: 2148492683226381 nanoseconds since boot outRecordLastRenewed: 7018100696742452000 nanoseconds since boot

1477331706.109351 ERROR: [AsfMeasurements] steadyRtt: -7015952204059211821 nanoseconds
1477331706.109368 ERROR: [AsfMeasurements] Wrong measurement

This means time::steady_clock::now() is smaller time::steady_clock::TimePoint::min().

(Machine is Ubuntu 14.04, gcc 4.9.3.
32 NFDs are running on this machine at the same time. Such wrong measurements happen randomly).

Ashlesh
________________________________
From: Lan Wang (lanwang)
Sent: Monday, October 24, 2016 1:21:49 PM
To: Junxiao Shi
Cc: Ashlesh Gawande (agawande); <nfd-dev at lists.cs.ucla.edu<mailto:nfd-dev at lists.cs.ucla.edu>>
Subject: Re: Help needed with ASF measurement

Junxiao,

Thank you very much for the quick feedback.

Ashlesh: have you found anything suspicious?

Lan

On Oct 24, 2016, at 11:00 AM, Junxiao Shi <shijunxiao at email.arizona.edu<mailto:shijunxiao at email.arizona.edu>> wrote:

Hi Ashlesh
This is probably a forwarding pipelines bug, but I won't have time to diagnose this until at least Thursday.
Things to look at:
1. Find every code line that updates last renewed field.
2. Find which forwarding pipelines calls the function that updates last renewed field.
3. Determine if there's a code path that generates an out record without updating last renewed field.
Yours, Junxiao

On Oct 24, 2016 08:52, "Ashlesh Gawande (agawande)" <agawande at memphis.edu<mailto:agawande at memphis.edu>> wrote:
Hi Junxiao

I am testing ASF in Mini-NDN.

The following line calculates the steady RTT by subtracting outRecord->getLastRenewed()
from time::steady_clock::now()
https://github.com/named-data/NFD/blob/master/daemon/fw/asf-measurements.cpp#L117
(which is called from beforeSatisfyInterest https://github.com/named-data/NFD/blob/master/daemon/fw/asf-strategy.cpp#L115)

Sometimes the value of this steadyRTT is huge (ex: 200000 seconds) or negative.
This makes ASF change faces to a higher RTT face.

So what could be the reason that this happening? I see much better and expected results if I ignore these high/negative values.

(I see that https://github.com/named-data/NFD/blob/master/daemon/table/pit-face-record.cpp#L34
initializes getLastRenewed to time::steady_clock::TimePoint::min(). So maybe for some reason getLastRenewed does not get updated?)

Thanks
Ashlesh

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://www.lists.cs.ucla.edu/pipermail/nfd-dev/attachments/20161024/4d6947b2/attachment.html>