Opened 3 years ago

Last modified 4 weeks ago

#10059 new defect

capture tor log messages before control connection is opened

Reported by: mcs Owned by: nickm
Priority: Medium Milestone: Tor: 0.3.???
Component: Core Tor/Tor Version: Tor: unspecified
Severity: Normal Keywords: tbb-usability, extdev-interview
Cc: brade, mikeperry, atagar, karsten Actual Points:
Parent ID: #9675 Points:
Reviewer: Sponsor:

Description

While working on ticket #9675, Kathy Brade and I discovered that the tor log warnings regarding clock skew are sometimes generated very early as tor starts up. Unfortunately, there is a known problem in Tor Launcher where tor log messages are not captured until Tor Launcher is able to connect to the control port and issue a SETEVENTS command (the Mozilla process control APIs do not provide a way to capture stdout or stderr).

One solution is for tor to provide a way to retrieve old log messages (e.g., a new getinfo command) or otherwise provide a way to capture messages that are generated before a control connection is opened. Another option for this specific scenario would be to modify tor to ensure that clock skew is always reported via the status/bootstrap-phase mechanism.

Child Tickets

TicketSummaryOwner
#6938Log early log messages to log files
#12501"Tor unexpectedly exited" if there is a wrong line in torrcbrade

Change History (13)

comment:1 Changed 3 years ago by mcs

  • Parent ID set to #9675

comment:2 Changed 3 years ago by arma

  • Cc atagar added

I think the way arm et al handle this is by reading Tor's stdout until it switches over to the control protocol.

Damian, can you clarify how arm does it and whether you're satisfied with that?

comment:3 follow-up: Changed 3 years ago by nickm

I think the way arm et al handle this is by reading Tor's stdout until it switches over to the control protocol.

According to mcs above, "the Mozilla process control APIs do not provide a way to capture stdout or stderr".

I'd agree that the stdout solution is inelegant, and I'd be happy to consider something better. It wouldn't be too hard to cache log messages that happen before the original log configuration, or the original controller connection. Perhaps it should be controlled by a command-line option; perhaps also there should be an upper-limit on the buffer size.

Another related question to consider: what to do with log messages if Tor dies before a controller connection can be made?

comment:4 in reply to: ↑ 3 Changed 3 years ago by mcs

Replying to nickm:

Another related question to consider: what to do with log messages if Tor dies before a controller connection can be made?

This exact issue just came up in #10416 (tor fails to start because it cannot open torrc). Maybe we do need to find a way for Tor Launcher to capture stdout.

comment:5 Changed 3 years ago by mcs

There is a replacement for Mozilla's nsIProcess API that is used by the Enigmail Thunderbird extension. It supports useful features like setting the working directory and capturing stdout. See:

http://hg.mozilla.org/ipccode/file/b22a621afdc5/modules

And newer version here:

http://sourceforge.net/p/enigmail/source/ci/master/tree/ipc/modules/

We could incorporate this module into Tor Launcher. It is entirely dependent on js-ctypes though, which I know Mike has been trying to eliminate/avoid (see #6152).

comment:6 follow-up: Changed 3 years ago by lunar

Probably naive idea: is there a way to redirect these early error messages to a file in Data/Tor? It could just then be read in case of errors…

comment:7 in reply to: ↑ 6 Changed 3 years ago by mcs

Replying to lunar:

Probably naive idea: is there a way to redirect these early error messages to a file in Data/Tor? It could just then be read in case of errors…

I don't know if there are privacy or performance concerns related to sending the tor log messages to a file. We could, assuming tor supports it, disable the file-based logging after Tor Launcher is able to successfully connect to the control port.

comment:8 Changed 3 years ago by karsten

  • Cc karsten added

comment:9 follow-up: Changed 3 years ago by nickm

I'm okay with doing an in-tor solution for this if you decide one is necessary; just let me know. It would probably involve adding a log type that lets you store the last N kb of log messages in a queue, and later query them via the control port.

comment:10 Changed 3 years ago by mikeperry

  • Keywords tbb-usability extdev-interview added

comment:11 Changed 3 years ago by nickm

  • Milestone set to Tor: 0.2.???

comment:12 in reply to: ↑ 9 Changed 11 months ago by mcs

  • Severity set to Normal

Replying to nickm:

I'm okay with doing an in-tor solution for this if you decide one is necessary; just let me know. It would probably involve adding a log type that lets you store the last N kb of log messages in a queue, and later query them via the control port.

(I am revisiting some old tickets today.) For Tor Launcher, it would be convenient to have a mechanism in tor such as the one you described. One tricky thing is that we would want to be sure Tor Launcher receives the entire, correct stream of messages (without duplicates or gaps), so we would need to figure out how to merge the queued messages with the ones we receive in response to SETEVENTS NOTICE WARN ERR. I am not sure how to do that unless tor assigns a sequence number or something similar to each message. Or it might work for tor to provide an option to send the queued messages as events as soon as the SETEVENTS command is received.

comment:13 Changed 4 weeks ago by teor

  • Milestone changed from Tor: 0.2.??? to Tor: 0.3.???

Milestone renamed

Note: See TracTickets for help on using tickets.