When parameters are computed, when combining a call: obj.F1 (). F2 (). F3 (sin (x))?

Question

I use stream operators (e.g. operator<<(const char*)) for logging. In my unit tests, I have a test like:

MyLogger oLogger;
oLogger << "charly";
oLogger << "foo" << sleep( 10 ) << "bar";
oLogger << "marcus";

First, I performed a second thread, which should be logged simultaneously. I was wondering why no other magazine was created between "foo"and "bar". Therefore, I printed the current time in each statement. I was expecting something like this:

50 sec 137051 usec charly 
50 sec 137930 usec foo 
60 sec 138014 usec 0 
60 sec 138047 usec bar 
60 sec 138088 usec marcus 

but got the following:

50 sec 137051 usec charly 
60 sec 137930 usec foo 
60 sec 138014 usec 0 
60 sec 138047 usec bar 
60 sec 138088 usec marcus 

What is wrong with the following idea:

[ 0 sec] MyLogger& MyLogger::operator<<( "charly" ) is processed.
[ 0 sec] MyLogger& MyLogger::operator<<( "foo" ) is processed.
         The return value is used for the next function.
[ 0 sec] int sleep( 10 ) is processed - this takes 10 seconds until the return
         value is available
[10 sec] MyLogger& MyLogger::operator<<( 0 ) is processed
         ( "0" is the return value of sleep(10) )
[10 sec] MyLogger& MyLogger::operator<<( "bar" ) is processed

But for what reason is it MyLogger::operator<<( "foo" )processed after sleep(10)?

Answer 1

, , "operator < <, TTBOMK gcc , .

:

push "charly"
push oLogger
call operator<<
pop
push "bar"
push 10
call sleep
push "foo"
push oLogger
call operator<<
call operator<<
call operator<<
pop