Opened 5 years ago

Last modified 2 years ago

#15607 needs_revision defect

Tor log dates imprecise

Reported by: atagar Owned by:
Priority: Medium Milestone: Tor: unspecified
Component: Core Tor/Tor Version:
Severity: Normal Keywords: tor-client tor-relay log usability needs-design
Cc: mcs Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

Hi Nick. Tor's log file uses the local timezone and lacks the year in its log file entries...

Apr 06 11:03:39.000 [notice] Tor 0.2.7.0-alpha-dev (git-4247ce99e5d9b7b2) opening new log file.
Apr 06 11:03:39.832 [notice] Tor v0.2.7.0-alpha-dev (git-4247ce99e5d9b7b2) running on Linux with Libevent 2.0.16-stable, OpenSSL 1.0.1 and Zlib 1.2.3.4.
Apr 06 11:03:39.832 [notice] Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning

This is fine, but has meant some hacks for arm which reads the log file to prepopulate that information. For instance, arm pretends the year is always 2012 to ensure log files made on leap years are readable (otherwise February 29th isn't a thing, see #5265).

Feel free to close this as 'no plan to fix' if you'd like. Just thought I'd run this by you to see if iso8601 timestamps or something more complete would be preferable.

Child Tickets

Change History (18)

comment:1 Changed 5 years ago by atagar

Summary: Tor log dates inpreciseTor log dates imprecise

comment:2 Changed 5 years ago by nickm

Milestone: Tor: 0.2.???

comment:3 Changed 4 years ago by rl1987

I did some preliminary work to teach Tor to use RFC 3339 timestamps for logging. See the following branch:

Now there are design decisions to be made!

  1. Currently, my patch prints correct timezone offset only on systems that support gettimeofday(2). On other systems (e.g. Windows) getting timezone offset requires using platform-specific approach. If we fail to, what do we do? Is it okay, as a fallback, to print the local time with zero offset from UTC?
  2. Users may not want to have their timezone information in the logs. Knowing timezone reduces uncertainty about geographic location, which might be dangerous for sensitive use cases. My proposition is to add ForceUTCTimestamps torrc option and to have it be enabled by default. The downside is that it might be confusing to users. Sounds valid?

comment:4 Changed 4 years ago by rl1987

Status: newneeds_information

comment:5 Changed 4 years ago by atagar

Thanks rl1987! Nick, what are your thoughts on this?

comment:6 Changed 4 years ago by nickm

This seems like a breaking change for anything that expected the old format and knew how to parse it.

Also, do we really expect the timezone to chance so often that we need to reformat it every time that we log a message?

comment:7 Changed 4 years ago by rl1987

Status: needs_informationneeds_review

I thought about possible timezone issues and decided not to print it in every entry, even though we lose RFC3339 conformance.

  • https://github.com/rl1987/tor/compare/bug15607_no_tz


comment:8 Changed 4 years ago by atagar

For nyx at least timezones aren't a concern (since I'm running locally, and can figure out what it is). Missing the year is the main trouble.

Thanks for digging into this!

comment:9 Changed 4 years ago by atagar

[ asked on irc... ]
11:18 < rl1987> I guess we're not merging/doing anything about #15607, since we don't want existing nyx to break?

For my part I'm fine with merging. This isn't the first change to break a part of Nyx, it's in need of a rewrite (... and getting one). Nyx was built to be pretty tolerant of things like this so feel free to move forward.

comment:10 Changed 4 years ago by rl1987

18:39 < rl1987> oh, and there was #15607
18:40 < rl1987> maybe we should reach a decision on that?
18:40 -!- cicada [~cicada_33@80.82.64.92] has joined #tor-dev
18:41 < armadev> putting a year in every log line seems like crazy talk
18:41 < armadev> i was always confused about why nyx tried to parse the log 
                 files anyway
18:42 < armadev> i could be convinced about a config option, "make logs 
                 readable by nyx", off by default, and then nyx turns it on
18:42 < armadev> but if nyx is going to do that, maybe it should just listen 
                 for log controller events and be done with it
18:42 -!- cicada [~cicada_33@0001fdfc.user.oftc.net] has quit []
18:42 < armadev> i guess the use case is to present your logs from disk to you, 
                 even before nyx started
18:44 < rl1987> then, wontfix?
18:45 < armadev> rl1987: i haven't read the bug
18:48 < atagar> armadev: 'i was always confused about why nyx tried to parse 
                the log files anyway' => Nyx emits its own log messages, and I 
                read the date because I order the overall log by the 
                timestamps. That, and nyx groups messages by date with a 
                border. Tor lacking the year isn't an overly big whoop, but 
                it's something I need to hack around and introduces errors with 
                edge cases like leap years.
18:49 < armadev> i wonder if tor should put a year at the top of its log when 
                 it opens it?
18:49 < armadev> (is this related?)
18:49 < atagar> Sure, for my purposes think that would do the trick.
18:49 < armadev> i am not against admitting the year
18:49 < armadev> i just don't want it in every line
18:51 < atagar> Understandable. It's very strange that tor omits it (first 
                application logs I've seen that does that), but it makes sense 
                for cutting down on noise if you don't care about long term 
                logging.
18:51 < atagar> Personally I'd opt for emitting the year on stdout but 
                including it in the log file, but just my two cents.
18:52 < atagar> oops, s/emitting/omitting
18:55 < rl1987> atagar, armadev: so, we need to log a full timestamp every time 
                we start a new log file, but log timestamps without year for 
                every regular log entry?
18:57 < rl1987> can we agree on this?
19:02 < armadev> rl1987: works for me. it doesn't even need to be every time we 
                 open a new log file. it could be whatever log line tor puts 
                 into the log file first. i hope there is something like that 
                 already, for existing log files, where tor writes its version 
                 and stuff first.

comment:11 Changed 4 years ago by atagar

Personally I don't think it's a great solution (it's quite a hack), but if this is what Nick and Roger prefer for tor then that's fine.

As mentioned at the end personally I think we should include full timestamps in the log, and omit the year for stdout. This reduces clutter where complete dates are irrelevant, and only includes complete dates where they're potentially useful.

comment:12 in reply to:  3 Changed 4 years ago by cypherpunks

Severity: Normal

Replying to rl1987:

  1. Users may not want to have their timezone information in the logs. Knowing timezone reduces uncertainty about geographic location, which might be dangerous for sensitive use cases. My proposition is to add ForceUTCTimestamps torrc option and to have it be enabled by default. The downside is that it might be confusing to users. Sounds valid?

I opened ticket #18112 regarding this.

comment:13 Changed 4 years ago by mcs

Cc: mcs added

comment:14 Changed 4 years ago by teor

Status: needs_reviewneeds_revision

comment:15 Changed 3 years ago by teor

Milestone: Tor: 0.2.???Tor: 0.3.???

Milestone renamed

comment:16 Changed 3 years ago by nickm

Keywords: tor-03-unspecified-201612 added
Milestone: Tor: 0.3.???Tor: unspecified

Finally admitting that 0.3.??? was a euphemism for Tor: unspecified all along.

comment:17 Changed 2 years ago by nickm

Keywords: tor-03-unspecified-201612 removed

Remove an old triaging keyword.

comment:18 Changed 2 years ago by nickm

Keywords: tor-client tor-relay log usability needs-design added
Note: See TracTickets for help on using tickets.