[Ns-developers] log time -> log context

[Gustavo Carneiro]

On 21/05/2008, Mathieu Lacage <mathieu.lacage at sophia.inria.fr> wrote:
>
> On Tue, 2008-05-20 at 18:10 +0100, Gustavo Carneiro wrote:
>
> >         I know that it does not scale but that was a decision a long
> >         time ago.
> >         We felt that the improvement from:
> >
> >         Simulator::Schedule (Seconds (1.0), MakeEvent (&MyFunction));
> >         to:
> >         Simulator::Schedule (Seconds (1.0), &MyFunction);
> >
> >         was worth the implementation pain.
> >
> > I was not involved in those discussions, but the way I see it the
> > change was to allow arbitrary callback parameters passed from to the
> > code that calls schedule to the function that receives control from
> > the scheduler.  A rather substantial change.
>
>
> No. The change was:
> 
> from:
> Simulator::Schedule (Seconds (1.0), MakeEvent (&MyFunction, args));
> to:
> Simulator::Schedule (Seconds (1.0), &MyFunction, args);
>
> Notice that I never mentioned Callback here. There used to be (and there
> still are but they are now private members of the Simulator class) a set
> of functions named MakeEvent, and not MakeCallback and these took the
> function pointers _and_ the arguments to the function.
>
>
> >
> > What we are talking here is merging two completely orthogonal APIs
> > into a single one.  A lot of coding for no apparent gain.  Or at least
> > I don't understand the gain...
>
>
> It saves you from having to type the call to MakeEvent.
>
>
> >
> >
> >         Now, if you really care about these other things, please,
> >         let's think
> >         about them _now_ before we go further and let's try to figure
> >         out
> >         whether it makes any sense to try to support further context
> >         information
> >         than the node id.
> >
> > I am thinking of netdevice number as context.  At least temporarily
> > until control reaches the IP layer.  But that would be very low on my
> > priority list.
>
>
> I do not understand how that would work. How would I interpret that
> context when outside of the netdevice ? It seems to me that if your
> model has model-specific context which needs to be printed in the
> logging output, your model should implement an extra logging macro to do
> that for you. That is low-tech but is so trivial to implement whenever
> you need it that I have a hard time seeing what is wrong about it.


I haven't thought about it very much; netdevice was just trying to give an
example.

If you are in a context not related to a netdevice, I would expect to see
log messages that did not print netdevice information at all.

>         >     3) most importantly, thinking about it some more I
> >         realized most
> >         > of the time the code that does the schedule does not know,
> >         or should
> >         > not know, the target node.  Instead it is the code receiving
> >         the
> >         > schedule that knows its own node.   Additionally, sometimes
> >         context
> >
> >
> >         Theoretically, you are right but this muddies even more the
> >         semantics of
> >         SetNodeId: "ignore the current event's node id, set the
> >         current context
> >         to this value, use it for the next Schedule call to store in
> >         the event
> >         its associated context".
> >
> > OK, I think with an example it is better to understand why this makes
> > sense:
> >
> >
> > void
> > CsmaChannel::PropagationCompleteEvent()
> > {
> >   NS_LOG_FUNCTION (this << m_currentPkt);
> >   NS_LOG_INFO ("UID is " << m_currentPkt->GetUid () << ")");
> >
> >   NS_ASSERT(m_state == PROPAGATING);
> >
> >   NS_LOG_LOGIC ("Receive");
> >
> >   std::vector<CsmaDeviceRec>::iterator it;
> >   for (it = m_deviceList.begin(); it < m_deviceList.end(); it++)
> >     {
> >       if (it->IsActive())
> >       {
> >         it->devicePtr->Receive (m_currentPkt->Copy ());
> >       }
> >     }
> >   m_state = IDLE;
> > }
> >
> > It's easy to see that, in this case, changing node id context is done
> > via a simple method call, not a schedule.  To support node id contexts
> > here, I would need to change current node right before each
> > it->devicePtr->Receive () call, and put it back in the end to the
> > original value.
>
>
> If you wanted to use a Schedule call, you would just schedule the call
> to Receive from the inner loop rather than call receive directly. Same
> thing.
>
>
> >
> > Therefore, SetNodeId() works and is the simplest solution.  Putting a
>
>
> Yes, it works. Yes, it is the solution which requires the smallest
> patch. However, I very much prefer something which will require _you_ to
> write a larger patch with minimal documentation and obvious semantics.
> Unless, of course, you can write down the documentation for that
> function and convince me that this documentation is understandable by
> mere mortals.


I don't know what else to explain:

  /**
   * Set the current node that is being simulated.
   * \warning this method has no effect on optimized NS-3 builds, as it is
used only for logging.
   * \param node   id of the current node, or -1 if none or not known
   */
  static void SetCurrentNode (int32_t node);

It's dead simple.  What might be missing perhaps is some guideline
explaining when the user is expected to call it.  Is that what you mean?

>  nodeId in Schedule calls would not be flexible enough, and would not
> >  be in any way simpler.  Two API calls instead of one is often a
> >  simpler solution.
> >
> >
> >
> >         >  transitions should happen before any schedule callback, as
> >         seen in
> >         > the socket example, where a stack of functions calls are
> >         made before
> >         > any schedule is done, and we want the logging messages to
> >         reflect the
> >         > actual current node during all those calls.
> >
> >
> >         If you do the nodeid setting in the first schedule done at the
> >         application layer, you will not have this problem in this
> >         case.
> >
> > But it would not fix the direct socket  issue.  A lot happens in
>
>
> You would just have to do extra work and make sure you call a schedule
> yourself to do this right.
>
>
> >  socket code before the first schedule is even invoked.  We want
> > everything to be correctly associated with the current node.
>
>
> Using raw sockets outside of the context of an Application Start
> function makes little sense and is clearly not the way the system was
> designed to be used: yes, it can be made to work, yes, we have examples
> which do this, yes you like being able to do it but, as discussed a
> while ago in a bug report, _this is not the way the system was designed
> to be used_. If, when you do this, you do not get the best logging
> messages in the world without some extra work, such is life.


About the extra work:

 1. I am not convinced the extra work will be worth anything.  It doesn't
improve readability in my opinion;
 2. Adding extra Schedule calls will increasing the number of events and
decrease NS-3 performance.  I want the logging improvements to be as little
intrusive as possible, as all logging should be.


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