[Ns-developers] log time -> log context

[Gustavo Carneiro]

On 19/05/2008, Mathieu Lacage <mathieu.lacage at sophia.inria.fr> wrote:
>
> On Sun, 2008-05-18 at 15:10 +0100, Gustavo Carneiro wrote:
> > On 17/05/2008, Gustavo Carneiro <gjcarneiro at gmail.com> wrote:
> > >
> > > I am unhappy about current logging.  As I reported some weeks ago, I
> miss
> > > the node number in logging messages, among other things.
> > >
> > > The repository gjc/ns-3-log-context I am (slowly) uploading tries to
> > > provide that.  First it renames LogTimePrinter to LogContextPrinter and
> so
> > > on.  Then  it adds Simulator::SetCurrentNode (int32_t nodeId) method
> (and
> > > some other related methods).  This method is to be called when the
> > > simulation is changing current node, for some reason.  The most common
> > > reason is a NetDevice receiving a packet.  Also EvenImpl receives a new
> > > nodeId attribute (32 bits), so that when a node "schedules" an event,
> when
> > > the event is actually run Simulator::SetCurrentNode is called with that
> > > nodeId.
> > >
> > > This patch is barely tested, so be warned.  It doesn't seem to work
> 100%;
> > > I'll have to figure out why later.
> >
> >
> > OK, problem was that user code was calling UDP socket API methods.
> > Naturally, with API calls from user code NS-3 does not _know_ the current
> > context.  A few lines of code added to udp-socket.cc took care of it.
>
>
> I would have expected that you modify the code of applications to set
> the node id prior to scheduling socket-related events. Actually, you
> might get away with just modifying Application::Start and Stop


Sure, that too.

But since user code is allowed to use sockets directly, we still need to set
node id in socket APIs, not just applications.  Yes, I know you would prefer
if applications were the only source of traffic in NS-3 programs, but I
think we have already agreed to also support user programs using sockets
directly as well...

There are quite a few more places where the current node id should be set,
of course.  This is only a proof-of-concept for now, waiting for a verdict.

>
> > The output is now looking like this:
> > [...]
> > [4479922400ns node 0013] Ipv4L3Protocol:Receive(0x649770, 0x7fff2d57e700,
> > 0x6f58b0, 2048, 03-06-00:00:00:00:00:0d)
> > [4479922400ns node 0013] Ipv4L3Protocol:Receive(): Packet from
> > 03-06-00:00:00:00:00:0d received on node 13
> > [4479922400ns node 0013] Ipv4L3Protocol:Forwarding(1, 0x6f58b0,
> > 0x7fff2d57e560, 0x6481e0)
> > [4479922400ns node 0013] Ipv4L3Protocol:Forwarding(): Forwarding logic
> for
> > node: 13
> > [4479922400ns node 0013] Ipv4L3Protocol:Forwarding(): For me (destination
> > match)
> > [4479922400ns node 0013] Ipv4L3Protocol:ForwardUp(0x649770, 0x6f58b0,
> > 0x7fff2d57e560)
> > [4479922400ns node 0013] UdpSocket:ForwardUp(0x6f6db0, 0x6f3ec0,
> 172.16.0.3,
> > 49153)
> > [4481250000ns node 0011] UdpSocket:Send(0x6f3640, 0x6ec8b0)
> > [4481250000ns node 0011] UdpSocket:DoSend()
> > [4481250000ns node 0011] UdpSocket:DoSendTo(0x6f3640, 0x6ec8b0,
> 172.16.0.5,
> > 9)
> > [4481250000ns node 0011]
> Ipv4L3Protocol:GetIfIndexForDestination(0x648dd0,
> > 172.16.0.5, 0x7fff2d57eb0c)
> > [4481250000ns node 0011] Ipv4L3Protocol:GetIfIndexForDestination():
> > Requesting Source Address
> > [4481250000ns node 0011] Ipv4L3Protocol:GetIfIndexForDestination(): Found
> > ifIndex 1
> > [4481250000ns node 0011] UdpSocket:DoSendTo(): Route exists
> > [4481250000ns node 0011] Ipv4L3Protocol:GetAddress(0x648dd0, 1)
> > [4481250000ns node 0011] Ipv4L3Protocol:GetInterface(0x648dd0, 1)
> > [4481250000ns node 0011] Ipv4L3Protocol:Send(0x648dd0, 0x6fb2a0,
> 172.16.0.3,
> > 172.16.0.5,  )
> > [4481250000ns node 0011] Ipv4L3Protocol:Lookup(0x648dd0, 0x7fff2d57e870,
> > 0x6fb2a0, 0x7fff2d57e8c0)
> > [4481250000ns node 0011] Ipv4L3Protocol:Lookup(0x648dd0, 4294967295,
> > 0x7fff2d57e870, 0x6fb2a0, 0x7fff2d57e7f0)
> > [4481250000ns node 0011] Ipv4L3Protocol:Lookup(): Requesting route
> > [4481250000ns node 0011] Ipv4L3Protocol:SendRealOut(0x648dd0, 1,
> 0x649e30,
> > 0x6fb2a0, 0x7fff2d57e870)
> > [4481250000ns node 0011] Ipv4L3Protocol:SendRealOut(): Send via interface
> 1
> > [4481250000ns node 0011] Ipv4L3Protocol:GetInterface(0x648dd0, 1)
> > [4481250000ns node 0011] Ipv4L3Protocol:SendRealOut(): Send to
> destination
> > 172.16.0.5
> > [4483672400ns node 0013] Ipv4L3Protocol:Receive(0x649770, 0x7fff2d57e700,
> > 0x6f7cc0, 2048, 03-06-00:00:00:00:00:0d)
> > [4483672400ns node 0013] Ipv4L3Protocol:Receive(): Packet from
> > 03-06-00:00:00:00:00:0d received on node 13
> > [4483672400ns node 0013] Ipv4L3Protocol:Forwarding(1, 0x6f7cc0,
> > 0x7fff2d57e560, 0x6481e0)
> > [4483672400ns node 0013] Ipv4L3Protocol:Forwarding(): Forwarding logic
> for
> > node: 13
> > [4483672400ns node 0013] Ipv4L3Protocol:Forwarding(): For me (destination
> > match)
> > [4483672400ns node 0013] Ipv4L3Protocol:ForwardUp(0x649770, 0x6f7cc0,
> > 0x7fff2d57e560)
> > [4483672400ns node 0013] UdpSocket:ForwardUp(0x6f6db0, 0x6f5fd0,
> 172.16.0.3,
> > 49153)
> > [...]
> >
> > It's very easy to filter for specifc node ids using grep.
> >
>
>


-- 
Gustavo J. A. M. Carneiro
INESC Porto, Telecommunications and Multimedia Unit
"The universe is always one step beyond logic." -- Frank Herbert