From 57574ea577a7306bb93447e7b8d0f11e88c654ce Mon Sep 17 00:00:00 2001 From: Mirko Bonadei Date: Fri, 12 Aug 2022 15:38:43 +0200 Subject: [PATCH] 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 Commit-Queue: Tomas Gunnarsson Cr-Commit-Position: refs/heads/main@{#37770} --- rtc_base/logging.cc | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/rtc_base/logging.cc b/rtc_base/logging.cc index 798c059fb3..4bc9183d97 100644 --- a/rtc_base/logging.cc +++ b/rtc_base/logging.cc @@ -138,9 +138,10 @@ LogMessage::LogMessage(const char* file, 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();