unison/doc/tutorial/tweaking.texi

@c ========================================================================
@c Begin document body here
@c ========================================================================

@c ========================================================================
@c PART:  Tweaking Ns-3
@c ========================================================================
@c The below chapters are under the major heading "Tweaking Ns-3"
@c This is similar to the Latex \part command
@c
@c ========================================================================
@c Tweaking Ns-3
@c ========================================================================
@node Tweaking Ns-3
@chapter Tweaking Ns-3

@menu
* Using the Logging Module::
* Using Command Line Arguments::
* Using the Tracing System::
@end menu

@c ========================================================================
@c Using the Logging Module
@c ========================================================================
@node Using the Logging Module
@section Using the Logging Module

@cindex logging
We have already taken a brief look at the ns-3 logging module while going
over the @code{first.cc} script.  We will now take a closer look and see what
kind of use-cases the logging subsystem was designed to cover.

@section Logging Overview
Many large systems support some kind of message logging facility, and ns-3
is not an exception.  In some cases, only error messages are logged to the 
``operator console'' (which is typically @code{stderr} in Unix-based systems).
In other systems, warning messages may be output as well as more detailed 
informational messages.  In some cases, logging facilities are used to output
debug messages which can quickly turn the output into a blur.

Ns-3 takes the view that all of these verbosity levels are useful and se
provides a selectable, multi-level approach to message logging.  Logging can
be disabled completely, enabled on a component-by-component basis, enabled
globally and has selectable verbosity levels.  The ns-3 log module provides
a straightforward, relatively easy to use way to get some kinds of information
out of your simulation.

You should understand that we do provide a general purpose mechanism --- 
tracing --- to get data out of your models which should be preferred for 
simulation output (see the tutorial section Using the Tracing System for
more details on our tracing system).  Logging should be preferred for 
debugging information, warnings, error messages, or any time you want to 
easily get a quick message out of your scripts or models.

There are currently seven levels of log messages of increasing verbosity
defined in the system.  

@itemize @bullet
@item NS_LOG_ERROR --- Log error messages;
@item NS_LOG_WARN --- Log warning messages;
@item NS_LOG_DEBUG --- Log relatively rare, ad-hoc debugging messages;
@item NS_LOG_INFO --- Log informational messages about program progress;
@item NS_LOG_FUNCTION --- Log a message describing each function called;
@item NS_LOG_LOGIC -- Log messages describing logical flow in a function;
@item NS_LOG_ALL --- Log everything.
@end itemize

We also provide an unconditional logging level that is always displayed,
irrespective of logging levels or component selection.

@itemize @bullet
NS_LOG_UNCOND -- Log the associated message unconditionally.
@end itemize

Each level can be requested singly or cumulatively; and can be set using a
shell environment variable (NS_LOG) or by logging system function call.  As
was seen earlier in the tutorial, the logging system has Doxygen documentation
so now would be a good time to peruse the Logging Module documentation.

Now that you have read the documentation in great detail, we can get some
interesting information out of the @code{first.cc} example script you dropped
in the scratch directory after the script walkthrough.

@section Enabling Logging Using the NS_LOG Environment Variable
@cindex NS_LOG
First, let's use the NS_LOG environment variable to turn on some more logging
in the @code{first.cc} script you have already built.  Go ahead and run the
script just as you did previously,

@verbatim
  ~/repos/ns-3-tutorial > ./waf --run scratch/first
  Entering directory `/home/craigdo/repos/ns-3-tutorial/build'
  Compilation finished successfully
  Sent 1024 bytes to 10.1.1.2
  Received 1024 bytes from 10.1.1.1
  Received 1024 bytes from 10.1.1.2
  ~/repos/ns-3-tutorial >
@end verbatim

The ``Sent'' and ``Received'' messages are actually logging messages from the
@code{UdpEchoClientApplication} and @code{UdpEchoServerApplication}.  We can
ask the client application, for example, to print more information by setting
its logging level via the NS_LOG environment variable.  I am going to assume
from here on that are using an sh-like shell that uses the``VARIABLE=value''
syntax.  If you are using a csh-like shell, then you will have to convert to
``setenv VARIABLE value'' syntax.

Let's ask the UDP echo client application to print a little more information.
Right now, it is responding to the following line of code in @code{first.cc},

@verbatim
  LogComponentEnable("UdpEchoClientApplication", LOG_LEVEL_INFO);
@end verbatim

This line of code enables the @code{LOG_LEVEL_INFO} level of logging.  When 
we pass a logging level flag, we are actually enabling the given level and
all lower levels.  In this case, we have enabled @code{NS_LOG_INFO},
@code{NS_LOG_DEBUG}, @code{NS_LOG_WARN} and @code{NS_LOG_ERROR}.  We can
increase the logging level and get more information without changing the
script and recompiling by setting the NS_LOG environment variable like this:

@verbatim
  ~/repos/ns-3-tutorial > export NS_LOG=UdpEchoClientApplication=level_all
@end verbatim

This sets the environment variable @code{NS_LOG} to the string,

@verbatim
  UdpEchoClientApplication=level_all
@end verbatim

The left hand side of the assignment is the name of the logging component we
want to set, and the right hand side is the flag we want to use.  In this case,
we are going to turn on all of the debugging levels for the application.  If
you run the script with NS_LOG set this way you should see the following 
output:

@verbatim
  ~/repos/ns-3-tutorial > ./waf --run scratch/first
  Entering directory `/home/craigdo/repos/ns-3-tutorial/build'
  Compilation finished successfully
  UdpEchoClientApplication:UdpEchoClient()
  UdpEchoClientApplication:StartApplication()
  UdpEchoClientApplication:ScheduleTransmit()
  UdpEchoClientApplication:Send()
  Sent 1024 bytes to 10.1.1.2
  Received 1024 bytes from 10.1.1.1
  UdpEchoClientApplication:HandleRead(0x62c640, 0x62cd70)
  Received 1024 bytes from 10.1.1.2
  UdpEchoClientApplication:StopApplication()
  UdpEchoClientApplication:DoDispose()
  UdpEchoClientApplication:~UdpEchoClient()
  ~/repos/ns-3-tutorial >
@end verbatim

The only additional debug information provided by the application is from
the NS_LOG_FUNCTION level.  You can now see a log of the function calls that
were made to the application.  If you look closely you will notice a single
colon between the string @code{UdpEchoClientApplication} and the method name
where you might have expected a C++ scope operator (@code{::}).  This is
intentional.  The name is not actually a class name, it is a logging component
name.  When there is a one-to-one correspondence between a source file and a
class, this will generally be the class name but you should understand that
it is not actually a class name, and there is a single colon to separate the
logging component name from the function name that is printed.

It turns out that in come cases, it can be hard to determine which method
actually generates a log message.  If you look in the text above, you may
wonder where the string ``@code{Received 1024 bytes from 10.1.1.1}'' comes
from.  You can resolve this by ORing the @code{prefix_func} level into the
@code{NS_LOG} environment variable.  Try doing the following,

@verbatim
  export 'NS_LOG=UdpEchoClientApplication=level_all|prefix_func'
@end verbatim

Note that the single quotes are required since the vertical bar is a Unix
pipe connector.

Now, if you run the script you will see that the logging system makes sure 
that every message from the given log component is prefixed with the component
name.

@verbatim
  ~/repos/ns-3-tutorial > ./waf --run scratch/first
  Entering directory `/home/craigdo/repos/ns-3-tutorial/build'
  Compilation finished successfully
  UdpEchoClientApplication:UdpEchoClient()
  UdpEchoClientApplication:StartApplication()
  UdpEchoClientApplication:ScheduleTransmit()
  UdpEchoClientApplication:Send()
  UdpEchoClientApplication:Send(): Sent 1024 bytes to 10.1.1.2
  Received 1024 bytes from 10.1.1.1
  UdpEchoClientApplication:HandleRead(0x62c710, 0x62ce40)
  UdpEchoClientApplication:HandleRead(): Received 1024 bytes from 10.1.1.2
  UdpEchoClientApplication:StopApplication()
  UdpEchoClientApplication:DoDispose()
  UdpEchoClientApplication:~UdpEchoClient()
  ~/repos/ns-3-tutorial >
@end verbatim

You can now see all of the messages coming from the UDP echo client application
are identified as such.  The remaining message must be coming from the UDP
echo server application.  We can enable that component by entering a colon
separated list of components in the NS_LOG environment variable.

@verbatim
  export 'NS_LOG=UdpEchoClientApplication=level_all|prefix_func:
                 UdpEchoServerApplication=level_all|prefix_func'
@end verbatim

Note that you will need to remove the newline after the @code{:} in the
example text above.

Now, if you run the script you will see all of the log messages from both the
echo client and server applications.  You may see that this can be very useful
in debugging problems.

@verbatim
  ~/repos/ns-3-tutorial > ./waf --run scratch/first
  Entering directory `/home/craigdo/repos/ns-3-tutorial/build'
  Compilation finished successfully
  UdpEchoServerApplication:UdpEchoServer()
  UdpEchoClientApplication:UdpEchoClient()
  UdpEchoServerApplication:StartApplication()
  UdpEchoClientApplication:StartApplication()
  UdpEchoClientApplication:ScheduleTransmit()
  UdpEchoClientApplication:Send()
  UdpEchoClientApplication:Send(): Sent 1024 bytes to 10.1.1.2
  UdpEchoServerApplication:HandleRead(): Received 1024 bytes from 10.1.1.1
  UdpEchoServerApplication:HandleRead(): Echoing packet
  UdpEchoClientApplication:HandleRead(0x62c760, 0x62ce90)
  UdpEchoClientApplication:HandleRead(): Received 1024 bytes from 10.1.1.2
  UdpEchoServerApplication:StopApplication()
  UdpEchoClientApplication:StopApplication()
  UdpEchoClientApplication:DoDispose()
  UdpEchoServerApplication:DoDispose()
  UdpEchoClientApplication:~UdpEchoClient()
  UdpEchoServerApplication:~UdpEchoServer()
  ~/repos/ns-3-tutorial >
@end verbatim

It is also sometimes useful to be able to see the simulation time at which a
log message is generated.  You can do this by ORing in the prefix_time bit.

@verbatim
  export 'NS_LOG=UdpEchoClientApplication=level_all|prefix_func|prefix_time:
                 UdpEchoServerApplication=level_all|prefix_func|prefix_time'
@end verbatim

If you run the script now, you should see the following output:

@verbatim
  ~/repos/ns-3-tutorial > ./waf --run scratch/first
  Entering directory `/home/craigdo/repos/ns-3-tutorial/build'
  Compilation finished successfully
  0ns UdpEchoServerApplication:UdpEchoServer()
  0ns UdpEchoClientApplication:UdpEchoClient()
  1000000000ns UdpEchoServerApplication:StartApplication()
  2000000000ns UdpEchoClientApplication:StartApplication()
  2000000000ns UdpEchoClientApplication:ScheduleTransmit()
  2000000000ns UdpEchoClientApplication:Send()
  2000000000ns UdpEchoClientApplication:Send(): Sent 1024 bytes to 10.1.1.2
  2003686400ns UdpEchoServerApplication:HandleRead(): Received 1024 bytes 
    from 10.1.1.1
  2003686400ns UdpEchoServerApplication:HandleRead(): Echoing packet
  2007372800ns UdpEchoClientApplication:HandleRead(0x62c8c0, 0x62d020)
  2007372800ns UdpEchoClientApplication:HandleRead(): Received 1024 bytes 
    from 10.1.1.2
  10000000000ns UdpEchoServerApplication:StopApplication()
  10000000000ns UdpEchoClientApplication:StopApplication()
  UdpEchoClientApplication:DoDispose()
  UdpEchoServerApplication:DoDispose()
  UdpEchoClientApplication:~UdpEchoClient()
  UdpEchoServerApplication:~UdpEchoServer()
  ~/repos/ns-3-tutorial >
@end verbatim

You can see that the constructor for the UdpEchoServer was called at a 
simulation time of 0 nanoseconds.  This is actually happening before the 
simulation starts.  The same for the UdpEchoClient constructor.

Recall that the @code{first.cc} script started the echo server application at
one second into the simulation.  You can now see that the 
@code{StartApplication} of the server is, in fact, called at one second (or
one billion nanoseconds).  You can also see that the echo client application
is started at a simulation time of two seconds as we requested in the script.

You can now follow the progress of the simulation from the 
@code{ScheduleTransmit} call in the client that calls @code{Send} to the 
@code{HandleRead} callback in the echo server application.  Note that the 
elapsed time as the packet is sent across the point-to-point link is 3.6864
milliseconds.  You see the echo server logging a message telling you that it
has echoed the packet and then, after a delay, you see the echo client receive
the echoed packet.

There is a lot that is happening under the covers in this simulation that you
are not seeing as well.  You can very easily follow the entire process by
turning on all of the logging components in the system.  Try setting the 
@code{NS_LOG} variable to the following,

@verbatim
  export 'NS_LOG=*=level_all|prefix_func|prefix_time'
@end verbatim

The asterisk is the logging component wildcard.  This will turn on all of the
logging in all of the components in the system.  I won't reproduce the output
here (as of this writing it produces 772 lines of output for the single packet
echo) but you can redirect this information into a file and look through it 
with your favorite editor if you like,

@verbatim
  ~/repos/ns-3-tutorial > ./waf --run scratch/first >& log.out
@end verbatim

I personally use this quite a bit when I am presented with a problem and I
have no idea where things are going wrong.  I can follow the progress of the
code quite easily without having to set breakpoints and step through code
in a debugger.  When I have a general idea about what is going wrong, I 
transition into a debugger for fine-grained examination of the problem.  This
output can be especially useful when your script does something completely 
unexpected.

@section Adding Logging to your Code
@cindex NS_LOG
You can add new logging to your simulations by making calls to the log 
component via several macros.  Let's do so in the @code{first.cc} script we
have in the @code{scratch} directory.

Recall that we have defined a logging component in that script.

@verbatim
  NS_LOG_COMPONENT_DEFINE ("FirstScriptExample");
@end verbatim

You now know that you can enable all of the logging for this component by
setting the @code{NS_LOG} environment variable to the various levels.  Let's
add some logging.  The macro to add an informational level log message is
@code{NS_LOG_INFO}.  Add one just before we start creating the nodes that 
tells you that the script is ``Creating Topology.''  This is done as in this
code snippet,

@verbatim
  NS_LOG_INFO ("Creating Topology");
@end verbatim

Now build the script using waf and clear the @code{NS_LOG} variable to turn 
off the torrent of logging we previously enabled:

@verbatim
  ~/repos/ns-3-tutorial > export NS_LOG=
@end verbatim

Now, if you run the script, you will not see your new message since its 
associated logging component has not been enabled.  In order to see your 
message you will have to enable the @code{FirstScriptExample} logging 
component with a level greater than or equal to @code{NS_LOG_INFO}.  If
you just want to see this particular level of logging, you can enable that
by,

@verbatim
  ~/repos/ns-3-tutorial > export NS_LOG=FirstScriptExample=info
@end verbatim

If you now run the script you will see your new logging message,

@verbatim
  ~/repos/ns-3-tutorial > ./waf --run scratch/first
  Entering directory `/home/craigdo/repos/ns-3-tutorial/build'
  Compilation finished successfully
  Creating Topology
  Sent 1024 bytes to 10.1.1.2
  Received 1024 bytes from 10.1.1.1
  Received 1024 bytes from 10.1.1.2
  ~/repos/ns-3-tutorial >
@end verbatim

As previously described, this does not also enable the lower levels of logging
but selects out the single infomational level.  

As we outlined in the Logging Overview, there are currently seven levels of 
logging verbosity you can use and you can also prefix your various log messages
with component name and simulation time.

@c ========================================================================
@c Using Command Line Arguments
@c ========================================================================
@node Using Command Line Arguments
@section Using Command Line Arguments

@section Overriding Default Attributes
@cindex command line arguments
Another way you can change the way that ns-3 scripts behave without editing
and building scripts is via @emph{command line arguments.}  We provide a 
mechanism to parse command line arguments and automatically set local and 
global variables based on those arguments.

The first step in using the command line argument system is to declare the
command line parser.  This is done quite simply (in your main program) as
in the following code,

@verbatim
    int
  main (int argc, char *argv[])
  {
    ...  

    CommandLine cmd;
    cmd.Parse (argc, argv);

    ...
  }
@end verbatim

This simple two line snippet is actually very useful by itself.  It opens the
door to the ns-3 global variable and attribute systems.  Go ahead and add that
two lines of code to the @code{first.cc} script at the start of @code{main}.
Go ahead and build the script and run it, but ask the script for help in the
following way,

@verbatim
  ~/repos/ns-3-tutorial > ./waf --run "scratch/first --PrintHelp"
@end verbatim

This will ask way to run the @code{scratch/first} script and pass the command
line argument @code{--PrintHelp} to the script.  The command line parser will
now see the @code{PrintHelp} argument and respond with,

@verbatim
  ~/repos/ns-3-tutorial > ./waf --run ``scratch/first --PrintHelp''
  Entering directory `/home/craigdo/repos/ns-3-tutorial/build'
  Compilation finished successfully
  --PrintHelp: Print this help message.
  --PrintGroups: Print the list of groups.
  --PrintTypeIds: Print all TypeIds.
  --PrintGroup=[group]: Print all TypeIds of group.
  --PrintAttributes=[typeid]: Print all attributes of typeid.
  --PrintGlobals: Print the list of globals.
  ~/repos/ns-3-tutorial >
@end verbatim

Let's focus on the @code{--PrintAttributes} option.  We have already hinted
at the attribute system while walking through the @code{first.cc} script.  We
looked at the following lines of code,

@verbatim
    PointToPointHelper pointToPoint;
    pointToPoint.SetDeviceParameter ("DataRate", StringValue ("5Mbps"));
    pointToPoint.SetChannelParameter ("Delay", StringValue ("2ms"));
@end verbatim

and mentioned that @code{DataRate} was actually an @code{Attribute} of the 
@code{PointToPointNetDevice}.  Let's use the command line argument parser
to take a look at the attributes of the PointToPointNetDevice.  The help
listing says that we should provide a typeid.  This corresponds to the class
name of the class to which the attributes belong.  In this case it will be
@code{ns3::PointToPointNetDevice}.  Let's go ahead and type in,

@verbatim
  ./waf --run "scratch/first --PrintAttributes=ns3::PointToPointNetDevice"
@end verbatim

The system will print out all of the attributes of this kind of net device.
Among the attributes you will see listed is,

@verbatim
  --ns3::PointToPointNetDevice::DataRate=[32768bps]:
    The default data rate fo r point to point links
@end verbatim

This is the default value that will be used when a PointToPointNetDevice is
created in the system.  We overrode this default with the parameter setting
in the PointToPointHelper above.  Let's use the default values for the 
PointToPoint devices and channels by deleting the SetDeviceParameter call and
the SetChannelParameter call from the @code{first.cc} we have in the scratch
directory.

Your script should now just declare the PointToPointHelper and not do any
sets as in the following example,

@verbatim
  ...

  NodeContainer nodes;
  nodes.Create (2);

  PointToPointHelper pointToPoint;

  NetDeviceContainer devices;
  devices = pointToPoint.Install (nodes);

  ...
@end verbatim

Go ahead and build the new script with waf.  Now let's go back and enable some
logging from the UDP echo server application and turn on the time prefix.

@verbatim
  export 'NS_LOG=UdpEchoServerApplication=level_all|prefix_time'
@end verbatim

If you run the script, you should now see the following output,

@verbatim
  ~/repos/ns-3-tutorial > ./waf --run scratch/first
  Entering directory `/home/craigdo/repos/ns-3-tutorial/build'
  Compilation finished successfully
  0ns UdpEchoServerApplication:UdpEchoServer()
  1000000000ns UdpEchoServerApplication:StartApplication()
  Sent 1024 bytes to 10.1.1.2
  2257324218ns Received 1024 bytes from 10.1.1.1
  2257324218ns Echoing packet
  Received 1024 bytes from 10.1.1.2
  10000000000ns UdpEchoServerApplication:StopApplication()
  UdpEchoServerApplication:DoDispose()
  UdpEchoServerApplication:~UdpEchoServer()
  ~/repos/ns-3-tutorial >
@end verbatim

Recall that the last time we looked at the simulation time at which the packet
was received by the echo server, it was at 2.0036864 seconds.  Now it is
receiving the packet at about 2.257 seconds.  This is because we just dropped
the data rate of the @code{PointToPointNetDevice} down to its default of 
32768 bits per second from five megabits per second.

If we were to provide a new @code{DataRate} using the command line, we could 
speed our simulation up again,

@verbatim
  ./waf --run "scratch/first --ns3::PointToPointNetDevice::DataRate=5Mbps"
@end verbatim

This will set the default value of the @code{DataRate} attribute back to 
five megabits per second.  To get the old behavior back, we will have to set
the speed-of-light delay of the channel.  We can ask the command line system
to print out the @code{Attributes} of the channel just like we did the net
device:

@verbatim
  ./waf --run "scratch/first --PrintAttributes=ns3::PointToPointChannel"
@end verbatim

and we discover the @code{Delay} attribute.

@verbatim
  --ns3::PointToPointChannel::Delay=[0ns]:
    Transmission delay through the channel
@end verbatim

We can then set both of these default values through the command line system,

@verbatim
  ./waf --run "scratch/first
    --ns3::PointToPointNetDevice::DataRate=5Mbps
    --ns3::PointToPointChannel::Delay=2ms"
@end verbatim

In which case we recover the timing we had when we explicitly set the
@code{DataRate} and @code{Delay} in the script:

@verbatim
  Compilation finished successfully
  0ns UdpEchoServerApplication:UdpEchoServer()
  1000000000ns UdpEchoServerApplication:StartApplication()
  Sent 1024 bytes to 10.1.1.2
  2003686400ns Received 1024 bytes from 10.1.1.1
  2003686400ns Echoing packet
  Received 1024 bytes from 10.1.1.2
  10000000000ns UdpEchoServerApplication:StopApplication()
  UdpEchoServerApplication:DoDispose()
  UdpEchoServerApplication:~UdpEchoServer()
@end verbatim

Note that the packet is received by the server at 2.0036864 seconds.  We 
could actually set any of the attributes used in the script in this way.  In
particular we could set the @code{UdpEchoClient} attribute @code{MaxPackets} 
to some other value than one.

How would you go about that?  Give it a try.  Remember you have to comment 
out the place we override the default attribute in the script.  Then you 
have to rebuild the script using the default.  You will also have to find the
syntax for actually setting the new default atribute value using the command
line help facility.  Once you have this figured out you should be able to
control the number of packets echoed from the command line.  Since we're nice
folks, we'll tell you that your command line should end up looking something
like,

@verbatim
  ./waf --run "scratch/first 
    --ns3::PointToPointNetDevice::DataRate=5Mbps 
    --ns3::PointToPointChannel::Delay=2ms 
    --ns3::UdpEchoClient::MaxPackets=2"
@end verbatim

@subsection Hooking Your Own Values
You can also add your own hooks to the command line system.  This is done
quite simply by using the @code{AddValue} method to the command line parser.

Let's use this facility to specify the number of packets to echo in a 
completely different way.  Let's add a local variable called @code{nPackets}
to the main function.  We'll initialize it to one to match our previous 
default behavior.  To allow the command line parser to change this value, we
need to hook the value into the parser.  Do this by adding a call to 
@code{AddValue}.  Go ahead and change the @code{scratch/first.cc} script to
start with the following code,

@verbatim
    int
  main (int argc, char *argv[])
  {
    uint32_t nPackets = 1;

    CommandLine cmd;
    cmd.AddValue("nPackets", "Number of packets to echo", nPackets);
    cmd.Parse (argc, argv);

    ...
@end verbatim

Scroll down to the point in the script where we set the @code{MaxPackets}
attribute and change it so that it is set to the variable @code{nPackets}
instead of the constant @code{1} as below.

@verbatim
  echoClient.SetAppAttribute ("MaxPackets", UintegerValue (nPackets));
@end verbatim

Now if you run the script and provide the @code{--PrintHelp} argument, you 
should see your new @code{User Argument} listed in the help.

@verbatim
  ~/repos/ns-3-tutorial > ./waf --run "scratch/first --PrintHelp"
  Entering directory `/home/craigdo/repos/ns-3-tutorial/build'
  Compilation finished successfully
  --PrintHelp: Print this help message.
  --PrintGroups: Print the list of groups.
  --PrintTypeIds: Print all TypeIds.
  --PrintGroup=[group]: Print all TypeIds of group.
  --PrintAttributes=[typeid]: Print all attributes of typeid.
  --PrintGlobals: Print the list of globals.
  User Arguments:
      --nPackets: Number of packets to echo
  ~/repos/ns-3-tutorial >
@end verbatim

If you want to specify the number of packets to echo, you can now do so by
setting the @code{nPackets} argument,

@verbatim
  ~/repos/ns-3-tutorial > ./waf --run "scratch/first --nPackets=2"
  Entering directory `/home/craigdo/repos/ns-3-tutorial/build'
  Compilation finished successfully
  Sent 1024 bytes to 10.1.1.2
  Received 1024 bytes from 10.1.1.1
  Received 1024 bytes from 10.1.1.2
  Sent 1024 bytes to 10.1.1.2
  Received 1024 bytes from 10.1.1.1
  Received 1024 bytes from 10.1.1.2
  ~/repos/ns-3-tutorial >
@end verbatim

If you are an ns-3 user, you can use the command line argument system to 
control global values and attributes.  If you are a model author, you can
add new attributes to your Objects and they will automatically be available
for setting by your users through the command line system.  If you are a
script author, you can add new variables to your scripts and hook them into
the command line system quite painlessly.

@c ========================================================================
@c Using the Tracing System
@c ========================================================================
@node Using the Tracing System
@section Using the Tracing System

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 basic goals of the @command{ns-3} tracing system are:

@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 must 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 built on the concepts of independent 
tracing sources and tracing sinks and a uniform mechanism for connecting
sources to sinks.  Trace sources are entities that can signal events that
happen in a simulation and provide access to interesting underlying data. 
For example, a trace source could indicate when a packet is received by a net
device and provide access to the packet for interested trace sinks.

Trace sources are not useful by themselves, they must be ``connected'' to
other pieces of code that actually do something useful with the information 
provided by the sink.  Trace sinks are consumers of the events and data
provided by the trace sources.  For example, one could create a trace sink t
hat would (when connected to the trace source of the previous example) print 
out interesting parts of the received packet.

The rationale for this explicit division is to allow users to attach new
types of sinks to existing tracing sources, without requiring editing and 
recompilation of the the core of the simulator.  Thus, in the example above, 
a user could define a new tracing sink in her script and attach it to an 
existing tracing source defined in the simulation core editing only the 
user script.

What remains to be defined is a way for users to find these hooks (tracing 
sources) and attach sinks to them.  A tracing namespace is defined for
this purpose.  

In this tutorial, we will walk through some pre-defined sources and sinks and
show how they may be customized with little user effort.  See the ns-3 manual
or how-to sections for information on advanced tracing configuration including
extending the tracing namespace and creating new tracing sources.

@cindex tracing
@cindex ASCII tracing
@subsection ASCII Tracing
Ns-3 provides an ASCII trace helper that is a wrapper around low-level 
tracing system.  This helper lets you configure some useful and easily
understood packet traces easily.  The output of a trace of a simulation run 
is an ASCII file --- thus the name.  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 and add some ASCII tracing output to our 
@code{first.cc} script.  The first thing you need to do is to add the 
following code to the script just before the call to @code{Simulator::Run ()}.

@verbatim
  std::ofstream ascii;
  ascii.open ("first.tr");
  PointToPointHelper::EnableAsciiAll (ascii);
@end verbatim

The first two lines are just vanilla C++ code to open a stream that will be
written to a file named ``first.tr.''  See your favorite C++ tutorial if you
are unfamiliar with this code.  The last line of code in the snippet above
tells ns-3 that you want to enable ASCII tracing on all point-to-point devices
in your simulation; and you want the (provided) trace sinks to write out
information about packet movement in ASCII format to the stream provided.
For those familiar with @command{ns-2}, the traced events are equivalent
to the popular trace points that log "+", "-", "d", and "r" events.

Since we have used a @code{std::ofstream} object, we also need to include the
appropriate header.  Add the following line to the script (I typically add it
above the ns-3 includes):

@verbatim
  #include <fstream>
@end verbatim

You can now build the script and run it from the command line:

@verbatim
  ./waf --run scratch/first
@end verbatim

@cindex first.tr
Just as you have seen previously, you may see some messages from Waf and then
the ``Compilation finished successfully'' message.  The following messages are
from the running program.  When it ran, the program will have created a file
named @code{first.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 by default.  If you want to control where the traces are saved
you can use the @code{--cwd} option of Waf to specify this.  We have not done
so, thus we need to change into the top level directory of our repo and take a
look at the file @code{first.tr} in your favorite editor.

@subsubsection Parsing Ascii Traces
@cindex parsing ascii traces
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}.  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 ascii trace enqueue operation
@cindex ascii trace dequeue operation
@cindex ascii trace drop operation
@cindex ascii trace receive operation
@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;
@item @code{r}: A packet was received by the net device.
@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 /NodeList/0/DeviceList/0/$ns3::PointToPointNetDevice/TxQueue/Enqueue 
  03 ns3::PppHeader (
  04   Point-to-Point Protocol: IP (0x0021)) 
  05   ns3::Ipv4Header (
  06     tos 0x0 ttl 64 id 0 offset 0 flags [none] 
  07     length: 1052 10.1.1.1 > 10.1.1.2)
  08     ns3::UdpHeader (
  09       length: 1032 49153 > 9) 
  10       Payload (size=1024)
@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 again
see confirmation that this is, indeed, happening.

@cindex node number
@cindex net device number
@cindex smart pointer
The next line of the example listing (reference 02) tell us the trace source
that originated this even expressed in the tracing namespace.  You can think
of the tracing womewhat like you would a filesystem namespace.  The root of 
the namespace is the @code{NodeList}.  This corresponds to a container in the 
ns-3 code that contains all of the nodes that were created in the system.
Just as a filesystem has may have directories under the root, we have node 
numbers in the @code{NodeList}.  The string @code{/NodeList/0} therefore 
refers to the zeroth node in the @code{NodeList} which we can think of as
``node 0.''  In each node there is a list of devices that have been installed.
This list appears next.  You can see that this trace event comes from 
@code{DeviceList/0} which is the zeroth device installed in the node. 

The next string, @code{$ns3::PointToPointNetDevice} tells you what kind of 
device it is that is in the zeroth position of the device list for node zero.
This should by now be completely expected.  Recall that the operation @code{+}
found at reference 00 means an enqueue operation on the transmit queue of the
device.  This is reflected in the final segments of the ``trace path'' which
are @code{TxQueue/Enqueue}.

The remaining lines in the trace should be fairly intuitive.  References 03-04
indicate that the packet is encapulated in the point-to-point protocol.  
References 05-07 show that the packet has an IP version four header and has
originated from IP address 10.1.1.1 and is destined for 10.1.1.2.  References
08-09 show that this is a UDP packet from and finally reference 10 shows that
the payload is the expected 1024 bytes.

The next line in the trace file shows the same packet being dequeued from the
transmit queue on the same node. 

The Third line in the trace file shows the packet being received by the net
device on the node with the echo server. I have reproduced that event below.

@verbatim
  00 r 
  01 2.25732 
  02 /NodeList/1/DeviceList/0/$ns3::PointToPointNetDevice/Rx 
  03 ns3::PppHeader (
  04   Point-to-Point Protocol: IP (0x0021)) 
  05   ns3::Ipv4Header (
  06     tos 0x0 ttl 64 id 0 offset 0 flags [none] 
  07     length: 1052 10.1.1.1 > 10.1.1.2)
  08     ns3::UdpHeader (
  09       length: 1032 49153 > 9) 
  10       Payload (size=1024)
@end verbatim

Notice that the trace operation is now @code{r} and the simulation time has
increased to 2.25732 seconds.  If you have been following the tutorial steps
closely this means that you have left the @code{DataRate} of the net devices
set to their default value of 32768 bps with a channel @code{Delay} of two
milliseconds.  This time should be familiar as you have seen it before in a
previous section.

The trace source namespace entry (reference 02) has changed to reflect that
this event is coming from node 1 (@code{/NodeList/1}) and the packet reception
trace source (@code{/Rx}).  It should be quite easy for you to follow the 
progress of the packet through the topology by looking at the rest of the 
traces in the file.

@subsection PCAP Trace Helper
@cindex pcap
@cindex Wireshark
The @command{ns-3} @emph{pcap trace helper} 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.
We encourage users to exploit the many tools available for analyzing pcap
traces.  In this tutorial, we show how tcpdump and Wireshark can be used.

@cindex pcap tracing
The code used to enable pcap tracing is a one-liner.  

@verbatim
  PointToPointHelper::EnablePcapAll ("first");
@end verbatim

Go ahead and insert this line of code after the ASCII tracing code we just 
added to @code{scratch/first.cc}.  Notice that we only gave the pcap trace
helper call the string, ``first,'' and not ``first.pcap'' or something 
similar.  This is because the parameter is a prefix, not a complete file name.
The pcap trace helper will actually create a trace file for every device in 
the simulation that generates a traced event.  The file names will be built
using the prefix, the node number, the device number and a ``.pcap'' suffix.

In our example script, we will see a files named ``first-0-0.pcap'' and
``first.1-0.pcap'' which are the pcap traces for node 0, device 0 and node 1,
device 1, respectively.

You can now run the script as you have been:

@verbatim
  ./waf --run scratch/first
@end verbatim

If you look at the top level directory of your distribution, you should now
see three log files:  @code{first.tr} is the ASCII trace file we have 
previously examined.  @code{first-0-0.pcap} and @code{first-1-0.pcap}
are the new pcap files we just generated.  

@subsubsection Reading output with tcpdump
@cindex tcpdump
The easiest thing to do at this point will be to use @code{tcpdump} to look
at the @code{pcap} files.  Output from dumping both files is shown below:

@verbatim
  ~/repos/ns-3-tutorial > /usr/sbin/tcpdump -r first-0-0.pcap -nn -tt
  reading from file first-0-0.pcap, link-type PPP (PPP)
  2.000000 IP 10.1.1.1.49153 > 10.1.1.2.9: UDP, length 1024
  2.514648 IP 10.1.1.2.9 > 10.1.1.1.49153: UDP, length 1024
  ~/repos/ns-3-tutorial > /usr/sbin/tcpdump -r first-1-0.pcap -nn -tt
  reading from file first-1-0.pcap, link-type PPP (PPP)
  2.257324 IP 10.1.1.1.49153 > 10.1.1.2.9: UDP, length 1024
  2.257324 IP 10.1.1.2.9 > 10.1.1.1.49153: UDP, length 1024
  ~/repos/ns-3-tutorial >
@end verbatim

You can see in the dump of ``first-0.0.pcap'' (the client device) that the 
echo packet is sent at 2 seconds into the simulation.  If you look at the
second dump (of ``first-1-0.pcap'') you can see that packet being received
at 2.257324 seconds.  You see the packet being echoed at 2.257324 seconds
in the second dump, and finally, you see the packet being received back at 
the client in the first dump at 2.514648 seconds.

@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/}.

Wireshark is a graphical user interface which can be used for displaying these
trace files.  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}.