Project

General

Profile

Bug #2473

Inconsistency in UDP face timeouts

Added by John DeHart over 4 years ago. Updated over 4 years ago.

Status:
Closed
Priority:
Low
Assignee:
Category:
Management
Target version:
Start date:
02/03/2015
Due date:
% Done:

100%

Estimated time:

Description

The UDP face timeout specified in the nfd config file and the value used don't agree.

I have 600 seconds specified in the config file but faces actually expire at 1200 seconds.
The message in the log file says 600 seconds.

I don’t have an easy way to check to see if this has been fixed in newer versions.
This is the released version of nfd that we run on the Testbed.
It is not causing any problems, just an inconsistency.

$ grep idle_timeout /etc/ndn/nfd.conf
    idle_timeout 600 ; idle time (seconds) before closing a UDP unicast face

$ nfd-status -f | grep 10.0.2.1
  faceid=343 remote=udp4://10.0.2.1:6363 local=udp4://10.0.2.2:6363 expires=1112s counters={in={2i 0d 108B} out={192i 2d 18059B}} non-local on-demand point-to-point

ndnops@ndnops:~$ grep 10.0.2.1 /var/log/ndn/nfd.log  | grep 343
1422989686.487219 INFO: [FaceTable] Added face id=343 remote=udp4://10.0.2.1:6363 local=udp4://10.0.2.2:6363
1422990886.487276 INFO: [UdpFace] [id:343,uri:udp4://10.0.2.1:6363] Idle for more than 600 seconds, closing
1422990886.487436 INFO: [UdpFace] [id:343,uri:udp4://10.0.2.1:6363] Close tunnel
1422990886.490994 INFO: [FaceTable] Removed face id=343 remote=udp4://10.0.2.1:6363 local=udp4://10.0.2.2:6363

ndnops@ndnops:~$ nfd-status -v
General NFD status:
                 nfdId=/localhost/daemons/nfd/KEY/ksk-1406409442387/ID-CERT
               version=0.2.0-88-gc5173de
             startTime=20150203T170240.606000
           currentTime=20150203T191649.046000
                uptime=8048 seconds
      nNameTreeEntries=1113
           nFibEntries=65
           nPitEntries=865
    nMeasurementsEntries=83
            nCsEntries=8192
          nInInterests=3695849
         nOutInterests=962078
              nInDatas=56719
             nOutDatas=56949

History

#1 Updated by Junxiao Shi over 4 years ago

  • Tracker changed from Task to Bug
  • Description updated (diff)
  • Category set to Management
  • Assignee set to Chengyu Fan
  • Priority changed from Normal to Low
  • Target version set to v0.3

#2 Updated by Chengyu Fan over 4 years ago

After check the code, I think the bug may be caused by the udp-face.cpp code.

In UdpFace::getFaceStatus(), the time left to timeout is calculated as:

time::milliseconds left = m_idleTimeout - time::duration_cast<time::milliseconds>(
  time::steady_clock::now() - m_lastIdleCheck);

The m_lastIdleCheck should be replaced using lastUsedTime (when the face is used).
Correct me if I'm wrong.

#3 Updated by Chengyu Fan over 4 years ago

Please ignore the note-2. It is not the major issue that introduces the inconsistent UDP face timeouts.

The logic in the code is a timeout face is removed when it is not used recently (in the last timeout period). Therefore, a face will be in the FIB for 2*timeout seconds.

Since this task requires the timeout must be exactly as the nfd.conf specified, the code logic is wrong.

#4 Updated by Alex Afanasyev over 4 years ago

I don't think we need exact timeout for UDP faces. This issue can be closed if we simply put comment about the UDP timeout parameter in the config file. The intention for non-precise timeout value is to reduce bookkeeping/scheduling overhead.

#5 Updated by Chengyu Fan over 4 years ago

If the timeout value is only to reduce the bookkeeping/scheduling overhead, I agree that put UDP timeout in the config file is good enough to let operators understand it.

Anyone has different opinions?

#6 Updated by Junxiao Shi over 4 years ago

face_system.udp.idle_timeout option represents the interval between idle checks. If an on-demand face has no incoming message between two checks, it's closed due to idle.

It's too expensive to reset the timer upon each incoming message, so the actual timeout would be anywhere within [idle_timeout, 2*idle_timeout).
Since the timer starts when the face is created, in the extreme case where only one message is received ever, the actual timeout would be close to 2*idle_timeout.

I agree with note-3 that this problem only needs a documentation update.

note-2 points out a related but different issue: the expiration time reported in Face Dataset.

I'm unsure what's the current algorithm, but the accurate algorithm is:

duration computeRemainingLifetime()
{
  if (face is not on-demand) {
    return infinite;
  }

  if (no incoming message since last idle check) {
    return duration until next idle check;
  }
  else {
    return duration until next idle check + interval between idle checks;
  }
}

#7 Updated by Chengyu Fan over 4 years ago

@Junxiao, the current algorithm did exactly as you suggested.

Therefore, I'll just do the config file update for this bug.

#8 Updated by Chengyu Fan over 4 years ago

  • Status changed from New to Code review
  • % Done changed from 0 to 100

#9 Updated by Alex Afanasyev over 4 years ago

Just to alert everybody. As part of this task, we are changing the default value for UDP timeout: from 30 to 600 seconds. For a long time we had inconsistency between effective "default" value in sample configuration file (600) and actual default value in face manager. I'll send alert to nfd-dev mailing list.

#10 Updated by Junxiao Shi over 4 years ago

  • Status changed from Code review to Closed

Also available in: Atom PDF