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 @command{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.

@node Logging Overview
@subsection Logging Overview
Many large systems support some kind of message logging facility, and 
@command{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.

@command{Ns-3} takes the view that all of these verbosity levels are useful 
and we provide a selectable, multi-level approach to message logging.  Logging
can be disabled completely, enabled on a component-by-component basis, or
enabled globally; and it provides selectable verbosity levels.  The 
@command{ns-3} log module provides a straightforward, relatively easy to use
way to get useful 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 within 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
@item NS_LOG_UNCOND -- Log the associated message unconditionally.
@end itemize

Each level can be requested singly or cumulatively; and logging can be set 
up 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 and now would be a good time to peruse the Logging Module 
documentation if you have not done so.

Now that you have read the documentation in great detail, let's use some of
that knowledge to get some interesting information out of the 
@code{scratch/myfirst.cc} example script you have already built.

@node Enabling Logging
@subsection Enabling Logging
@cindex NS_LOG
Let's use the NS_LOG environment variable to turn on some more logging, but
to get our bearings, go ahead and run the script just as you did previously,

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

You should see the now familiar output of the first @command{ns-3} example
program

@verbatim
  Entering directory `repos/ns-3-dev/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
@end verbatim

It turns out that the ``Sent'' and ``Received'' messages you see above 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 my examples to the ``setenv VARIABLE value'' syntax 
required by those shells.

Right now, the UDP echo client application is responding to the following line
of code in @code{scratch/myfirst.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
  export NS_LOG=UdpEchoClientApplication=level_all
@end verbatim

This sets the shell 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, the @command{ns-3} logging 
system will pick up the change and you should see the following output:

@verbatim
  Entering directory `repos/ns-3-allinone/ns-3-dev/build'
  Build finished successfully (00:00:00)
  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(0x638180, 0x6389b0)
  Received 1024 bytes from 10.1.1.2
  UdpEchoClientApplication:StopApplication()
  UdpEchoClientApplication:DoDispose()
  UdpEchoClientApplication:~UdpEchoClient()
@end verbatim

The additional debug information provided by the application is from
the NS_LOG_FUNCTION level.  This shows every time a function in the application
is called during script execution.  Note that there are no requirements in the
@command{ns-3} system that models must support any particular logging 
functionality.  The decision regarding how much information is logged
is left to the individual model developer.  In the case of the echo 
applications, a good deal of log output is available.

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 there instead of a double
colon to remind you in a relatively subtle way to conceptually separate the 
logging component name from the class name.

It turns out that in some 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.2}'' 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 quotes are required since the vertical bar we use to indicate an
OR operation is also 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
  Entering directory `repos/ns-3-allinone/ns-3-dev/build'
  Build finished successfully (00:00:00)
  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(0x638180, 0x6389b0)
  UdpEchoClientApplication:HandleRead(): Received 1024 bytes from 10.1.1.2
  UdpEchoClientApplication:StopApplication()
  UdpEchoClientApplication:DoDispose()
  UdpEchoClientApplication:~UdpEchoClient()
@end verbatim

You can now see all of the messages coming from the UDP echo client application
are identified as such.  The message ``Received 1024 bytes from 10.1.1.2'' is
now clearly identified as coming from the echo client application.  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

Warning:  You will need to remove the newline after the @code{:} in the
example text above which is only there for document formatting purposes.

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
  Entering directory `repos/ns-3-allinone/ns-3-dev/build'
  Build finished successfully (00:00:00)
  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(0x638320, 0x638b50)
  UdpEchoClientApplication:HandleRead(): Received 1024 bytes from 10.1.1.2
  UdpEchoServerApplication:StopApplication()
  UdpEchoClientApplication:StopApplication()
  UdpEchoClientApplication:DoDispose()
  UdpEchoServerApplication:DoDispose()
  UdpEchoClientApplication:~UdpEchoClient()
  UdpEchoServerApplication:~UdpEchoServer()
@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

Again, you will have to remove the newline above.  If you run the script now,
you should see the following output:

@verbatim
  Entering directory `repos/ns-3-allinone/ns-3-dev/build'
  Build finished successfully (00:00:00)
  0s UdpEchoServerApplication:UdpEchoServer()
  0s UdpEchoClientApplication:UdpEchoClient()
  1s UdpEchoServerApplication:StartApplication()
  2s UdpEchoClientApplication:StartApplication()
  2s UdpEchoClientApplication:ScheduleTransmit()
  2s UdpEchoClientApplication:Send()
  2s UdpEchoClientApplication:Send(): Sent 1024 bytes to 10.1.1.2
  2.00369s UdpEchoServerApplication:HandleRead(): Received 1024 bytes from 10.1.1.1
  2.00369s UdpEchoServerApplication:HandleRead(): Echoing packet
  2.00737s UdpEchoClientApplication:HandleRead(0x638490, 0x638cc0)
  2.00737s UdpEchoClientApplication:HandleRead(): Received 1024 bytes from 10.1.1.2
  10s UdpEchoServerApplication:StopApplication()
  10s UdpEchoClientApplication:StopApplication()
  UdpEchoClientApplication:DoDispose()
  UdpEchoServerApplication:DoDispose()
  UdpEchoClientApplication:~UdpEchoClient()
  UdpEchoServerApplication:~UdpEchoServer()
@end verbatim

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

Recall that the @code{scratch/first.cc} script started the echo server 
application at one second into the simulation.  You can now see that the 
@code{StartApplication} method 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 in its @code{HandleRead} method.

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 above is the logging component wildcard.  This will turn on all 
of the logging in all of the components used in the simulation.  I won't 
reproduce the output here (as of this writing it produces 974 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
  ./waf --run scratch/myfirst > log.out 2>&1
@end verbatim

I personally use this volume of logging 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 kind of output can be especially useful when your script does 
something completely unexpected.  If you are stepping using a debugger you
may miss an unexpected excursion completely.  Logging the excursion makes it
quickly visible.

@node Adding Logging to your Code
@subsection 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{myfirst.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
go ahead add some logging to the script.  The macro used to add an 
informational level log message is @code{NS_LOG_INFO}.  Go ahead and 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,

Open @code{scratch/myfirst.cc} in your favorite editor and add the line,

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

right before the lines,

@verbatim
  NodeContainer nodes;
  nodes.Create (2);
@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
  ./waf
  export NS_LOG=
@end verbatim

Now, if you run the script, 

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

you will @emph{not} see your new message since its associated logging 
component (@code{FirstScriptExample}) 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 it by,

@verbatim
  export NS_LOG=FirstScriptExample=info
@end verbatim

If you now run the script you will see your new ``Creating Topology'' log
message,

@verbatim
  Entering directory `repos/ns-3-allinone/ns-3-dev/build'
  Build finished successfully (00:00:00)
  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
@end verbatim

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

@subsection Overriding Default Attributes
@cindex command line arguments
Another way you can change how @command{ns-3} scripts behave without editing
and building 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 @command{ns-3} global variable and @code{Attribute} systems.  Go 
ahead and add that two lines of code to the @code{scratch/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
  ./waf --run "scratch/myfirst --PrintHelp"
@end verbatim

This will ask Waf to run the @code{scratch/myfirst} script and pass the command
line argument @code{--PrintHelp} to the script.  The quotes are required to 
sort out which program gets which argument.  The command line parser will
now see the @code{--PrintHelp} argument and respond with,

@verbatim
  Entering directory `repos/ns-3-allinone/ns-3-dev/build'
  Build finished successfully (00:00:00)
  --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.
@end verbatim

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

@verbatim
    PointToPointHelper pointToPoint;
    pointToPoint.SetDeviceAttribute ("DataRate", StringValue ("5Mbps"));
    pointToPoint.SetChannelAttribute ("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 @code{Attributes} of the PointToPointNetDevice.  The help
listing says that we should provide a @code{TypeId}.  This corresponds to the
class name of the class to which the @code{Attributes} belong.  In this case it
will be @code{ns3::PointToPointNetDevice}.  Let's go ahead and type in,

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

The system will print out all of the @code{Attributes} of this kind of net device.
Among the @code{Attributes} you will see listed is,

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

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

Your script should now just declare the @code{PointToPointHelper} and not do 
any @code{set} operations 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 (@code{./waf}) and 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
  Build finished successfully (00:00:00)
  0s UdpEchoServerApplication:UdpEchoServer()
  1s UdpEchoServerApplication:StartApplication()
  Sent 1024 bytes to 10.1.1.2
  2.25732s Received 1024 bytes from 10.1.1.1
  2.25732s Echoing packet
  Received 1024 bytes from 10.1.1.2
  10s UdpEchoServerApplication:StopApplication()
  UdpEchoServerApplication:DoDispose()
  UdpEchoServerApplication:~UdpEchoServer()
@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.00369 seconds.

@verbatim
  2.00369s UdpEchoServerApplication:HandleRead(): Received 1024 bytes from 10.1.1.1
@end verbatim

Now it is receiving the packet at 2.25732 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.  We do this in the following way, according to
the formula implied by the help item:

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

This will set the default value of the @code{DataRate} @code{Attribute} back to 
five megabits per second.  Are you surprised by the result?  It turns out that
in order to get the original behavior of the script back, we will have to set 
the speed-of-light delay of the channel as well.  We can ask the command line 
system to print out the @code{Attributes} of the channel just like we did for
the net device:

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

We discover the @code{Delay} @code{Attribute} of the channel is set in the following
way:

@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/myfirst
    --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
  Entering directory `repos/ns-3-allinone/ns-3-dev/build'
  Build finished successfully (00:00:00)
  0s UdpEchoServerApplication:UdpEchoServer()
  1s UdpEchoServerApplication:StartApplication()
  Sent 1024 bytes to 10.1.1.2
  2.00369s Received 1024 bytes from 10.1.1.1
  2.00369s Echoing packet
  Received 1024 bytes from 10.1.1.2
  10s UdpEchoServerApplication:StopApplication()
  UdpEchoServerApplication:DoDispose()
  UdpEchoServerApplication:~UdpEchoServer()
@end verbatim

Note that the packet is again received by the server at 2.00369 seconds.  We 
could actually set any of the @code{Attributes} used in the script in this way.
In particular we could set the @code{UdpEchoClient Attribute 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 @code{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/myfirst 
    --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 @code{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.  We do this by adding a call to 
@code{AddValue}.  Go ahead and change the @code{scratch/myfirst.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}
@code{Attribute} and change it so that it is set to the variable @code{nPackets}
instead of the constant @code{1} as is shown below.

@verbatim
  echoClient.SetAttribute ("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 display.

Try,

@verbatim
  ./waf --run "scratch/myfirst --PrintHelp"
@end verbatim

@verbatim
  Entering directory `repos/ns-3-allinone/ns-3-dev/build'
  Build finished successfully (00:00:00)
  --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
@end verbatim

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

@verbatim
  ./waf --run "scratch/myfirst --nPackets=2"
@end verbatim

You should now see

@verbatim
  Entering directory `repos/ns-3-allinone/ns-3-dev/build'
  Build finished successfully (00:00:00)
  0s UdpEchoServerApplication:UdpEchoServer()
  1s UdpEchoServerApplication:StartApplication()
  Sent 1024 bytes to 10.1.1.2
  2.25732s Received 1024 bytes from 10.1.1.1
  2.25732s Echoing packet
  Received 1024 bytes from 10.1.1.2
  Sent 1024 bytes to 10.1.1.2
  3.25732s Received 1024 bytes from 10.1.1.1
  3.25732s Echoing packet
  Received 1024 bytes from 10.1.1.2
  10s UdpEchoServerApplication:StopApplication()
  UdpEchoServerApplication:DoDispose()
  UdpEchoServerApplication:~UdpEchoServer()
@end verbatim

You have now echoed two packets.

You can see that if you are an @command{ns-3} user, you can use the command 
line argument system to control global values and @code{Attributes}.  If you are
a model author, you can add new @code{Attributes} to your @code{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 could be used:  

@verbatim
  #include <iostream>
  ...
  int main ()
  {
    ...
    std::cout << "The value of x is " << x << std::endl;
    ...
  } 
@end verbatim

You could even use the logging module to add a little structure to your 
solution.  There are many well-known problems generated by such approaches
and so we have provided a generic event tracing subsystem to address the 
issues we thought were important.

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 contents 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 
that 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 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 by editing only the 
user script.

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
@command{Ns-3} provides helper functionality that wraps the low-level tracing
system to help you with the details involved in configuring some easily 
understood packet traces.  If you enable this functionality, you will see
output in a ASCII files --- 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{scratch/myfirst.cc} script.  

The first thing you need to do is to add the following include to the top of
the script just after the GNU GPL comment:

@verbatim
  #include <fstream>
@end verbatim

Then, right before the before the call to @code{Simulator::Run ()}, add the
following lines of code.

@verbatim
  std::ofstream ascii;
  ascii.open ("myfirst.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 ``myfirst.tr.''  See your favorite C++ tutorial if you
are unfamiliar with this code.  The last line of code in the snippet above
tells @command{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.

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

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

@cindex myfirst.tr
Just as you have seen many times before, you will see some messages from Waf and then
the ``Build finished successfully'' with some number of messages from 
the running program.  

When it ran, the program will have created a file named @code{myfirst.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 ASCII trace file @code{myfirst.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 window considerably.

Each line in the file corresponds to a @emph{trace event}.  In this case
we are tracing events on the @emph{transmit queue} present in every 
point-to-point net device in the simulation.  The transmit queue is a queue 
through which every packet destined for a point-to-point channel must pass.
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 in the trace file.  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 protocol 17 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 
operation.  We have a @code{+} character, so this corresponds to an
@emph{enqueue} operation on the transmit queue.  The second line (reference 01)
is the simulation time expressed in seconds.  You may recall that we asked the 
@code{UdpEchoClientApplication} 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 line of the example trace (reference 02) tell us which trace source
originated this event (expressed in the tracing namespace).  You can think
of the tracing namespace somewhat like you would a filesystem namespace.  The 
root of the namespace is the @code{NodeList}.  This corresponds to a container
managed in the @command{ns-3} core code that contains all of the nodes that are
created in a script.  Just as a filesystem may have directories under the 
root, we may have node numbers in the @code{NodeList}.  The string 
@code{/NodeList/0} therefore refers to the zeroth node in the @code{NodeList}
which we typically think of as ``node 0.''  In each node there is a list of 
devices that have been installed.  This list appears next in the namespace.
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 is in the zeroth position of the device list for node zero.
Recall that the operation @code{+} found at reference 00 meant that an enqueue 
operation happened 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 encapsulated 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 packet has a UDP header 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/MacRx 
  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
and the channel @code{Delay} set to their default values.  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{/MacRx}).  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 Tracing
@cindex pcap
@cindex Wireshark
The @command{ns-3} device helpers can also be used to create trace files in the
@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 concentrate on viewing pcap traces with tcpdump.

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

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

Go ahead and insert this line of code after the ASCII tracing code we just 
added to @code{scratch/myfirst.cc}.  Notice that we only passed the string
``myfirst,'' and not ``myfirst.pcap'' or something similar.  This is because the 
parameter is a prefix, not a complete file name.  The helper will actually 
create a trace file for every point-to-point device in the simulation.  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 eventually see files named ``myfirst-0-0.pcap'' 
and ``myfirst.1-0.pcap'' which are the pcap traces for node 0-device 0 and 
node 1-device 0, respectively.

Once you have added the line of code to enable pcap tracing, you can run the
script in the usual way:

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

If you look at the top level directory of your distribution, you should now
see three log files:  @code{myfirst.tr} is the ASCII trace file we have 
previously examined.  @code{myfirst-0-0.pcap} and @code{myfirst-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.  

@verbatim
  tcpdump -nn -tt -r myfirst-0-0.pcap
  reading from file myfirst-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

  tcpdump -nn -tt -r myfirst-1-0.pcap
  reading from file myfirst-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
@end verbatim

You can see in the dump of @code{myfirst-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 (@code{first-1-0.pcap}) you can see that packet being received
at 2.257324 seconds.  You see the packet being echoed back 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}.