2009-09-15 00:05:36 -07:00
|
|
|
@node Tracing
|
|
|
|
|
@chapter Tracing
|
|
|
|
|
|
2009-10-18 22:11:29 -07:00
|
|
|
The tracing subsystem is one of the most important mechanisms to understand in
|
2009-09-15 00:05:36 -07:00
|
|
|
@command{ns-3}. In most cases, @command{ns-3} users will have a brilliant idea
|
|
|
|
|
for some new and improved networking feature. In order to verify that this
|
|
|
|
|
idea works, the researcher will make changes to an existing system and then run
|
2009-10-18 22:11:29 -07:00
|
|
|
experiments to see how the new feature behaves by gathering statistics
|
|
|
|
|
that capture the behavior of the feature.
|
2009-09-15 00:05:36 -07:00
|
|
|
|
|
|
|
|
In other words, the whole point of running a simulation is to generate output for
|
|
|
|
|
further study. In @command{ns-3}, the subsystem that enables a researcher to do
|
|
|
|
|
this is the tracing subsystem.
|
|
|
|
|
|
|
|
|
|
@menu
|
2009-10-16 07:13:05 -07:00
|
|
|
* Tracing Motivation::
|
2009-09-15 00:05:36 -07:00
|
|
|
* Overview::
|
|
|
|
|
* Using the Tracing API::
|
2009-10-16 07:13:05 -07:00
|
|
|
* Tracing implementation details::
|
2009-09-15 00:05:36 -07:00
|
|
|
@end menu
|
|
|
|
|
|
2009-10-16 07:13:05 -07:00
|
|
|
@node Tracing Motivation
|
2009-09-15 00:05:36 -07:00
|
|
|
@section Motivation
|
|
|
|
|
|
|
|
|
|
There are many ways to get information out of a program. The most straightforward
|
|
|
|
|
way is to just directly print the information to the standard output, as in,
|
|
|
|
|
|
|
|
|
|
@verbatim
|
|
|
|
|
#include <iostream>
|
|
|
|
|
...
|
|
|
|
|
int main ()
|
|
|
|
|
{
|
|
|
|
|
...
|
|
|
|
|
std::cout << ``The value of x is `` << x << std::endl;
|
|
|
|
|
...
|
|
|
|
|
}
|
|
|
|
|
@end verbatim
|
|
|
|
|
|
|
|
|
|
This is workable in small environments, but as your simulations get more and more
|
2009-10-18 22:11:29 -07:00
|
|
|
complicated, you end up with more and more prints and the task of parsing and
|
2009-09-15 00:05:36 -07:00
|
|
|
performing computations on the output begins to get harder and harder.
|
|
|
|
|
|
|
|
|
|
Another thing to consider is that every time a new tidbit is needed, the software
|
|
|
|
|
core must be edited and another print introduced. There is no standardized way
|
|
|
|
|
to control all of this output, so the amount of output tends to grow without
|
|
|
|
|
bounds. Eventually, the bandwidth required for simply outputting this information
|
|
|
|
|
begins to limit the running time of the simulation. The output files grow to
|
|
|
|
|
enormous sizes and parsing them becomes a problem.
|
|
|
|
|
|
|
|
|
|
@command{ns-3} provides a simple mechanism for logging and providing some control
|
|
|
|
|
over output via @emph{Log Components}, but the level of control is not very fine
|
|
|
|
|
grained at all. The logging module is a relatively blunt instrument.
|
|
|
|
|
|
|
|
|
|
It is desirable to have a facility that allows one to reach into the core system
|
|
|
|
|
and only get the information required without having to change and recompile the
|
|
|
|
|
core system. Even better would be a system that notified the user when an item
|
|
|
|
|
of interest changed or an interesting event happened.
|
|
|
|
|
|
|
|
|
|
The @command{ns-3} tracing system is designed to work along those lines and is
|
|
|
|
|
well-integrated with the Attribute and Config substems allowing for relatively
|
|
|
|
|
simple use scenarios.
|
|
|
|
|
|
|
|
|
|
@node Overview
|
|
|
|
|
@section Overview
|
|
|
|
|
|
|
|
|
|
The tracing subsystem relies heavily on the @code{ns-3} Callback and Attribute
|
|
|
|
|
mechanisms. You should read and understand the corresponding sections of the
|
|
|
|
|
manual before attempting to understand the tracing system.
|
|
|
|
|
|
|
|
|
|
The ns-3 tracing system is built on the concepts of independent tracing sources
|
|
|
|
|
and tracing sinks; along with 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. A trace source might also indicate
|
2009-10-18 22:11:29 -07:00
|
|
|
when an interesting state change happens in a model. For example, the congestion
|
2009-09-15 00:05:36 -07:00
|
|
|
window of a TCP model is a prime candidate for a trace source.
|
|
|
|
|
|
|
|
|
|
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 source.
|
|
|
|
|
The entities that consume trace information are called trace sinks. Trace sources
|
|
|
|
|
are generators of events and trace sinks are consumers.
|
|
|
|
|
|
|
|
|
|
This explicit division allows for large numbers of trace sources to be scattered
|
|
|
|
|
around the system in places which model authors believe might be useful. Unless
|
|
|
|
|
a user connects a trace sink to one of these sources, nothing is output. This
|
|
|
|
|
arrangement allows relatively unsophisticated users to attach new types of sinks
|
|
|
|
|
to existing tracing sources, without requiring editing and recompiling the core
|
|
|
|
|
or models of the simulator.
|
|
|
|
|
|
|
|
|
|
There can be zero or more consumers of trace events generated by a trace source.
|
|
|
|
|
One can think of a trace source as a kind of point-to-multipoint information link.
|
|
|
|
|
|
2009-10-18 22:11:29 -07:00
|
|
|
The ``transport protocol'' for this conceptual point-to-multipoint link is an
|
2009-09-15 00:05:36 -07:00
|
|
|
@code{ns-3} @code{Callback}.
|
|
|
|
|
|
|
|
|
|
Recall from the Callback Section that callback facility is a way to allow two
|
|
|
|
|
modules in the system to communicate via function calls while at the same time
|
|
|
|
|
decoupling the calling function from the called class completely. This is the
|
|
|
|
|
same requirement as outlined above for the tracing system.
|
|
|
|
|
|
2009-10-18 22:11:29 -07:00
|
|
|
Basically, a trace source @emph{is} a callback to which multiple
|
|
|
|
|
functions may be registered. When a trace sink expresses
|
2009-09-15 00:05:36 -07:00
|
|
|
interest in receiving trace events, it adds a callback to a list of callbacks
|
|
|
|
|
held by the trace source. When an interesting event happens, the trace source
|
|
|
|
|
invokes its @code{operator()} providing zero or more parameters. This tells
|
|
|
|
|
the source to go through its list of callbacks invoking each one in turn. In
|
|
|
|
|
this way, the parameter(s) are communicated to the trace sinks, which are just
|
|
|
|
|
functions.
|
|
|
|
|
|
|
|
|
|
@subsection The Simplest Example
|
|
|
|
|
|
|
|
|
|
It will be useful to go walk a quick example just to reinforce what we've said.
|
|
|
|
|
|
2009-10-18 22:11:29 -07:00
|
|
|
@smallformat
|
|
|
|
|
@example
|
2009-09-15 00:05:36 -07:00
|
|
|
#include ``ns3/object.h''
|
|
|
|
|
#include ``ns3/uinteger.h''
|
|
|
|
|
#include ``ns3/traced-value.h''
|
|
|
|
|
#include ``ns3/trace-source-accessor.h''
|
|
|
|
|
|
|
|
|
|
#include <iostream>
|
|
|
|
|
|
|
|
|
|
using namespace ns3;
|
2009-10-18 22:11:29 -07:00
|
|
|
@end example
|
|
|
|
|
@end smallformat
|
2009-09-15 00:05:36 -07:00
|
|
|
|
|
|
|
|
The first thing to do is include the required files. As mentioned above, the
|
|
|
|
|
trace system makes heavy use of the Object and Attribute systems. The first
|
|
|
|
|
two includes bring in the declarations for those systems. The file,
|
|
|
|
|
@code{traced-value.h} brings in the required declarations for tracing data
|
|
|
|
|
that obeys value semantics.
|
|
|
|
|
|
|
|
|
|
In general, value semantics just means that you can pass the object around,
|
|
|
|
|
not an address. In order to use value semantics at all you have to have an
|
|
|
|
|
object with an associated copy constructor and assignment operator
|
|
|
|
|
available. We extend the requirements to talk about the set of operators
|
|
|
|
|
that are pre-defined for plain-old-data (POD) types. Operator=, operator++,
|
|
|
|
|
operator--, operator+, operator==, etc.
|
|
|
|
|
|
|
|
|
|
What this all means is that you will be able to trace changes to an object
|
|
|
|
|
made using those operators.
|
|
|
|
|
|
2009-10-18 22:11:29 -07:00
|
|
|
@smallformat
|
|
|
|
|
@example
|
2009-09-15 00:05:36 -07:00
|
|
|
class MyObject : public Object
|
|
|
|
|
{
|
|
|
|
|
public:
|
|
|
|
|
static TypeId GetTypeId (void)
|
|
|
|
|
{
|
|
|
|
|
static TypeId tid = TypeId ("MyObject")
|
|
|
|
|
.SetParent (Object::GetTypeId ())
|
|
|
|
|
.AddConstructor<MyObject> ()
|
|
|
|
|
.AddTraceSource ("MyInteger",
|
|
|
|
|
"An integer value to trace.",
|
|
|
|
|
MakeTraceSourceAccessor (&MyObject::m_myInt))
|
|
|
|
|
;
|
|
|
|
|
return tid;
|
|
|
|
|
}
|
|
|
|
|
|
|
|
|
|
MyObject () {}
|
|
|
|
|
TracedValue<uint32_t> m_myInt;
|
|
|
|
|
};
|
2009-10-18 22:11:29 -07:00
|
|
|
@end example
|
|
|
|
|
@end smallformat
|
2009-09-15 00:05:36 -07:00
|
|
|
|
|
|
|
|
Since the tracing system is integrated with Attributes, and Attributes work
|
|
|
|
|
with Objects, there must be an @command{ns-3} @code{Object} for the trace source
|
|
|
|
|
to live in. The two important lines of code are the @code{.AddTraceSource} and
|
|
|
|
|
the @code{TracedValue} declaration.
|
|
|
|
|
|
|
|
|
|
The @code{.AddTraceSource} provides the ``hooks'' used for connecting the trace
|
|
|
|
|
source to the outside world. The @code{TracedValue} declaration provides the
|
2009-09-15 11:57:12 -07:00
|
|
|
infrastructure that overloads the operators mentioned above and drives the callback
|
2009-09-15 00:05:36 -07:00
|
|
|
process.
|
|
|
|
|
|
2009-10-18 22:11:29 -07:00
|
|
|
@smallformat
|
|
|
|
|
@example
|
2009-09-15 00:05:36 -07:00
|
|
|
void
|
|
|
|
|
IntTrace (Int oldValue, Int newValue)
|
|
|
|
|
{
|
|
|
|
|
std::cout << ``Traced `` << oldValue << `` to `` << newValue << std::endl;
|
|
|
|
|
}
|
2009-10-18 22:11:29 -07:00
|
|
|
@end example
|
|
|
|
|
@end smallformat
|
2009-09-15 00:05:36 -07:00
|
|
|
|
|
|
|
|
This is the definition of the trace sink. It corresponds directly to a callback
|
|
|
|
|
function. This function will be called whenever one of the operators of the
|
|
|
|
|
@code{TracedValue} is executed.
|
|
|
|
|
|
2009-10-18 22:11:29 -07:00
|
|
|
@smallformat
|
|
|
|
|
@example
|
2009-09-15 00:05:36 -07:00
|
|
|
int
|
|
|
|
|
main (int argc, char *argv[])
|
|
|
|
|
{
|
|
|
|
|
Ptr<MyObject> myObject = CreateObject<MyObject> ();
|
|
|
|
|
|
2009-10-18 22:11:29 -07:00
|
|
|
myObject->TraceConnectWithoutContext ("MyInteger", MakeCallback(&IntTrace));
|
2009-09-15 00:05:36 -07:00
|
|
|
|
|
|
|
|
myObject->m_myInt = 1234;
|
|
|
|
|
}
|
2009-10-18 22:11:29 -07:00
|
|
|
@end example
|
|
|
|
|
@end smallformat
|
2009-09-15 00:05:36 -07:00
|
|
|
|
|
|
|
|
In this snippet, the first thing that needs to be done is to create the object
|
|
|
|
|
in which the trace source lives.
|
|
|
|
|
|
|
|
|
|
The next step, the @code{TraceConnectWithoutContext}, forms the connection
|
|
|
|
|
between the trace source and the trace sink. Notice the @code{MakeCallback}
|
|
|
|
|
template function. Recall from the Callback section that this creates the
|
|
|
|
|
specialized functor responsible for providing the overloaded @code{operator()}
|
2009-09-15 11:57:12 -07:00
|
|
|
used to ``fire'' the callback. The overloaded operators (++, --, etc.) will
|
|
|
|
|
use this @code{operator()} to actually invoke the callback. The
|
|
|
|
|
@code{TraceConnectWithoutContext}, takes a string parameter that provides
|
|
|
|
|
the name of the Attribute assigned to the trace source. Let's ignore the bit
|
|
|
|
|
about context for now since it is not important yet.
|
2009-09-15 00:05:36 -07:00
|
|
|
|
|
|
|
|
Finally, the line,
|
|
|
|
|
|
|
|
|
|
@verbatim
|
|
|
|
|
myObject->m_myInt = 1234;
|
|
|
|
|
@end verbatim
|
|
|
|
|
|
|
|
|
|
should be interpreted as an invocation of @code{operator=} on the member
|
|
|
|
|
variable @code{m_myInt} with the integer @code{1234} passed as a parameter.
|
|
|
|
|
It turns out that this operator is defined (by @code{TracedValue}) to execute
|
|
|
|
|
a callback that returns void and takes two integer values as parameters --
|
|
|
|
|
an old value and a new value for the integer in question. That is exactly
|
|
|
|
|
the function signature for the callback function we provided -- @code{IntTrace}.
|
|
|
|
|
|
|
|
|
|
To summarize, a trace source is, in essence, a variable that holds a list of
|
|
|
|
|
callbacks. A trace sink is a function used as the target of a callback. The
|
|
|
|
|
Attribute and object type information systems are used to provide a way to
|
|
|
|
|
connect trace sources to trace sinks. The act of ``hitting'' a trace source
|
|
|
|
|
is executing an operator on the trace source which fires callbacks. This
|
|
|
|
|
results in the trace sink callbacks registering interest in the source being
|
|
|
|
|
called with the parameters provided by the source.
|
|
|
|
|
|
|
|
|
|
@subsection Using the Config Subsystem to Connect to Trace Sources
|
|
|
|
|
|
|
|
|
|
The @code{TraceConnectWithoutContext} call shown above in the simple example is
|
|
|
|
|
actually very rarely used in the system. More typically, the @code{Config}
|
|
|
|
|
subsystem is used to allow selecting a trace source in the system using what is
|
|
|
|
|
called a @emph{config path}.
|
|
|
|
|
|
|
|
|
|
For example, one might find something that looks like the following in the system
|
|
|
|
|
(taken from @code{examples/tcp-large-transfer.cc})
|
|
|
|
|
|
2009-10-18 22:11:29 -07:00
|
|
|
@smallformat
|
|
|
|
|
@example
|
2009-09-15 00:05:36 -07:00
|
|
|
void CwndTracer (uint32_t oldval, uint32_t newval) {}
|
|
|
|
|
|
|
|
|
|
...
|
|
|
|
|
|
|
|
|
|
Config::ConnectWithoutContext (
|
|
|
|
|
"/NodeList/0/$ns3::TcpL4Protocol/SocketList/0/CongestionWindow",
|
|
|
|
|
MakeCallback (&CwndTracer));
|
2009-10-18 22:11:29 -07:00
|
|
|
@end example
|
|
|
|
|
@end smallformat
|
2009-09-15 00:05:36 -07:00
|
|
|
|
|
|
|
|
This should look very familiar. It is the same thing as the previous example,
|
2009-09-15 11:57:12 -07:00
|
|
|
except that a static member function of class @code{Config} is being called instead
|
|
|
|
|
of a method on @code{Object}; and instead of an @code{Attribute} name, a path is
|
2009-09-15 00:05:36 -07:00
|
|
|
being provided.
|
|
|
|
|
|
|
|
|
|
The first thing to do is to read the path backward. The last segment of the path
|
|
|
|
|
must be an @code{Attribute} of an @code{Object}. In fact, if you had a pointer to
|
2009-09-15 11:57:12 -07:00
|
|
|
the @code{Object} that has the ``CongestionWindow'' @code{Attribute} handy (call it
|
|
|
|
|
@code{theObject}), you could write this just like the previous example:
|
2009-09-15 00:05:36 -07:00
|
|
|
|
2009-10-18 22:11:29 -07:00
|
|
|
@smallformat
|
|
|
|
|
@example
|
2009-09-15 00:05:36 -07:00
|
|
|
void CwndTracer (uint32_t oldval, uint32_t newval) {}
|
|
|
|
|
|
|
|
|
|
...
|
|
|
|
|
|
2009-09-15 11:57:12 -07:00
|
|
|
theObject->TraceConnectWithoutContext ("CongestionWindow", MakeCallback (&CwndTracer));
|
2009-10-18 22:11:29 -07:00
|
|
|
@end example
|
|
|
|
|
@end smallformat
|
2009-09-15 00:05:36 -07:00
|
|
|
|
2009-09-15 11:57:12 -07:00
|
|
|
It turns out that the code for @code{Config::ConnectWithoutContext} does exactly that.
|
|
|
|
|
This function takes a path that represents a chain of @code{Object} pointers and follows
|
2009-09-15 00:05:36 -07:00
|
|
|
them until it gets to the end of the path and interprets the last segment as an
|
2009-09-15 11:57:12 -07:00
|
|
|
@code{Attribute} on the last object. Let's walk through what happens.
|
2009-09-15 00:05:36 -07:00
|
|
|
|
|
|
|
|
The leading ``/'' character in the path refers to a so-called namespace. One of the
|
|
|
|
|
predefined namespaces in the config system is ``NodeList'' which is a list of all of
|
|
|
|
|
the nodes in the simulation. Items in the list are referred to by indices into the
|
|
|
|
|
list, so ``/NodeList/0'' refers to the zeroth node in the list of nodes created by
|
|
|
|
|
the simulation. This node is actually a @code{Ptr<Node>} and so is a subclass of
|
|
|
|
|
an @code{ns3::Object}.
|
|
|
|
|
|
|
|
|
|
As described in the Object Model section, @code{ns-3} supports an object aggregation
|
|
|
|
|
model. The next path segment begins with the ``$'' character which indicates a
|
|
|
|
|
@code{GetObject} call should be made looking for the type that follows. When a
|
|
|
|
|
node is initialized by an @code{InternetStackHelper} a number of interfaces are
|
|
|
|
|
aggregated to the node. One of these is the TCP level four protocol. The runtime
|
|
|
|
|
type of this protocol object is ``ns3::TcpL4Protocol''. When the @code{GetObject}
|
|
|
|
|
is executed, it returns a pointer to the object of this type.
|
|
|
|
|
|
|
|
|
|
The @code{TcpL4Protocol} class defines an Attribute called ``SocketList'' which is
|
|
|
|
|
a list of sockets. Each socket is actually an @code{ns3::Object} with its own
|
|
|
|
|
@code{Attributes}. The items in the list of sockets are referred to by index just
|
|
|
|
|
as in the NodeList, so ``SocketList/0'' refers to the zeroth socket in the list
|
|
|
|
|
of sockets on the zeroth node in the NodeList -- the first node constructed in the
|
|
|
|
|
simulation.
|
|
|
|
|
|
|
|
|
|
This socket, the type of which turns out to be an @code{ns3::TcpSocketImpl} defines
|
|
|
|
|
an attribute called ``CongestionWindow'' which is a @code{TracedValue<uint32_t>}.
|
|
|
|
|
The @code{Config::ConnectWithoutContext} now does a,
|
|
|
|
|
|
2009-10-18 22:11:29 -07:00
|
|
|
@smallformat
|
|
|
|
|
@example
|
2009-09-15 00:05:36 -07:00
|
|
|
object->TraceConnectWithoutContext ("CongestionWindow", MakeCallback (&CwndTracer));
|
2009-10-18 22:11:29 -07:00
|
|
|
@end example
|
|
|
|
|
@end smallformat
|
2009-09-15 00:05:36 -07:00
|
|
|
|
|
|
|
|
using the object pointer from ``SocketList/0'' which makes the connection between
|
|
|
|
|
the trace source defined in the socket to the callback -- @code{CwndTracer}.
|
|
|
|
|
|
|
|
|
|
Now, whenever a change is made to the @code{TracedValue<uint32_t>} representing the
|
|
|
|
|
congestion window in the TCP socket, the registered callback will be executed and
|
2009-10-18 22:11:29 -07:00
|
|
|
the function @code{CwndTracer} will be called printing out the old and new values
|
2009-09-15 00:05:36 -07:00
|
|
|
of the TCP congestion window.
|
|
|
|
|
|
|
|
|
|
@node Using the Tracing API
|
|
|
|
|
@section Using the Tracing API
|
|
|
|
|
|
|
|
|
|
There
|
|
|
|
|
are three levels of interaction with the tracing system:
|
|
|
|
|
|
|
|
|
|
@itemize @bullet
|
|
|
|
|
@item Beginning user can easily control which objects are participating in tracing;
|
|
|
|
|
@item Intermediate users can extend the tracing system to modify the output format
|
|
|
|
|
generated or use existing trace sources in different ways, without modifying the
|
|
|
|
|
core of the simulator;
|
|
|
|
|
@item Advanced users can modify the simulator core to add new tracing sources and
|
|
|
|
|
sinks.
|
2009-09-19 16:24:55 -07:00
|
|
|
@end itemize
|
2009-09-15 00:05:36 -07:00
|
|
|
|
2009-10-16 07:13:05 -07:00
|
|
|
@node Tracing implementation details
|
2009-09-15 00:05:36 -07:00
|
|
|
@section Implementation details
|