Sam’s Network Simulation Cradle Blog

Finally got some performance information out of NS-2/NSC. Didn’t manage to get profiling working at all, on my FreeBSD 5.1 computer in uni the link failed because it couldn’t find -lstdc++_p. Whatever that is. Couldn’t find any references to it on google.

I looked through the code to see where the data copies happen. I came up with the following findings: SENDING:

  sim: write data to socket
* stack: buffer data in socket buffer
  [data now held by stack. Eventually a packet will be sent]
  g_if_send_packet
  BSDStack::if_send_packet_mbuf
* - m_copydata (copies entire packet data)
  sim: BSDAgent::send_callback
* - memcpy (copies entire packet data)
  [memory now handled by simulation]

RECEIVING

  sim: BSDAgent::recv
  stack: BSDStack::if_receive_packet
  fake_ether_input
* - m_copyback (copies entire packet)
  netisr_dispatch
  [memory now handled by stack]
  sim: read
* copy data into read buffer

The * indicates where there is a data copy. So I went through and changes copying so only a maximum of 100 bytes is copied, where normally there would be up to 1500 bytes copied. I haven’t changed reading/writing to sockets yet, the full amount of data is copied in those situations.

I only got a small performance increase. Quite suprising! I wish I could profile the application. The following graph shows the differences in times: Graph.

Note: my new simulation framework was very useful here, it validated the simulations; the results are exactly the same with my news performance changes.

Arg! I do profiling quite a lot, but it just isn’t gonna work this time.

I added the -pg option to compiling all the files and the linker line. First of all I get stupid errors like so:

/usr/lib/libc_r.so.5: undefined reference to `clock_gettime'
/usr/lib/libc_r.so.5: undefined reference to `__sys_fchmod'
/usr/lib/libc_r.so.5: undefined reference to `__sys_aio_suspend'
/usr/lib/libc_r.so.5: undefined reference to `__siglongjmp'
/usr/lib/libc_r.so.5: undefined reference to `__pselect'
/usr/lib/libstdc++.so.4: undefined reference to `wcslen'
/usr/lib/libstdc++.so.4: undefined reference to `strtold'
/usr/lib/libc_r.so.5: undefined reference to `_getlogin'
... this continues

So I explicitly added -lc_r -lstdc++ to the linking line. This got rid of the errors. An ns.gmon file was even created. But it was 0 bytes long.

Bugger.

Began looking into performance. Added a couple of things that I thought might speed it up; just cutting down on data copies. The initial changes made it not work, when I revised them I found that it made no difference at all. Bugger.

So I decided to profile. Still waiting on the build at the moment…

More work on the simulation framework. I am now actually using more, so I’m finding features it lacks and small bugs. Just fixed the validation stuff, it now works but is more limited than I had originally planned. Currently simulations are only allowed to output one floating point number as their result, which is less than desirable. Still, it is good enough for now, a better mechanism can be found at a later date.

Need to finish off my research proposal…

Put in a lot of work on a python-based simulation framework. There is still some bash scripting there too for now, but that will go in the future I imagine.

Threw away all the old Perl scripts. Though they had progessed quite a bit, they were still messy. And I don’t really know Perl all that well.

I’m quite happy with the way the Python scripts are turning out. Python rocks. Soon I should have a nice simulation and validation framework with is MUCH more powerful than what I had before. I should really have made this a long time ago.

Spent a bit of time on my research proposal. Mostly done.

Starting thinking about new simulation framework. Decided on Python. Didn’t get much more done. Moved things from 420/ to nsc/. It’s no longer my 420, after all.

How we model the application sending data is interesting. I now have two options: NoBuffers InfiniteBuffers

The first sends data the same way iperf-hacked does. This means that if an attempt to send data fails, it forgets about the failure.

The second way I implemented some time ago, and I can’t remember why. At any rate, whenever a send fails, it makes a note of the failure (”puts it into a buffer”) and attempts to send this amount next time. This is implemented as the integer to_send which is incremented whenever you fail to send data and decremented whenever data is sent. Need to figure out why I implemented this again!

To be able to set hz in simulation I had to update the parser to work a lot better. Finished that today, it now makes a parse tree and understands the difference between local and global variables a lot better. Seems pretty good now. The entire structure and design of the parser has changed quite majorly now.

Managed to generate the interesting graph I had been trying to make 4 or so weeks ago. Find the graph here.

An interesting problem here was how the simulated sending application changed the results quite a lot. I had to change the code so it worked like my hacked iperf and suddenly the results were similar. Yay. At long last.

Huge bug fixed completely today. Boy, that has taken a while. It was all because of schednetisr. Maybe I should explain this in detail at some point…

I first re-ran my emulation network test. I put debugging in to print out what time (accurate to the microsecond) swinet() was called. This is the function that goes off and calls the correct protocol handler for each packet on each protocol queue. i.e. it calls ipinput() for each packet on the IP queue.

I noted the times between calls to this function varied a lot, they were not the ~10 milliseconds I was expecting. Even more interesting, only 1 packet was processed in each call to swi_net(). That is weird, I thought. I used to have some results a long time ago which showed more than 1 packet was processed in each call.

My only conclusion here is that my previous kernel hacks and debugging code were just plain wrong.

This means I had been formulating theories all based upon an incorrect premise. Needless to say I was unsucessful in my attempts to solve this problem in other ways.

I then went and traced through the code in simulation to see the exact code path taken when a packet arrives. It was as I understood it, there was nothing new going on here.

Then I checked the kernel code by going through by hand and checking each function to see what function it calls next. The results are below:

1. network driver (file: dev/fxp/if_fxp.c in the emulation network case)
2. ether_input (ethernet frame handling)
3. netisr_dispatch (basic packet handling, I thought this just added the packet to a queue)
4. schednetisr
5. swi_sched
6. [various kernel ithread / ISR routines]

The interesting step here was in netisr_dispatch. I had to go through a couple of minor functions and macros to figure out that the packet was not only enqueued in the packet queue, but schednetisr is called as well. schednetisr is a function I remember looking at a long time ago, and discarding at the time because it was too early to look at. I had thought it wasn’t called anymore, but it certainly is.

The Fix

The fix is to implement the swisched function in simulation correctly. This just has to call the network stack interrupt then allow the application to consume data. What happens in emulation is that the network stack software interrupt routine, swinet, is placed on the run queue. Once it has finished, the application waiting on a select or read will be woken up.

The new Cichlid visualisation, BSOD, was profiled and optimised yet more today. It is now reasonably optimal and doesn’t seem to slow down when most adverse networking things happen. “Slammer” still slows it down quite a bit, but it is still happy enough.

Every stack increased ticks every tick, so if you had two stacks, ticks would increase by 2 every tick. Not one. This would effect RTO’s and not much else probably.

Oh well, another bug fixed, at least I am getting something useful done…

All the time in emulation, when data is acked, the window is reduced by some amount or increased back out to its normal size. Often in simulation, the window is reduced by the amount of data that is acked, and then a window update is sent.

For some acks, what happens in simulation is just like emulation.

So this behaviour can and does happen in simulation, it is just that there are still a crapload of window update packets. I should ponder on what this means, I wasn’t really aware of this before.

I also fiddled with buffer sizes today. Changing the socket buffer size to be larger didn’t seem to effect results much. It certainly didn’t get rid of the window update duplicate acks. Interesting.

Maybe the number of packets / swi_net is correct? I dunno. I’m getting confused again. Maybe I should check exactly what I get in simulation and note it here. I’ve looked into some other simulations, and they also show this duplicate ack problem. The reason I haven’t seen it earlier in my studies is simply because I haven’t used tcptrace until (relatively) recently. It does seem to be correct, I have noticed the duplicate acks in log files since.

I must say that having tcptrace on my side is a good thing, it is awesome simulating something then analysing it in tcptrace. If only I wasn’t getting these strange results!

No evidence that kernel threads effect anything…

For some reason I am seeing only 1 packet per swi_net in emulation at the moment. Why is this? This was NOT the case before: I was getting 2, 3, etc. packets in some periods, 1 in others. I have hacked the kernel, sure, but only to add some debugging messages; and these are fairly infrequent now; less so than in my initial test where I figured that there was greater than 1 packet in a period. So what’s up? I have no idea… I don’t know why it would be any different.

Brendon and Sam’s Online Display (working title) now goes really well. Networking to get data was implemented today and works well enough. Is using an annoying library (HawkNL) that is not necessary (though it does make it platform independant). Anyway, it works really well now and is pretty cool. There was a stupid bug for aaaggeesss today that made flows of packets flicker on and off. It was to do with a bad index into a colour array that would sometimes make the flow have an alpha value of 0 (invisible). Anyway, it’s all fixed now.

I worked on getting the BuNg engine into a network visualisation product that works better than Cichlid today. Made a lot of progress, but there is still a bit more work to get done tomorrow. It is mostly there, I have packets flying around as they are supposed to but it is not quite connected up with any data yet!

Put more hacks into the FreeBSD 5.1 kernel to output useful information. I found out that printf always prints to the console as well as syslog. I changed my debug statements to log instead, which works well.

I think the amount of debugging information I was outputting was effecting results, though. I never got more than more packet in an interval. This perhaps needs a little more investigation.

As far as I can see, there is only one buffer; the socket buffer. No other buffers exist anywhere except when there is a read from userspace.

Question: does threading (of the kernel) play a part in our results? How do we find out? Should perhaps read more about the recent threading improvements in 5.x FreeBSD kernels.

Default routes work now. I’ve got rid of my silly mistakes and re-implemented a bit of code the way it should have been written in the first place. Unfortunately, this doesn’t change anything insofar as simulation results go.

I thought I had got rid of the error, but no! It’s still there. Need to figure out why, I really don’t know anymore. I’m pretty sure it shooouuulld work.