use consistent time stamps in logging

[zooko]

Brian:

Would it be okay if I changed flogtool dump and flogtool web-viewer to use the ISO 8601'ish, UTC, format that we earlier agreed and and that is implemented in

​http://allmydata.org/trac/tahoe/browser/src/allmydata/node.py#L29

Currently I'm trying to match two logs, one of which is in dump format and one of which is in web-viewer format, and I can't find any matching timestamps. The timestamps don't have any time zone information attached to them, which makes me think that they must be in UTC, but I'm not sure.

Examples:

from the dump:

oy2wi53k 1204167662.092443: helper: upload_chk query for SI fxka6q4pfenkvchyh2z4xkg5xa
oy2wi53k 1204167662.0932679: doing a quick check+UEBfetch
g5rdi5te 1204167662.096379: storage: slot_readv n5cbdwdbi3bec6opkmvnd6hhdm []
g5rdi5te 1204167662.0970781: returning shares [1]

from the web-view:

• 17:52:32 0.7390 [26722]: AssistedUploader starting
  • 17:52:32 0.7390 [26724]: contacting helper..
  • 17:52:32 0.9500 [26725]: helper says we need to upload
  • 17:52:33 0.5810 [26731]: upload finished, building readcap

!>>> pyutil.time_format.iso_utc(1204167662.092443) '2008-02-28_03:01:02.092443'

So there's either a UTC-vs.-localtime problem here, or else I'm looking at logs from two different times. Anyway, I'll stop posting my debugging notes in this ticket now. ;-)

assigning to Brian with the intent that he will answer the "yea/nay" question and assign it back to me

[zooko]

escape from wiki formatting

[zooko]

I think Brian said "Okay" to me about this issue on IRC, so assigning it back to myself...

[warner]

Hm. I am often frustrated when looking at a log file and trying to figure out whether this is the operation that I just did ten minutes ago, or if it is from last night, and the eight-hour PST offset is usually almost exactly the difference between these two. I always waste a couple of minutes trying to remember what my offset is and then mentally applying the math to each timestamp to compensate.

While I understand the unambiguosity-value in a UTC timestamp, I almost never want to see it in that format. So I'll accept and apply a foolscap patch to do this, but I'll be happier with one that adds a --utc option to enable this, and which does localtime (with a suitable "-0800" suffix) by default. For the web-viewer, I'd suggest a command-line switch which could then be overridden with a ?timezone=utc or timezone=local query arg.

[zooko]

"Hm. I am often frustrated when looking at a log file and trying to figure out whether this is the operation that I just did ten minutes ago, or if it is from last night, and the eight-hour PST offset is usually almost exactly the difference between these two."

So apparently you usually look at log files from computers in the same time zone as yourself. Hopefully as Tahoe spreads, you will more and more frequently look at log files from computers running in other time zones. Personally, I already have this situation, as many of the Tahoe nodes that I want to examine are not in my timezone.

In any case, the important thing is that the timezone is unambiguous, which means either it is required to be always UTC, or it has a timezone specifier at the end.

Then people who have nothing better to do can argue about what the default value should be. (Just kidding. You get to choose because you're the authority on foolscap.)

[warner]

let's move this one over to the foolscap trac, ​http://foolscap.lothar.com/trac

[zooko]

​http://foolscap.lothar.com/trac/ticket/90 # timestamps: formatting and timezones

[zooko]

moved to foolscap, so marked as wontfix here.