Boost logo

Boost :

From: Darryl Green (darryl.green_at_[hidden])
Date: 2005-05-03 22:38:44


Gennadiy Rozental <gennadiy.rozental <at> thomson.com> writes:
>
> > So something like this:
> >
> > BOOST_LOG (x) << "Result of f: " << f ().
> >
> > Turns into something more like (expanding out the code inside the
> > classes and greatly oversimplifying, but this iis the gist):
> >
> > if (!x.is_enabled ())
> > ;
> > else
> > {
> > ostringstream s;
> > s << "Result of f: " << f ();
> > write_msg (logger::manager (), x, s.str ());
> > }
> >
> > So if there are nested logging calls inside of "f" that are destined
> > for the logger "x", they will hit the output device *before* the
> > caller's message does.
>
> This means that in example like above Logs from m() calls will be printed
> before f() and g(). And nobody will be able to tell which one is from where.
> It's completely unacceptable IMO. Threading/no threading, cashing /no
> cashing Log is NOT allowed to change an order of events.
>

But the order hasn't been changed - it just isn't what you expected.
I'm not sure why you didn't expect it - it seems reasonable (to me) that
the result of evaluating the complete expression is logged. If some
subexpression has a side effect that writes to a log, its results will
be logged when the sub-expression is complete. That is "in order" afaiks.

What about this:

time_t slow_time()
{
   BOOST_LOG(x) << "going to sleep at " << time(0);
   sleep(1);
   time_t t;
   BOOST_LOG(x) << "waking up at " << t = time(0);
   return t;
}

void f()
{
  BOOST_LOG(x) << "slow_time returned " << slow_time() << " then " << slow_time();
}

Resulting in (I ran this test a long time ago, boot time isn't bad either :-) :

going to sleep at 0
waking up at 1
going to sleep at 1
waking up at 2
slow time returned 1 then 2

Looks in order to me. I'm still not sure what the alternative is?

Darryl.


Boost list run by bdawes at acm.org, gregod at cs.rpi.edu, cpdaniel at pacbell.net, john at johnmaddock.co.uk