Opened 8 years ago

Closed 8 years ago

#5069 closed defect (fixed)

obfsproxy log file has no timestamps

Reported by: arma Owned by: asn
Priority: Medium Milestone:
Component: Archived/Obfsproxy Version:
Severity: Keywords:
Cc: Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

My logfile so far says

Brand new obfsproxy log:
[info] 76.99.61.6:39262 (obfs2): trying to connect to 127.0.0.1:9009

When did each of those lines occur?

Child Tickets

Attachments (5)

0001-Add-timestamps-to-log-messages.patch (1.0 KB) - added by karsten 8 years ago.
Patch that adds timestamps to log messages
0001-Add-timestamps-to-log-messages.2.patch (1.1 KB) - added by karsten 8 years ago.
Patch that adds timestamps to log messages, updated 2012-02-10T10:10:10Z
0001-Add-a-timestamp-to-the-first-log-message.patch (865 bytes) - added by karsten 8 years ago.
Patch to add a timestamp to the first log message
task-5069-patches.tar (10.0 KB) - added by karsten 8 years ago.
Improved patches to add timestamps to logs
0001-Fix-first-log-line.patch (758 bytes) - added by karsten 8 years ago.
Fix first log line.

Download all attachments as: .zip

Change History (18)

Changed 8 years ago by karsten

Patch that adds timestamps to log messages

comment:1 Changed 8 years ago by karsten

Status: newneeds_review

Please find the patch attached to this ticket.

comment:2 Changed 8 years ago by arma

It should be <time.h>, not "time.h". <> is for system headers, and "" is for your own headers.

When you call strftime, you should say sizeof(ts) rather than 21. Otherwise you're asking for troubles later when somebody changes one 21 but not the other.

Why do you have a T in the middle of the timestamp, and a Z at the end? The Z might be for Zulu I guess?

In general I'm alarmed by the lack of autoconf lines to search for <time.h> vs <sys/time.h>, and by the C++ approach of declaring variables in the middle of code -- if obfsproxy's build process had more warnings enabled it would warn a lot.

Changed 8 years ago by karsten

Patch that adds timestamps to log messages, updated 2012-02-10T10:10:10Z

comment:3 in reply to:  2 Changed 8 years ago by karsten

Replying to arma:

It should be <time.h>, not "time.h". <> is for system headers, and "" is for your own headers.

Fixed.

When you call strftime, you should say sizeof(ts) rather than 21. Otherwise you're asking for troubles later when somebody changes one 21 but not the other.

Fixed.

Why do you have a T in the middle of the timestamp, and a Z at the end? The Z might be for Zulu I guess?

T is the delimiter. Wikipedia says there's a delimiter in ISO 8601. I think if we want to use the Z we should also use the T. Z is Zulu time.

See new patch attached to this ticket. Thanks for the code review!

Changed 8 years ago by karsten

Patch to add a timestamp to the first log message

comment:4 Changed 8 years ago by karsten

Here's another patch to add a timestamp to the first log message. I think the purpose of writing "Brand new obfsproxy log:" was to see if writing to the log file works. I reduced that to writing a single newline and added a log message to say that obfsproxy started. (I need the start time for the stats script to know when a 24-hour stats period starts.)

comment:5 in reply to:  4 Changed 8 years ago by asn

Replying to karsten:

Here's another patch to add a timestamp to the first log message. I think the purpose of writing "Brand new obfsproxy log:" was to see if writing to the log file works. I reduced that to writing a single newline and added a log message to say that obfsproxy started. (I need the start time for the stats script to know when a 24-hour stats period starts.)

The "Brand new obfsproxy log:" string was written as a delimiter to separate log instances from each other.

I think that open() with the O_WRONLY flag (open_and_set_obfsproxy_logfile()) should fail if you have no write permissions for the file.

I think we can remove the write_logfile_prologue() function in its entirety, and simply add a:
log_info("\nStarting.") after setting the logging_method, like you did. How do you feel about this?

comment:6 Changed 8 years ago by asn

Just mentioning that I think we decided that the final format of the timestamp will be the same as tor's. That is 'yyyy-mm-dd hh:mm:ss' in local time.

comment:7 Changed 8 years ago by asn

Status: needs_reviewneeds_revision

Some other notes, we should pump up the buffer size (bytes are cheap, 10000CE is close), put the buffer size in a preprocessor definition, check the strftime() return value, and do comment:5.

Changed 8 years ago by karsten

Attachment: task-5069-patches.tar added

Improved patches to add timestamps to logs

comment:8 Changed 8 years ago by karsten

Please see the attached tarball. Feel free to squash before merging.

I fixed everything except the Y10K thing. Bytes are cheap, but do we really want to document that we're using 20 bytes for the ISO timestamp, because of YYYYY? I decided against it.

comment:9 in reply to:  8 Changed 8 years ago by asn

Status: needs_revisionneeds_review

Replying to karsten:

Please see the attached tarball. Feel free to squash before merging.

Thanks!

I fixed everything except the Y10K thing. Bytes are cheap, but do we really want to document that we're using 20 bytes for the ISO timestamp, because of YYYYY? I decided against it.

Fair enough. I was thinking of bumping up the buffer size to a something like '32', not necessarily just by a single byte. In any case, if it works for the next 7000+ years, it should be fine.

Putting this in needs_review.

comment:10 Changed 8 years ago by nickm

Resolution: fixed
Status: needs_reviewclosed

Looks ok, squashed and merged.

Changed 8 years ago by karsten

Fix first log line.

comment:11 Changed 8 years ago by karsten

Resolution: fixed
Status: closedreopened

Linus found that the first log line looks quite funny now:

2012-02-11 09:01:28 [info]
Starting.

Oops. Here's a patch.

comment:12 Changed 8 years ago by Sebastian

Status: reopenedneeds_review

comment:13 Changed 8 years ago by nickm

Resolution: fixed
Status: needs_reviewclosed

merged

Note: See TracTickets for help on using tickets.