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
I have several questions about this: 1. How do you know in general which log present trace of first invocation, and which one second: void acess_db( ... ) { if( some error ) log << "invalid account key" << key; } int get_balance(...){ ... if( !access_db(...) ) return 0; } ... log << "Mary has balance: " << get_balance() << " and John has balance: " << get_balance() Let say an output is:
access_db Invalid account key: 25 < access_db access_db < access_db Mary has balance: 0 and John has balance: 100
----------------------------------------- Could you say where an error occurred (without looking into code and knowledge how log system is working)? Would it be like this: Mary has balance:
access_db Invalid account key: 25 < access_db 0 and John has balance: access_db < access_db 100
It would be clear. I understand that later is slightly less readable but In my experience usually what happened is that log entry fragmenting occur only on hi levels of log (or in case of error). While with regular log level and normal log flow it's not an issue. 2. How does the log system know when to dump the cash? Does it introduce any scope guards? 3. How deep it will work? And how many different cashed we could have the same time? 4. What kind of overhead it introduces? Now instead of directly writing into stream we keep second copy of every piece of log essentially doubling the memory usage and increasing log overhead, isn't it?
Looks in order to me. I'm still not sure what the alternative is?
It may be desirable in some circumstances. But it may be not. IMO Log should follow program flow 1:1. Including order of events during log entry output. Gennadiy