[Click] NSClick - performance upgrade for NS-2
Björn Lichtblau
lichtbla at informatik.hu-berlin.de
Thu Jan 26 05:46:37 EST 2012
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();
More information about the click
mailing list