[Click] Scheduling of timers in nsclick

[Jonathan Kirchhoff]

Hi,

I'm a bit confused about the behavior of the Timer class in nsclick 
(Click 1.07rc1 / NS-2.33).

I have written an Element that adds random jitter to outgoing packets, 
keeping the original order of arrival. It is based on an idea posted on 
this list a few years ago [1].

The element pulls packets from a NotifierQueue and adds them to a FIFO 
queue. For each packet, a departure time within Current_Time + [0, 
MAXJITTER] it generated and added to a separate list in ascending order. 
A timer is scheduled using the first element of the departure time list 
(schedule_at(Timestamp)). On execution of the run_timer() function, a 
packet is pushed to the output port and the departure time is removed 
from the list. The timer is rescheduled using the next departure time, 
if the list is non empty.

However, the usage of timers for scheduling produces unexpected results; 
here's an example:

Scenario: 2 nodes (*.1, *.2).
    - Node 1 generates packets using TimedSource (0.5s interval), adds 
jitter, and outputs them on eth0 (wireless).
    - Node 2 receives packets on eth0, adds jitter, and discards them 
afterwards.

The jitter is uniformly distributed within [0, 0.05]. I have attached 
the click config of the sender [2] and the receiver [3].

------

The first packet is generated and jittered:

ODMRPJitter [0.500000][192.168.1.1]: Packet enqueued, next departure at 
0.533000
ODMRPJitter [0.500000][192.168.1.1]: Timer expires at 0.533000
ODMRPJitter [0.533000][192.168.1.1]: Arrival = 0.500000, Departure = 
0.533000, Diff = 0.033000 /* Packet is sent to eth0 */

No problems so far. Node 1 generates a packet (using TimedSource), 
schedules departure at 0.533 and outputs the packet upon expiry of the 
timer.

The packet is then received by node 2:

Receive: 0.536686: 192.168.1.1 > 192.168.1.2: ip-proto-4
ODMRPJitter [0.536686][192.168.1.2]: Packet enqueued, next departure at 
0.572686
ODMRPJitter [0.536686][192.168.1.2]: Timer expires at 0.572686

Like before, a timer is set to expire at a given time, but this time, 
the scheduling seems to go wrong:

ODMRPJitter [1.000000][192.168.1.1]: Packet enqueued, next departure at 
1.027000
ODMRPJitter [1.000000][192.168.1.1]: Timer expires at 1.027000
ODMRPJitter [1.027000][192.168.1.1]: Arrival = 1.000000, Departure = 
1.027000, Diff = 0.027000
Receive: 1.030786: 192.168.1.1 > 192.168.1.2: ip-proto-4
ODMRPJitter [1.030786][192.168.1.2]: Arrival = 0.536686, Departure = 
1.030786, Diff = 0.494100 /* Max delay exceeded! */

The timer did not fire at 0.572686; instead, it is executed upon the 
next receive event.

Strangely, the jittering of the second packet received by node 2 works 
as expected:

ODMRPJitter [1.030786][192.168.1.2]: Packet enqueued, next departure at 
1.045786
ODMRPJitter [1.030786][192.168.1.2]: Timer expires at 1.045786
ODMRPJitter [1.045786][192.168.1.2]: Arrival = 1.030786, Departure = 
1.045786, Diff = 0.015000

------

This scheme repeats just as described above. Every second packet which 
is received by node 2 exceeds it's maximum delay due to this anomaly.

It seems that the correct scheduling of the timer is somehow connected 
to the eth0 receive events. I was not able to reproduce the problem with 
nodes independently generating and discarding packets (without ever 
sending them). However, I fail to understand the circumstances which 
lead to this scheduling anomaly.

I would be really glad if someone would give me a hint on this, because 
I'm somewhat stuck on this problem.

I will of course provide further examples, explanations or code excerpts 
if necessary.

Thanks in advance!

Regards
Jonathan

[1] http://pdos.csail.mit.edu/pipermail/click/2005-January/003446.html


[2] Configuration of the sender

elementclass ODMRP {
  $myaddr, $myaddr_ethernet |

  TimedSource(INTERVAL 0.5)
      -> SetTimestamp
      -> IPEncap(4, $myaddr, 192.168.1.2)
      -> EtherEncap(0x0800,  $myaddr_ethernet, FF:FF:FF:FF:FF:FF)
      -> NotifierQueue
      -> ODMRPJitter(0.05, $myaddr, DEBUG 1)
      -> Queue
      -> ToSimDevice(eth0);
}
odmrp_inst :: ODMRP(eth0, eth0);


[3] Configuration of the receiver

elementclass ODMRP {
  $myaddr, $myaddr_ethernet |

  FromSimDevice(eth0, 4096)
    -> Strip(14)
    -> SetTimestamp
    -> CheckIPHeader
    -> IPPrint(Receive, TIMESTAMP 1)
    -> NotifierQueue
    -> ODMRPJitter(0.05, $myaddr, DEBUG 1)
    -> Queue
    -> IPPrint(Forward, TIMESTAMP 1)
    -> Discard;
}
odmrp_inst :: ODMRP(eth0, eth0);