From b06247d9a0de9dd31a84e17deaf597f6a2cb2920 Mon Sep 17 00:00:00 2001 From: Mark Salyzyn Date: Fri, 4 Dec 2015 09:32:27 -0800 Subject: [PATCH] logd: best 2/3 filter for timezone glitches klogd is sensitive to changes in timezone resulting in glitches surrounding conversion to local realtime logging. logger manages a map from monotonic to realtime, but the process is racey since the system can change the timezone at any time, this catches those cases where it glitches. Bug: 21868540 Change-Id: I03de6675fcd04f18ba7306a24dc3d9e750d86976 --- logd/LogKlog.cpp | 25 +++++++++++++++++++++++++ 1 file changed, 25 insertions(+) diff --git a/logd/LogKlog.cpp b/logd/LogKlog.cpp index 2a3f52f99..db7e68218 100644 --- a/logd/LogKlog.cpp +++ b/logd/LogKlog.cpp @@ -778,6 +778,31 @@ int LogKlog::log(const char *buf, size_t len) { memcpy(np, p, b); np[b] = '\0'; + if (!isMonotonic()) { + // Watch out for singular race conditions with timezone causing near + // integer quarter-hour jumps in the time and compensate accordingly. + // Entries will be temporal within near_seconds * 2. b/21868540 + static uint32_t vote_time[3]; + vote_time[2] = vote_time[1]; + vote_time[1] = vote_time[0]; + vote_time[0] = now.tv_sec; + + if (vote_time[1] && vote_time[2]) { + static const unsigned near_seconds = 10; + static const unsigned timezones_seconds = 900; + int diff0 = (vote_time[0] - vote_time[1]) / near_seconds; + unsigned abs0 = (diff0 < 0) ? -diff0 : diff0; + int diff1 = (vote_time[1] - vote_time[2]) / near_seconds; + unsigned abs1 = (diff1 < 0) ? -diff1 : diff1; + if ((abs1 <= 1) && // last two were in agreement on timezone + ((abs0 + 1) % (timezones_seconds / near_seconds)) <= 2) { + abs0 = (abs0 + 1) / (timezones_seconds / near_seconds) * + timezones_seconds; + now.tv_sec -= (diff0 < 0) ? -abs0 : abs0; + } + } + } + // Log message int rc = logbuf->log(LOG_ID_KERNEL, now, uid, pid, tid, newstr, (unsigned short) n);