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.