Ticket #867 (closed enhancement: fixed)

Opened 6 years ago

Last modified 4 years ago

Improvements to logging timestamp

Reported by: itamarst Owned by: therve
Priority: highest Milestone:
Component: core Keywords:
Cc: exarkun, itamarst, anthony, jknight, therve, jerub Branch:
Author: Launchpad Bug:

Description


Attachments

867_log.diff Download (3.1 KB) - added by therve 4 years ago.

Change History

Changed 6 years ago by itamarst

Anthony wanted to add seconds timestamps, and I agree this is a good idea. His
suggestion was using ISO 8601 timestamps as a standard format
(http://www.cl.cam.ac.uk/~mgk25/iso-time.html).

With seconds and local timezone, format would be:
2005-01-20T11:30:20-0500

For comparision, current format is:
2005/01/20 11:32 EST
or sometimes (on Windows):
2005/01/20 11:32 Eastern Standard Time

so this would be 4 extra characters per message (on non-broken platforms).
Simply adding seconds to current format is 3 extra characters, so I think that's
reasonable.

This solves: 
1. Lack of resolution in current format.
2. Really really really long timezone names on Windows.
3. Ambiguity of timezone regarding daylight savings time.

Changed 6 years ago by itamarst

There's code for doing ISO 8601 in xml.utils.iso8601. This is going to be sucky
and slow, I can tell already, until we make twisted have efficient "get the
current second" code  or something :(

Changed 6 years ago by jknight

1) ISO8601 format is usually spelled without a T in the middle when meant 
for human readability. That is, an ISO8601 date and an ISO8601 time, 
separated by a space, instead of an ISO8601 combined datetime. 
"2005-01-20 11:30:20-0500".

2) It's too bad %z in strftime isn't standard (or else that python doesn't 
just implement its own strftime instead of using the OS's), because then a 
good format would be "%Y-%m-%D %H:%M:%S%z", and would allow the code and 
behavior to not be changed, just the default format string.

Changed 4 years ago by therve

  • cc therve added
  • keywords review added

It seems the timezone problem has already been fixed. Attached a patch adding seconds and changing date separators to '-'.

Changed 4 years ago by exarkun

Still dislike this solution. The real problem is that setting the format from outside Twisted is hard. That's what should be fixed.

Changed 4 years ago by therve

I can't agree more. But I thought it was beyond the scope of this ticket, which just talks about the default format used.

The best way for me to customize the format is to subclass FileLogObserver and to make t.p.log uses it: very easy if you don't use twistd. The real problem is setting the format inside twistd :).

Changed 4 years ago by jml

  • priority changed from normal to highest

Changed 4 years ago by jerub

  • keywords review removed
  • owner changed from itamarst to therve

These strings are almost but not quite ISO8601.

"2001-02-02 23:05:06 -0500"
vs.
"2001-02-02 23:05:06-0500"

The docstring says: "human-readable string", update this to say, "ISO8601 string", and and please update the strings to be valid ISO8601 strings, then you may merge.

Changed 4 years ago by therve

Changed 4 years ago by therve

  • keywords review added

OK I updated the patch according to your comments. I tried to be more explicit in the docstring, and changed the timestamp position (note that's still not ISO8601, as jknight pointed out).

Changed 4 years ago by jerub

  • keywords review removed
  • cc jerub added

Facinating. I always considered the 'T' optional, but according to the sources I just read, it's valid to omit it, but you change the meaning. When you omit the 'T' and use a ' ' instead, you're actually putting an ISO8601 date next to an ISO8601 time, which isn't the same thing as having an ISO8601 datetime. How schizophrenic.

Oh well, mx.Datetime.ISO.ParseAny() pulls it in fine, so that's good enough for me.

I'm satisfied with this patch, please commit to trunk. Please make a note in your commit message intended for the release manager what the old format was and what the new format is. This will be important information for the release notes (someone, somewhere, might rely on the old timestamp format).

Changed 4 years ago by therve

  • owner therve deleted

Changed 4 years ago by exarkun

  • priority changed from highest to normal

I think this basically addresses #880 as well. However, I think the nasty crud in conch should be removed as part of this change as well (so I am not applying the patch now).

I'll probably get to the conch stuff soon, but if anyone feels like beating me to it...

Changed 4 years ago by therve

For the conch stuff, you're talking about _LogTimeFormatMixin in test_ssh ? If it's that I can update the patch with its removal, it doesn't seem to have to much impact.

Changed 4 years ago by exarkun

Yea, that's what I mean.

Jerub has been threatening to actually fix this issue, though, by making it possible to configure logging on the twistd command line. If he makes makes any progress on that it might be a good idea to include this change as a part of that one. I generally like to keep changes as separate and tiny as possible, but with actual configurability, there wouldn't even need to be a change to the default logging format.

Changed 4 years ago by therve

  • keywords review added
  • priority changed from normal to highest

As I didn't get news from something into twistd, I went on and cleaned some stuff.

Ready to review in improve-log-867.

Changed 4 years ago by exarkun

  • owner set to therve
  • keywords review removed

I reflowed the part of the formatTime docstring which talks about ISO8601, since it looked wierd.

Everything else in this branch looks great. Please merge it.

Changed 4 years ago by therve

  • status changed from new to closed
  • resolution set to fixed

(In [19485]) Merge improve-log-867

Author: therve Reviewer: exarkun Fixes #867

Add seconds to default log format, for using ISO8601 date and an ISO8601 time. In the process some cleanups have been made.

People relying on the old default format (to parse log for example) should be warned.

Note: See TracTickets for help on using tickets.