[Ns-developers] log time -> log context

[Gustavo Carneiro]

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.

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