Always compute the time for a trace event when it is being logged rather than when it is being created. Usually these are the same, but if they aren't, doing the opposite can lead to out of order trace events.

This commit is contained in:
A.J. Beamon 2020-02-21 13:57:04 -08:00
parent 2e699fef55
commit 2431d4d788
2 changed files with 4 additions and 5 deletions

View File

@ -111,7 +111,7 @@ extern bool isAssertDisabled( int line );
// ASSERT_WE_THINK() is to be used for assertions that we want to validate in testing, but which are judged too
// risky to evaluate at runtime, because the code should work even if they are false and throwing internal_error() would
// result in a bug. Don't use it for assertions that are *expensive*; look at EXPENSIVE_VALIDATION.
#define ASSERT_WE_THINK( condition ) ASSERT( !g_network->isSimulated() || (condition) )
#define ASSERT_WE_THINK( condition ) ASSERT( !g_network || !g_network->isSimulated() || (condition) )
#define ABORT_ON_ERROR( code_to_run ) \
try { code_to_run; } \

View File

@ -773,7 +773,7 @@ bool TraceEvent::init() {
}
detail("Severity", int(severity));
detailf("Time", "%.6f", getCurrentTime());
detail("Time", "0.000000");
timeIndex = fields.size() - 1;
detail("Type", type);
@ -983,9 +983,8 @@ void TraceEvent::log(bool useCurrentTime) {
init();
try {
if (enabled) {
if (useCurrentTime) {
fields.mutate(timeIndex).second = format("%.6f", TraceEvent::getCurrentTime());
}
fields.mutate(timeIndex).second = format("%.6f", TraceEvent::getCurrentTime());
if (this->severity == SevError) {
severity = SevInfo;
backtrace();