@c ========================================================================
@c Simulation Output
@c ========================================================================
@node Simulation Output
@chapter Simulation Output
At this point, you should be able to execute any of the built-in
programs distributed with @command{ns-3}. Next, we will look at
how to generate and tailor the simulation output, before turning
to how to modify simulation scripts to do different things.
@node Tracing Basics
@section Tracing Basics
The whole point of simulation is to generate output for further
study, and the @command{ns-3} tracing system is a primary
mechanism for this.
Since @command{ns-3} is a C++ program, standard facilities for
generating output from C++ programs apply:
@verbatim
#include <iostream>
...
int main ()
{
...
std::cout << "The value of x is " << x << std::endl;
...
}
@end verbatim
The goal of the @command{ns-3} tracing system is to
provide a structured way to configure the simulator to output results
in standard or modifiable formats.
@itemize @bullet
@item For basic tasks, the tracing system should allow the user to
generate standard tracing for popular tracing sources, and to customize
which objects generate the tracing.
@item Intermediate users will be able to extend the tracing system to
modify the output format generated, or to insert new tracing sources,
without modifying the core of the simulator.
@item Advanced users can modify the simulator core to add new
tracing sources and sinks.
@end itemize
The @command{ns-3} tracing system is fundamentally built on the
concept of separating tracing sources from sinks.
@enumerate
@item Trace sources (e.g., provide access to every packet received)
@item Trace sinks (e.g., print out the packet)
@item A mechanism to tie together sources and sinks
@end enumerate
The rationale for this division is to allow users to attach new
types of sinks to existing tracing sources, without requiring
users to edit and recompile the core of the simulator.
Thus, in the example above, a user could write a new tracing sink
and attach it to an existing tracing source. What remains to
be defined is a way for users to find these hooks (tracing sources)
and attach sinks to them. A new tracing namespace is defined for
this purpose.
We will first walk through how some pre-defined sources and sinks
are provided and may be customized with little user effort. We
return later in this chapter to advanced tracing configuration including
extending the tracing namespace and creating new tracing sources.
@subsection ASCII tracing
@cindex ASCII
For Internet nodes, the ASCII trace wrapper is a wrapper around
the @command{ns-3} low-level
tracing system that lets you get access to underlying trace events easily.
The output of a trace of a simulation run is an ASCII file --- thus the name.
In the spirit of keeping things simple, you won't be able to control or
configure the output at this stage.
For those familiar with @command{ns-2} output, this type of trace is
analogous to the @command{out.tr} generated by many scripts.
@cindex tracing packets
Let's just jump right in. As usual, we need to include the definitions
related to using ASCII tracing (don't edit any files quite yet):
@verbatim
#include "ns3/ascii-trace.h"
@end verbatim
We then need to add the code to the script to actually enable the ASCII tracing
code. The following code must be inserted before the call to
@code{Simulator::Run ();}:
@verbatim
AsciiTrace asciitrace ("tutorial.tr");
asciitrace.TraceAllQueues ();
asciitrace.TraceAllNetDeviceRx ();
@end verbatim
The first line declares an object of type @code{AsciiTrace} named
@code{asciitrace} and passes a string parameter to its constructor. This
parameter is a file name to which all of the trace information will be written.
The second line, @code{asciitrace.TraceAllQueues ();} asks the trace object to
arrange that all queue operations (enqueue, dequeue, drop) on the queues
in all of the nodes of the system be traced. On the receive side,
@code{asciitrace.TraceAlllNetDeviceRx ()} traces packets received by
a NetDevice. For those familiar with @command{ns-2}, these are equivalent
to the popular trace points that log "+", "-", "d", and "r" events.
Try running the following program from the command line:
@verbatim
./waf --run tutorial-csma-echo-ascii-trace
@end verbatim
@cindex tutorial.tr
Just as you have seen previously, you will see some messages from @emph{Waf}
and then the ``Compilation finished successfully'' message. The
next message, @code{UDP Echo Simulation} is from the running program. When
it ran, the program will have created a file named @code{tutorial.tr}.
Because of the way that Waf works, the file is not created in the local
directory, it is created at the top-level directory of the repository. So,
change into the top level directory and take a look at the file
@code{tutorial.tr} in your favorite editor.
@subsubsection Parsing Ascii Traces
@cindex parsing ascii traces
This section parses in detail the structure of the ascii tracing
output. If you find this output format self explanatory (it
resembles tcpdump output), you may skip to the next
section on pcap tracing.
@cindex trace event
There's a lot of information there in a pretty dense form, but the first thing
to notice is that there are a number of distinct lines in this file. It may
be difficult to see this clearly unless you widen your windows considerably.
Each line in the file corresponds to a @emph{trace event}. A trace event
happens whenever specific conditions happen in the simulation. In this case
we are tracing events on the @emph{device queue} present in every net device
on every node in the simulation. The device queue is a queue through which
every packet destined for a channel must pass --- it is the device
@emph{transmit} queue. Note that each line in the trace file begins with a
lone character (has a space after it). This character will have the following
meaning:
@cindex enqueue
@cindex dequeue
@cindex drop
@itemize @bullet
@item @code{+}: An enqueue operation occurred on the device queue;
@item @code{-}: A dequeue operation occurred on the device queue;
@item @code{d}: A packet was dropped, typically because the queue was full.
@end itemize
Let's take a more detailed view of the first line. I'll break it down into
sections (indented for clarity) with a two digit reference number on the
left side:
@verbatim
00 +
01 2
02 nodeid=0
03 device=0
04 queue-enqueue
05 pkt-uid=9
06 ETHERNET
07 length/type=0x806,
08 source=08:00:2e:00:00:00,
09 destination=ff:ff:ff:ff:ff:ff
10 ARP(request
11 source mac: 08:00:2e:00:00:00
12 source ipv4: 10.1.1.1
13 dest ipv4: 10.1.1.2)
14 ETHERNET fcs=0
@end verbatim
@cindex trace event
@cindex simulation time
The first line of this expanded trace event (reference number 00) is the
queue operation. We have a @code{+} character, so this corresponds to an
@emph{enqueue} operation. The second line (reference 01) is the simulation
time expressed in seconds. You may recall that we asked the
@code{UdpEchoClient} to start sending packets at two seconds. Here we see
confirmation that this is, indeed, happening.
@cindex node number
@cindex net device number
@cindex smart pointer
The next lines of the example listing (references 02 and 03) tell us that
this trace event originated in a given node and net device. Each time a node
is created it is given an identifying number that monotonically increases from
zero. Therefore, @code{nodeid=0} means that the node in which the given trace
event originated is the first node we created. In the case of our script,
this first node is is the node pointed to by the smart pointer @code{n0}. Not
too surprisingly, this is also the node to which we attached the
@code{UdpEchoClient}. The device number is local to each node, and so the
device given by @code{device=0} is the first net device that we added to the
node in question. In our simulation, this corresponds to the
@code{CsmaNetDevice} we added to node zero (@code{n0}).
@cindex uid
@cindex unique ID
@cindex packet
The next line (reference 04) is a more readable form of the operation code
seen in the first line --- i.e., the character @code{+} means
@code{queue-enqueue}. Reference number 05 indicates that the @emph{unique id}
of the packet being enqueued is @code{9}. The fact that the first packet we
see has a unique ID of 9 should indicates to you that other things have
happened in the protocol stack before we got to this point. This will become
clear momentarily.
@cindex Ethernet
@cindex MAC address
Reference items 06 and 14 indicate that this is an Ethernet packet with
a zero (not computed) checksum (note the indentation to make parsing this
trace event a little easier). Reference 08 and 09 are the source and
destination addresses of this packet. The packet is from the MAC address we
assigned to the node zero net device in the script, and is destined for the
broadcast address --- this is a broadcast packet.
@cindex Address Resolution Protocol
@cindex ARP
@cindex ARP|request
Reference items 10 through 13 make clear what is happening. This is an ARP
(Address Resolution Protocol) request for the MAC address of the node on
which the @code{UdpEchoServer} resides. The protocol stack can't send a UDP
packet to be echoed until it knows (resolves) the MAC address; and this trace
event corresponds to an ARP request being queued for transmission to the local
network. The next line in the trace file (partially expanded),
@verbatim
00 -
01 2
02 nodeid=0
03 device=0
04 queue-dequeue
05 pkt-uid=9
...
@end verbatim
shows the (same) ARP request packet being dequeued from the device queue by
the net device and (implicitly) being sent down the channel to the broadcast
MAC address. We are not tracing net device reception events so we don't
actually see all of the net devices receiving the broadcast packet. We do,
however see the following in the third line of the trace file:
@verbatim
00 +
01 2.00207
02 nodeid=1
03 device=0
04 queue-enqueue
05 pkt-uid=10
06 ETHERNET
07 length/type=0x806,
08 source=08:00:2e:00:00:01,
09 destination=08:00:2e:00:00:00,
10 ARP(reply
11 source mac: 08:00:2e:00:00:01
12 source ipv4: 10.1.1.2
13 dest mac: 08:00:2e:00:00:00
14 dest ipv4: 10.1.1.1)
15 ETHERNET fcs=0
@end verbatim
@cindex simulation time
@cindex ARP|response
Notice that this is a queue-enqueue operation (references 00 and 04) happening
on node one (reference 02) at simulation time 2.00207 seconds (reference 01).
Looking at the packet payload (references 10-14) we see that this is an ARP
reply to the request sent by node one. Note that the simulation time
(reference 01) is now 2.00207 seconds. This is direct result of the data rate
(5 mb/s) and latency (2 ms) parameters that we passed to the
@code{CsmaChannel} when we created it. Clearly the ARP request packet was
sent over the channel and received approximately 2 ms later by node one. A
corresponding ARP response packet was created and enqueued on node one's net
device. It is this enqueue trace event that has being logged.
@cindex queue
@cindex queue|transmit
@cindex echo
Given the current state of affairs, the next thing you may expect to see is
this ARP request being received by node zero, but remember we are only looking
at trace events on the device @emph{transmit} queue. The reception of the ARP
response by node zero will not directly trigger any trace event in this case,
but it will enable the protocol stack to continue what it was originally doing
(trying to send an echo packet). Thus, the next line we see in the trace file
(@code{tutorial.tr}) is the first UDP echo packet being sent to the net device.
@verbatim
00 +
01 2.00415
02 nodeid=0
03 device=0
04 queue-enqueue
05 pkt-uid=7
06 ETHERNET
07 length/type=0x800,
08 source=08:00:2e:00:00:00,
09 destination=08:00:2e:00:00:01
10 IPV4(
11 tos 0x0
12 ttl 64
13 id 0
14 offset 0
15 flags [none]
16 length: 1052) 10.1.1.1 > 10.1.1.2
17 UDP(length: 1032)
18 49153 > 7
19 DATA (length 1024)
20 ETHERNET fcs=0
@end verbatim
@cindex simulation time
@cindex echo
@cindex ARP
@cindex ARP|request
@cindex ARP|response
@cindex IP
@cindex Ipv4
I won't go into too much detail about this packet, but I will point out a
few key items in the trace. First, the packet was enqueued at simulation time
of 2.00415 seconds. This time reflects the fact that the echo client
application started at 2. seconds and there were two ARP packets transmitted
across the network (two milliseconds + data transmission time each way). The
packet unique identifier (reference 05) is 7. Notice that this is a lower
number than the ARP request packet, which had a unique ID of 9. This tells
us that the UDP packet was actually created before the ARP request packet ---
which makes perfect sense since it was the attempt to send packet 7 that
triggered sending the ARP request packet 9. Note that this an Ethernet
packet (reference 06) like all other packets in this simulation, however this
particular packet carries an IPV4 payload and therefore has an IP version 4
header (indicated by references 10-16). This Ipv4 in turn contains a UDP
header (references 17, 18) and finally 1024 bytes of data (reference 20).
Clearly, this is the UDP echo packet emitted by the
@code{UdpEchoClient Application}.
The next trace event is an ARP request from node one. We can infer that node
one has received the UDP echo packet and the @code{UdpEchoServer Application}
on that node has turned the packet around. Just as node zero needed to ARP
for the MAC address of node one, now node one must ARP for the MAC address of
node zero. We see the ARP request enqueued on the transmit queue of node one;
then we see the ARP request dequeued from the transmit queue of node one (and
implicitly transmitted to node zero). Then we see an ARP response enqueued
on the transmit queue of node zero; and finally the ARP response dequeued (and
implicitly transmitted back to node one).
This exchange is summarized in the following trace event excerpts,
@verbatim
+ 2.00786 nodeid=1 ... ARP(request ...
- 2.00786 nodeid=1 ... ARP(request ...
+ 2.00994 nodeid=0 ... ARP(reply ...
- 2.00994 nodeid=0 ... ARP(reply ...
@end verbatim
The final two trace events in the @code{tutorial.tr} file correspond to the
echoed packet being enqueued for transmission on the net device for node one,
and that packet being dequeued (and implicitly transmitted back to node zero).
@cindex AsciiTrace!TraceAllNetDeviceRx
@cindex ARP!request
If you look at the trace file (@code{tutorial.tr}) you will also see some
entries with an @code{r} event, indicating a
@emph{receive} trace event. Recall that the first packet sent on the network
was a broadcast ARP request. We should then see all four nodes receive a
copy of this request. This is the case, as the first four receive trace
events are,
@verbatim
r 2.00207 nodeid=0 device=0 dev-rx pkt-uid=9 ARP(request ...
r 2.00207 nodeid=1 device=0 dev-rx pkt-uid=9 ARP(request ...
r 2.00207 nodeid=2 device=0 dev-rx pkt-uid=9 ARP(request ...
r 2.00207 nodeid=3 device=0 dev-rx pkt-uid=9 ARP(request ...
@end verbatim
@cindex unique ID
You can see that a copy of the broadcast packet with unique ID 9 was received
by the net devices on nodes 0, 1, 2 and 3. We leave it up to you to parse the
rest of the trace file and understand the remaining reception events.
@subsection PCAP Trace Wrapper
@cindex pcap
@cindex Wireshark
The @command{ns-3} @emph{pcap trace wrapper} is used to create trace files in
@code{.pcap} format. The acronym pcap (usually written in lower case) stands
for @emph{p}acket @emph{cap}ture, and is actually an API that includes the
definition of a @code{.pcap} file format. The most popular program that can
read and display this format is Wireshark (formerly called Ethereal).
However, there are many traffic trace analyzers that use this packet
format, including X, Y, and Z. We encourage users to exploit the
many tools available for analyzing pcap traces; below, we show how
tcpdump and Wireshark can be used..
@cindex tutorial-csma-echo-ascii-trace.cc
@cindex tutorial-csma-echo-pcap-trace.cc
The code used to enable pcap tracing is similar to that for ASCII tracing.
We have provided another file, @code{tutorial-csma-echo-pcap-trace.cc} that
uses the pcap trace wrapper. We have added the code to include the pcap
trace wrapper definitions:
@verbatim
#include "ns3/pcap-trace.h"
@end verbatim
And then added the following code below the AsciiTrace methods:
@cindex PcapTrace
@cindex PcapTrace!TraceAllIp
@verbatim
PcapTrace pcaptrace ("tutorial.pcap");
pcaptrace.TraceAllIp ();
@end verbatim
The first line of the code immediately above declares an object of type
@code{PcapTrace} named @code{pcaptrace} and passes a string parameter to its
constructor. This object is used to hide the details of the actual tracing
subsystem. The parameter is a base file name from which the actual trace file
names will be built. The second line of code tells the @code{PcamTrace}
object to trace all IP activity in all of the nodes present in the simulation.
@cindex interface index
Trace files are not created until trace activity is detected. Each file name
is composed of the base file name, followed by a @code{'-'}, a node id followed
by a @code{'-}', and an IP interface index. You will soon see a file named
@code{tutorial.pcap-0-1}, for example. This will be the trace file generated
as events are detected on node zero, interface index one. N.B. Interface
indices are different that net device indices --- interface index zero
corresponds to the loopback interface and interface index one corresponds to
the first net device you added to a node.
You may run the new program just like all of the others so far:
@cindex Waf
@verbatim
./waf --run tutorial-csma-echo-pcap-trace
@end verbatim
If you look at the top level directory of your distribution, you should now
see three log files: @code{tutorial.tr} is the ASCII trace file we have
previously examined. @code{tutorial.pcap-0-1} and @code{tutorial.pcap-1-1}
are the new pcap files we just generated. There will not be files
corresponding to nodes two and three since we have not sent any IP packets to
those nodes.
@subsubsection Reading output with tcpdump
@cindex tcpdump
@subsubsection Reading output with Wireshark
@cindex Wireshark
If you are unfamiliar with Wireshark, there is a web site available from which
you can download programs and documentation: @uref{http://www.wireshark.org/}.
If you have Wireshark available, you can open each of the trace files and
display the contents as if you had captured the packets using a
@emph{packet sniffer}. Note that only IP packets are traced using this
wrapper, so you will not see the ARP exchanges that were logged when using
the ASCII trace wrapper. You are encouraged to take a look at the contents
of these pcap files using your favorite pcap software (or Wireshark).
@node Advanced Tracing
@section Advanced Tracing