@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

@verbatim

  ./waf --run scratch/myfirst

@end verbatim

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

program

@verbatim

  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 you 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

  UdpEchoClientApplication:UdpEchoClient()

  UdpEchoClientApplication:StartApplication()

  UdpEchoClientApplication:ScheduleTransmit()

  UdpEchoClientApplication:Send()

  Sent 1024 bytes to 10.1.1.2

  Received 1024 bytes from 10.1.1.1

  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

@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

  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(): 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

  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(): 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

  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(): 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 

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 

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 

milliseconds.  You see the echo server logging a message telling you that it

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 

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

progress of the code quite easily without having to set breakpoints and step 

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

  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/myfirst.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

  --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,