@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 spririt 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 surpsisingly, 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 tranmit 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 defintions:

@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 unfamilar 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