Use sub-second timestamps for powerd, chrome, ui, etc logs |
||||||||
Issue descriptionThe Android Debug Tool Extension [0] is very powerful tool for viewing logs in feedback reports. [0] https://chrome.google.com/webstore/a/google.com/detail/android-bug-tool-extensio/mbbaofdfoekifkfpgehgffcpagbbjkmj This tool has a "Combined" mode that interleaves timestamped log entries from multiple log files. This is a great way to visualize what is happening across the entire system at a glance. However, one big draw-back at present, is that, since chrome/ui/powerd logs only have whole-second precision, these logs are not interleaved accurately with respect to kernel (syslog), netlog, and other logs that have sub-second timestamps.
,
Nov 23 2016
From base/logging.c:
// writes the common header info to the stream
void LogMessage::Init(const char* file, int line) {
...
if (g_log_timestamp) {
time_t t = time(nullptr);
struct tm local_time = {0};
#ifdef _MSC_VER
localtime_s(&local_time, &t);
#else
localtime_r(&t, &local_time);
#endif
struct tm* tm_time = &local_time;
stream_ << std::setfill('0')
<< std::setw(2) << 1 + tm_time->tm_mon
<< std::setw(2) << tm_time->tm_mday
<< '/'
<< std::setw(2) << tm_time->tm_hour
<< std::setw(2) << tm_time->tm_min
<< std::setw(2) << tm_time->tm_sec
<< ':';
}
So, time returns time in seconds, and that's all Chrome uses.
This looks quite easy to fix, by using clock_gettime() instead.
,
Nov 23 2016
CL to use clock_gettime(): https://codereview.chromium.org/2528613002/
,
Nov 30 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/543a3be1be43bf23fbca2140ad90d18ee7ec6655 commit 543a3be1be43bf23fbca2140ad90d18ee7ec6655 Author: djkurtz <djkurtz@chromium.org> Date: Wed Nov 30 14:17:34 2016 base: Print sub-second resolution timestamps Currently Chrome logs time in full seconds. On Chrome OS, all other loggers use at least microsecond resolution. This makes it hard to compare Chrome timestamps to other system events. Instead, have Chrome use gettimeofday() on POSIX to fetch microsecond resolution timestamps, and GetLocalTime() on Windows to fetch millisecond resolution timestamps Note: the Windows implementation is adapted from mini_chromium: https://chromium.googlesource.com/chromium/mini_chromium/+/9f129335dbe57ae9a3... BUG= chromium:638472 TEST=tail -F /var/log/chrome/chrome shows microsecond timestamps, like: [1:1:1123/185804.213359:VERBOSE1:zygote_main_linux.cc(599)] ZygoteMain: initializing 2 fork delegates R=dcheng NOPRESUBMIT=true Review-Url: https://codereview.chromium.org/2528613002 Cr-Commit-Position: refs/heads/master@{#435254} [modify] https://crrev.com/543a3be1be43bf23fbca2140ad90d18ee7ec6655/base/logging.cc
,
Nov 30 2016
,
Nov 30 2016
,
Dec 1 2016
Your change meets the bar and is auto-approved for M56 (branch: 2924)
,
Dec 3 2016
The following revision refers to this bug: https://chromium.googlesource.com/chromium/src.git/+/689d0f35b7686e94fa928da10126c15ef881cb4b commit 689d0f35b7686e94fa928da10126c15ef881cb4b Author: djkurtz <djkurtz@chromium.org> Date: Sat Dec 03 02:15:42 2016 base: Print sub-second resolution timestamps Currently Chrome logs time in full seconds. On Chrome OS, all other loggers use at least microsecond resolution. This makes it hard to compare Chrome timestamps to other system events. Instead, have Chrome use gettimeofday() on POSIX to fetch microsecond resolution timestamps, and GetLocalTime() on Windows to fetch millisecond resolution timestamps Note: the Windows implementation is adapted from mini_chromium: https://chromium.googlesource.com/chromium/mini_chromium/+/9f129335dbe57ae9a3... BUG= chromium:638472 TEST=tail -F /var/log/chrome/chrome shows microsecond timestamps, like: [1:1:1123/185804.213359:VERBOSE1:zygote_main_linux.cc(599)] ZygoteMain: initializing 2 fork delegates R=dcheng NOPRESUBMIT=true NOTRY=true TBR=mark Review-Url: https://codereview.chromium.org/2528613002 Cr-Commit-Position: refs/heads/master@{#435254} (cherry picked from commit 543a3be1be43bf23fbca2140ad90d18ee7ec6655) Review-Url: https://codereview.chromium.org/2536203005 Cr-Commit-Position: refs/branch-heads/2924@{#314} Cr-Branched-From: 3a87aecc31cd1ffe751dd72c04e5a96a1fc8108a-refs/heads/master@{#433059} [modify] https://crrev.com/689d0f35b7686e94fa928da10126c15ef881cb4b/base/logging.cc
,
Dec 3 2016
,
Feb 6 2017
Verified on build 9202.17.0 |
||||||||
►
Sign in to add a comment |
||||||||
Comment 1 by vapier@google.com
, Aug 17 2016