[Click] NSClick - performance upgrade for NS-2

Björn Lichtblau lichtbla at informatik.hu-berlin.de
Fri Feb 17 12:43:08 EST 2012


Hi,

yes, this in contrast to the last patch runs well for me, however my 
colleague using ns-2 complains. Can anyone else using ns-2 test that 
(cause we have some modifications in click and ns2.. just to be sure)?

The time for him is advancing very slowly, basically click and sim are 
pingponging until ns_active_iter is greater than ns_iters_per_time and 
than advances an Timestamp::epsilon, always. We need to investigate a 
bit further here..

And i'm still curious to know how you intend this to work in all cases, 
regarding that a packet pushed into an element can lead to aborting a 
timer and/or later/earlier scheduling of a timer. But maybe im thinking 
too theoretical here?

Thanks again for your effort, regards, Björn


On 02/17/2012 01:53 AM, Eddie Kohler wrote:
> Hi Björn,
>
> I bit the bullet and ran this under NS-3. I fixed some bugs and ran it 
> enough times that I am pretty confident it works (the previous version 
> did have bugs). I checked it into master. Let me know if it helps.
>
> Eddie
>
>
> On 1/26/12 5:46 AM, Björn Lichtblau wrote:
>> Hi,
>>
>> On 01/25/2012 11:14 PM, Eddie Kohler wrote:
>>> Hi Björn,
>>>
>>> On 1/25/12 3:52 PM, Björn Lichtblau wrote:
>>>> Click can't run too fast, Click and simulator are synchronized, 
>>>> running
>>>> serialized. Time in Click won't advance until routerthread returns to
>>>> the simulator, and the simulator calls Click exactly at that time it
>>>> requested with SIMCLICK_SCHEDULE.
>>>
>>> Click runs outside of the simulator too, remember. The relationship
>>> between simulator time and Click time is an issue with the current
>>> design.
>>>
>> Sure! My comment was only meant for when Click is coupled with a
>> simulator, and i agree, the misfit between real-world and simulator
>> environment is where problems stem from. I wanted to clarify (just to be
>> on the safe side) that event pileup did not happen because someone's
>> running too fast but because the contract how to handle a
>> SIMCLICK_SCHEDULE in detail is undocumented and can be interpreted in
>> different ways.
>> So may i ask how you want it to work now, like "everytime
>> SIMCLICK_SCHEDULE is called the simulator must call Click at that 
>> time" ?
>>
>>>> Regarding the commit i get strange results, but i have to recheck. 
>>>> Does
>>>> this patch try to also solve the issue Lalith raised: "Patch for
>>>> nanosecond scheduling precision in ns-3-click" ?
>>>
>>> It prepares for that issue but doesn't solve it. Can you explain what
>>> strange results you see?
>>>
>> Ok, i first though it happens because i had the ns3-side patch of
>> Laliths applied, but still does not work with an older version.
>>
>> I have this script below which should send a packet at 0s, 0.5s and 1s.
>> (could be boiled down just to RatedSource ->  Queue ->  Discard). The
>> output below shows that Click is called fine at 0 where the packet is
>> generated.
>>
>> Then SLEEPINESS_TRIGGER ping-pongs happen because of using the Queue and
>> the issue i mentioned before. I just left this in to show Click is still
>> doing multiple SIMCLICK_SCHEDULEs for the same time (0s). But that's
>> fine here because it is needed i think, intended ?
>>
>> The problem now is that finally Click schedules for 501ms (i don't know
>> where this +1 ms is coming from, but it's fine and has always been there
>> in this test, the 3rd and last packet would get scheduled at 1.001s).
>> But when Click is called at 0.501s nothing happens and Click does not
>> reschedule, taking the second break in Routerthread::driver() at the
>> end, so nothing more ever happens.
>>
>> Just a complete guess, but it looks like the previous issue (
>> http://pdos.csail.mit.edu/pipermail/click/2011-October/010357.html and
>> http://pdos.csail.mit.edu/pipermail/click/2011-November/010408.html)
>> again. Click would need another call at 0.501s (or maybe a little bit
>> later, wasn't there an artificial advancement of 1us or 1ns added?
>> *confused*) because the first call only expires the timer which makes
>> the task ready, and the task is only run with another Click call, which
>> won't happen now because Click already called SIMCLICK_SCHEDULE for 
>> 0.501s.
>> (But why is Click doing that for 0.0s, is that a special case?).
>>
>> Björn
>>
>>
>> Script:
>>
>> RatedSource(\<AAAAAAAAAAAAAAAABBBBBBBBBBBBBBBBCCCCCCCCCCCCCCCCDDDDDDDDDDDDDDDDEEEEEEEEEEEEEEEEFFFFFFFFFFFFFFFF>, 
>>
>> RATE 2, LIMIT 3) ->
>>       IncrementSeqNo(NET_BYTE_ORDER true, OFFSET 2) ->
>>           Queue() ->
>>       EtherEncap(0xBBBB, 00:00:00:00:00:00, ff:ff:ff:ff:ff:ff) ->
>>       SetTXRate(RATE 108) ->
>>       WifiEncap(0x00, 0:0:0:0:0:0) ->
>>       RadiotapEncap() ->
>>       Print("txing ", MAXLENGTH 50) ->
>>       Discard;
>>
>>
>> Output:
>>
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0
>> SIMCLICK_IFID_FROM_NAME: eth0 1
>> 0s Ipv4ClickRouting:DoStart(): Node0 has initialised a Click Router
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_IF_READY: 1
>> +0.0ns
>> txing :   92 | 00000c00 04040300 6c00000b 08000000 ffffffff ffff0000
>> 00000000 00000000 00000000 aaaa0300 0000bbbb aaaa0000 0000
>> 0s Ipv4ClickRouting:simclick_sim_send(): simclick_sim_send called at 0:
>> 1 1  92
>> 0s Ipv4ClickRouting:HandlePacketFromClick(): HandlePacketFromClick
>> 0s Ipv4ClickRouting:HandlePacketFromClick(): Incoming packet from eth0
>> of type 1. Sending packet down the stack.
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_IF_READY: 1
>> +0.0ns
>> before run timers
>> after run timers
>> driver(): [0.000000]
>> driver(): [0.000000]
>> 0s Ipv4ClickRouting:HandleScheduleFromClick(): HandleScheduleFromClick
>> at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_SCHEDULE at
>> 0s and 0usecs.
>> 0s Ipv4ClickRouting:RunClickEvent(): RunClickEvent at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_IF_READY: 1
>> +0.0ns
>> before run timers
>> after run timers
>> driver(): [0.000000]
>> driver(): [0.000000]
>> 0s Ipv4ClickRouting:HandleScheduleFromClick(): HandleScheduleFromClick
>> at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_SCHEDULE at
>> 0s and 0usecs.
>> 0s Ipv4ClickRouting:RunClickEvent(): RunClickEvent at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_IF_READY: 1
>> +0.0ns
>> before run timers
>> after run timers
>> driver(): [0.000000]
>> driver(): [0.000000]
>> 0s Ipv4ClickRouting:HandleScheduleFromClick(): HandleScheduleFromClick
>> at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_SCHEDULE at
>> 0s and 0usecs.
>> 0s Ipv4ClickRouting:RunClickEvent(): RunClickEvent at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_IF_READY: 1
>> +0.0ns
>> before run timers
>> after run timers
>> driver(): [0.000000]0s Ipv4ClickRouting:simclick_sim_command(): Node0
>> SIMCLICK_IFID_FROM_NAME: eth0 1
>> 0s Ipv4ClickRouting:DoStart(): Node0 has initialised a Click Router
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_IF_READY: 1
>> +0.0ns
>> txing :   92 | 00000c00 04040300 6c00000b 08000000 ffffffff ffff0000
>> 00000000 00000000 00000000 aaaa0300 0000bbbb aaaa0000 0000
>> 0s Ipv4ClickRouting:simclick_sim_send(): simclick_sim_send called at 0:
>> 1 1  92
>> 0s Ipv4ClickRouting:HandlePacketFromClick(): HandlePacketFromClick
>> 0s Ipv4ClickRouting:HandlePacketFromClick(): Incoming packet from eth0
>> of type 1. Sending packet down the stack.
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_IF_READY: 1
>> +0.0ns
>> before run timers
>> after run timers
>> driver(): [0.000000]
>> driver(): [0.000000]
>> 0s Ipv4ClickRouting:HandleScheduleFromClick(): HandleScheduleFromClick
>> at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_SCHEDULE at
>> 0s and 0usecs.
>> 0s Ipv4ClickRouting:RunClickEvent(): RunClickEvent at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_IF_READY: 1
>> +0.0ns
>> before run timers
>> after run timers
>> driver(): [0.000000]
>> driver(): [0.000000]
>> 0s Ipv4ClickRouting:HandleScheduleFromClick(): HandleScheduleFromClick
>> at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_SCHEDULE at
>> 0s and 0usecs.
>> 0s Ipv4ClickRouting:RunClickEvent(): RunClickEvent at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_IF_READY: 1
>> +0.0ns
>> before run timers
>> after run timers
>> driver(): [0.000000]
>> driver(): [0.000000]
>> 0s Ipv4ClickRouting:HandleScheduleFromClick(): HandleScheduleFromClick
>> at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_SCHEDULE at
>> 0s and 0usecs.
>> 0s Ipv4ClickRouting:RunClickEvent(): RunClickEvent at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_IF_READY: 1
>> +0.0ns
>> before run timers
>> after run timers
>> driver(): [0.000000]
>> driver(): [0.000000]
>> 0s Ipv4ClickRouting:HandleScheduleFromClick(): HandleScheduleFromClick
>> at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_SCHEDULE at
>> 0s and 0usecs.
>> 0s Ipv4ClickRouting:RunClickEvent(): RunClickEvent at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_IF_READY: 1
>> +0.0ns
>> before run timers
>> after run timers
>> driver(): [0.000000]
>> driver(): [0.000000]
>> 0s Ipv4ClickRouting:HandleScheduleFromClick(): HandleScheduleFromClick
>> at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_SCHEDULE at
>> 0s and 0usecs.
>> 0s Ipv4ClickRouting:RunClickEvent(): RunClickEvent at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_IF_READY: 1
>> +0.0ns
>> before run timers
>> after run timers
>> driver(): [0.000000]
>> driver(): [0.000000]
>> 0s Ipv4ClickRouting:HandleScheduleFromClick(): HandleScheduleFromClick
>> at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_SCHEDULE at
>> 0s and 0usecs.
>> 0s Ipv4ClickRouting:RunClickEvent(): RunClickEvent at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_IF_READY: 1
>> +0.0ns
>> before run timers
>> after run timers
>> driver(): [0.000000]
>> driver(): [0.000000]
>> 0s Ipv4ClickRouting:HandleScheduleFromClick(): HandleScheduleFromClick
>> at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_SCHEDULE at
>> 0s and 0usecs.
>> 0s Ipv4ClickRouting:RunClickEvent(): RunClickEvent at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_IF_READY: 1
>> +0.0ns
>> before run timers
>> after run timers
>> driver(): [0.000000]
>> driver(): [0.000000]
>> 0s Ipv4ClickRouting:HandleScheduleFromClick(): HandleScheduleFromClick
>> at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_SCHEDULE at
>> 0s and 0usecs.
>> 0s Ipv4ClickRouting:RunClickEvent(): RunClickEvent at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_IF_READY: 1
>> +0.0ns
>> before run timers
>> after run timers
>> driver(): [0.000000]
>> driver(): [0.000000]
>> 0s Ipv4ClickRouting:HandleScheduleFromClick(): HandleScheduleFromClick
>> at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_SCHEDULE at
>> 0s and 0usecs.
>> 0s Ipv4ClickRouting:RunClickEvent(): RunClickEvent at 0 0 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_IF_READY: 1
>> +0.0ns
>> before run timers
>> after run timers
>> driver(): [0.000000]
>> driver(): [0.000000]
>> 0s Ipv4ClickRouting:HandleScheduleFromClick(): HandleScheduleFromClick
>> at 0 501000 +0.0ns
>> 0s Ipv4ClickRouting:simclick_sim_command(): Node0 SIMCLICK_SCHEDULE at
>> 0s and 501000usecs.
>> 0.501s Ipv4ClickRouting:RunClickEvent(): RunClickEvent at 0 501000
>> +501000000.0ns
>> before run timers
>> after run timers
>> driver(): [0.501000]
>> driver(): [0.501000]
>> driver(): break2
>> endPrint
>>
>> "driver(): ..." and "before/after run timers" were added to Click, the
>> rest is coming from the simulator:
>>
>> iff --git a/lib/routerthread.cc b/lib/routerthread.cc
>> index 51f5684..842fe99 100644
>> --- a/lib/routerthread.cc
>> +++ b/lib/routerthread.cc
>> @@ -635,6 +635,7 @@ RouterThread::driver()
>>    #endif
>>
>>           // run timers
>> +       click_chatter("before run timers");
>>           do {
>>    #if !BSD_NETISRSCHED
>>               if (iter % timer_set().timer_stride())
>> @@ -646,6 +647,7 @@ RouterThread::driver()
>>    #endif
>>               timer_set().run_timers(this, _master);
>>           } while (0);
>> +       click_chatter("after run timers");
>>
>>           // run operating system
>>           do {
>> @@ -685,7 +687,9 @@ RouterThread::driver()
>>    #if CLICK_NS
>>        do {
>>           Timestamp t = Timestamp::now();
>> +       click_chatter("driver(): [%{timestamp}]",&  t);
>>           t = (ns_timeval ? t.usec_ceil() : t.nsec_ceil());
>> +       click_chatter("driver(): [%{timestamp}]",&t);
>>           if (active()) {
>>               if (t != _ns_last_active) {
>>                   _ns_active_iter = 0;
>> @@ -694,10 +698,14 @@ RouterThread::driver()
>>                   t += (ns_timeval ? Timestamp::make_usec(1) :
>> Timestamp::make_nsec(1));
>>           } else if (Timestamp next_expiry =
>> timer_set().timer_expiry_steady())
>>               t = (ns_timeval ? next_expiry.usec_ceil() :
>> next_expiry.nsec_ceil());
>> -       else
>> +       else {
>> +           click_chatter("driver(): break");
>>               break;
>> -       if (_ns_scheduled&&  t>= _ns_scheduled)
>> +       }
>> +       if (_ns_scheduled&&  t>= _ns_scheduled){
>> +           click_chatter("driver(): break2");
>>               break;
>> +       }
>>           _ns_scheduled = t;
>>           if (ns_timeval) {
>>               struct timeval tv = t.timeval();
>>
>> _______________________________________________
>> click mailing list
>> click at amsterdam.lcs.mit.edu
>> https://amsterdam.lcs.mit.edu/mailman/listinfo/click




More information about the click mailing list