Fix potentially negative Timestamp in logs.
This bug was activated by [1] when we started to store the timestamp
in the webrtc::Timestamp class (causing an RTC_DCHECK to trigger) but
it has been in the codebase for long time (but without using
webrtc::Timestamp the RTC_DCHECK was not triggered).
Basically, LogStartTime() can be called externally to create a baseline
for logging but if that is not the case, LogMessage should call it [2]
and initialise the baseline.
This was happening in reverse order, causing the first LogMessage to
call LogStartTime() after the SystemTimeMillis(), causing a negative
time difference that when gets wrapped into webrtc::Timestamp triggers
the RTC_DCHECK [3].
[1] - https://webrtc-review.googlesource.com/c/src/+/269249
[2] - https://source.chromium.org/chromium/chromium/src/+/main:third_party/webrtc/rtc_base/logging.h;l=493-497;drc=821b92a66ed661714cc21020b5a045fcd18d0176
[3] - https://source.chromium.org/chromium/chromium/src/+/main:third_party/webrtc/rtc_base/units/unit_base.h;l=122;drc=6dcd43f1e4f2f3ec0bd844cd45e011e9c4d16e38
Bug: b/238157120
Change-Id: I891799316503030c0df5e10e759a61dfc5e1ab3c
Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/271582
Reviewed-by: Tomas Gunnarsson <tommi@webrtc.org>
Commit-Queue: Tomas Gunnarsson <tommi@webrtc.org>
Cr-Commit-Position: refs/heads/main@{#37770}
diff --git a/rtc_base/logging.cc b/rtc_base/logging.cc
index 798c059..4bc9183d 100644
--- a/rtc_base/logging.cc
+++ b/rtc_base/logging.cc
@@ -138,9 +138,10 @@
int err) {
log_line_.set_severity(sev);
if (log_timestamp_) {
+ int64_t log_start_time = LogStartTime();
// Use SystemTimeMillis so that even if tests use fake clocks, the timestamp
// in log messages represents the real system time.
- int64_t time = TimeDiff(SystemTimeMillis(), LogStartTime());
+ int64_t time = TimeDiff(SystemTimeMillis(), log_start_time);
// Also ensure WallClockStartTime is initialized, so that it matches
// LogStartTime.
WallClockStartTime();
