Я использую потоковые операторы (например, operator<<(const char*)
) для ведения журнала.В моих модульных тестах у меня есть тест, подобный следующему:
MyLogger oLogger;
oLogger << "charly";
oLogger << "foo" << sleep( 10 ) << "bar";
oLogger << "marcus";
Сначала я выполнил второй поток, который должен одновременно регистрироваться.Мне было интересно, почему между "foo"
и "bar"
другой лог-выход не генерировался.Поэтому я напечатал в каждом операторе текущее время.Я ожидал что-то вроде этого:
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
, но получил это:
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
Что не так со следующей идеей:
[ 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
Но по какой причинеMyLogger::operator<<( "foo" )
обрабатывается после sleep(10)
?