CODEWITHSUNDEEP
google-chrome
P.T.
P.T.

Reputation: 25177

What format is the log prefix in the chrome_debug.log?

I have configured google-chrome to dump a debug log to chrome_debug.log in the user-data-dir.

This is handy for debugging some of our more obtuse browser problems. However, I'm having some timeout issues, so I'm trying to figure out what the prefix on log lines means. Since this log is from today (June 11th), I'm guessing the "0611" part is today's date. I'm guessing the "/053512" after that is a timestamp in seconds?

[296:296:0611/053512:VERBOSE1:password_store_factory.cc(276)] Password storage detected desktop environment: (unknown)
[296:296:0611/053512:WARNING:password_store_factory.cc(322)] Using basic (unencrypted) store for password storage. See http://code.google.com/p/chromium/wiki/LinuxPasswordStorage for more information about password storage options.
[296:296:0611/053512:VERBOSE1:render_process_host_impl.cc(687)] Mojo Channel is enabled on host
[6:6:0611/053512:VERBOSE1:sandbox_linux.cc(68)] Activated seccomp-bpf sandbox for process type: renderer.
[6:6:0611/053512:VERBOSE1:child_thread_impl.cc(321)] Mojo is enabled on child
[6:6:0611/053527:INFO:child_thread_impl.cc(725)] ChildThreadImpl::EnsureConnected()
[296:318:0611/053611:VERBOSE1:chrome_browser_main_posix.cc(216)] Handling shutdown for signal 15.

Even better would be a pointer to where the code is that generates the prefix. Since I suspect it changes (I'm running chrome v43.0.x, on Debian Linux).

The doc says:

The boilerplate values enclosed by brackets on each line are in the format:

[process_id:thread_id:ticks_in_microseconds:log_level:file_name(line_number)]

But "0611/053512" is pretty clearly not "ticks_in_microseconds".

Upvotes: 6

Views: 1643

Answers (1)

P.T.
P.T.

Reputation: 25177

Chrome's base/logging.cc in LogMessage::Init defines the content of the log prefix from chrome_debug.log. The timestamp portion is defined by:

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 thats: mmDD/HHMMSS (month, day, /, hour, minute, second).

Thus the difference between the two timestamps "0611/053512" and "0611/053611" is not 99 seconds, but 59 seconds.

Upvotes: 6

Related Questions