[tahoe-dev] collective effort to improve logging

[Brian Warner]

> With ISO-8601'ish, UTC timestamps, they would look like this:
> 
> 2007-09-11_20:02:47 [Uninitialized] Stopping factory <foolscap.negotiate.TubConnectorClientFactory object [from z23k6ynh] [to qtjkk6cy] at 0x208e6b0>
> 2007-09-11_20:02:48 [Client] z23k6ynh: 'connected to qtjkk6cy'

I'm happy with all of the data in an 8601 timestamp, but that underscore
makes it really hard for me to read.

What would you think about this:?

 2007-09-11 20:02:48 [Client] z23k6ynh: 'connected to qtjkk6cy'


As for the localtime+tz form:

> 070911-14:02:48-06 [Client] z23k6ynh: 'connected to qtjkk6cy'

I find that hard to read too.. the standard twisted log format makes the
timezone a bit easier to spot:

 2007/09/17 12:47 -0700 [twisted.internet.protocol.Factory] count 24134

but of course I'd prefer to have the seconds in there.

On the whole, I find that (historically) I've had more cause to compare
events in a log file to events in meatspace, and thus localtime tends to be
more immediately useful to me. But most of that experience is drawn from a
less distributed world than this represents, and I anticipate comparing
multi-timezone events frequently in the coming months. Also, not losing
information is my highest priority, so localtime w/o a timezone is not good.
I'd prefer relatively compact UTC (2007-09-11 20:02:48) to more verbose
localtime+tz (2007-09-11 20:02:48 -0700).

The DJB approach is tai64 at the start of each line, and use an external tool
to convert it into whatever you want. While we don't need picosecond or
exasecond resolution (64bits before the binary point, 32bits after, so it has
a range of 18e18s, and resolution of 233e-12s), the idea is sound, and
connects well with my thoughts that we're doing ourselves a disservice by
limiting our logfiles to human-readable anyways:

 @4000000046eeac0b074a2854 [Client] z23k6ynh: 'connected to qtjkk6cy'

catting the logfile through /usr/bin/tai64nlocal results in:

 2007-09-17 09:32:01.122300500 [Client] z23k6ynh: 'connected to qtjkk6cy'

Or of course /usr/bin/tai64n leaves it in UTC.


cheers,
 -Brian