Opened 8 years ago

Closed 8 years ago

#6736 closed defect (fixed)

Tor is a bit loud at startup

Reported by: nickm Owned by:
Priority: Medium Milestone: Tor: 0.2.4.x-final
Component: Core Tor/Tor Version:
Severity: Keywords: tor-client
Cc: Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

Here is a typical startup log:

Aug 30 02:06:48.496 [notice] Tor v0.2.4.0-alpha-dev (git-661bd3fe714f0c99) running on Darwin.
Aug 30 02:06:48.496 [notice] Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning
Aug 30 02:06:48.496 [notice] This version is not a stable Tor release. Expect more bugs than usual.
Aug 30 02:06:48.496 [notice] Configuration file "/usr/local/etc/tor/torrc" not present, using reasonable defaults.
Aug 30 02:06:48.499 [notice] Initialized libevent version 2.1.1-alpha-dev using method kqueue. Good.
Aug 30 02:06:48.499 [notice] Opening Socks listener on 127.0.0.1:9050
Aug 30 02:06:48.000 [notice] No AES engine found; using AES_* functions.
Aug 30 02:06:48.000 [notice] This version of OpenSSL has a slow implementation of counter mode; not using it.
Aug 30 02:06:48.000 [notice] OpenSSL OpenSSL 0.9.8r 8 Feb 2011 looks like version 0.9.8m or later; I will try SSL_OP to enable renegotiation
Aug 30 02:06:48.000 [notice] Reloaded microdescriptor cache.  Found 0 descriptors.
Aug 30 02:06:48.000 [notice] I learned some more directory information, but not enough to build a circuit: We have no usable consensus.
Aug 30 02:06:49.000 [notice] Bootstrapped 5%: Connecting to directory server.
Aug 30 02:06:49.000 [notice] Heartbeat: Tor's uptime is 0:00 hours, with 1 circuits open. I've sent 0 kB and received 0 kB.
Aug 30 02:06:49.000 [notice] Bootstrapped 10%: Finishing handshake with directory server.
Aug 30 02:06:49.000 [notice] We weren't able to find support for all of the TLS ciphersuites that we wanted to advertise. This won't hurt security, but it might make your Tor (if run as a client) more easy for censors to block.
Aug 30 02:06:49.000 [notice] To correct this, use a more recent OpenSSL, built without disabling any secure ciphers or features.
Aug 30 02:06:50.000 [notice] Bootstrapped 15%: Establishing an encrypted directory connection.
Aug 30 02:06:50.000 [notice] Bootstrapped 20%: Asking for networkstatus consensus.
Aug 30 02:06:50.000 [notice] Bootstrapped 25%: Loading networkstatus consensus.
Aug 30 02:06:51.000 [notice] I learned some more directory information, but not enough to build a circuit: We have no usable consensus.
Aug 30 02:06:52.000 [notice] Bootstrapped 40%: Loading authority key certs.
Aug 30 02:06:53.000 [notice] Bootstrapped 45%: Asking for relay descriptors.
Aug 30 02:06:53.000 [notice] I learned some more directory information, but not enough to build a circuit: We have only 0/3067 usable microdescriptors.
Aug 30 02:06:55.000 [notice] We now have enough directory information to build circuits.
Aug 30 02:06:55.000 [notice] Bootstrapped 80%: Connecting to the Tor network.
Aug 30 02:06:55.000 [notice] Bootstrapped 85%: Finishing handshake with first hop.
Aug 30 02:06:55.000 [notice] Bootstrapped 90%: Establishing a Tor circuit.
Aug 30 02:06:57.000 [notice] Tor has successfully opened a circuit. Looks like client functionality is working.
Aug 30 02:06:57.000 [notice] Bootstrapped 100%: Done.

That's 29 lines to say "everything's okay."

Child Tickets

TicketStatusOwnerSummaryComponent
#6758closedNo need to print first heartbeat messageCore Tor/Tor
#6759closedDon't tell user about reloading microdesc cache at startupCore Tor/Tor
#6760closedQuiet initial "learned some more directory information" log messageCore Tor/Tor

Change History (12)

comment:1 Changed 8 years ago by nickm

(Actually, it's 29 lines to say "everything's ok, but maybe use OpenSSL 1.0.x". Having too many log messages hides the important ones. :/ )

comment:2 Changed 8 years ago by asn

Arguably, lines:

Aug 30 02:06:48.000 [notice] No AES engine found; using AES_* functions.

and

This version of OpenSSL has a slow implementation of counter mode; not using it.

can be demoted to 'info'. They are just informative messages.

Another - more extreme - change would be to stop issuing "{libevent,openssl,tor} initialized" messages as they initialize, and just send a single message with their versions after they have all initialized. However, this is kind of messy to implement and if something breaks before that single message then the user might not have the version information he needs.

comment:3 Changed 8 years ago by nickm

Status: newneeds_review

See branch "quiet_lib_versions" for some changes I like.

comment:4 Changed 8 years ago by asn

Aug 30 02:06:57.000 [notice] Tor has successfully opened a circuit. Looks like client functionality is working.
can also be considered redundant since it is followed by
Aug 30 02:06:57.000 [notice] Bootstrapped 100%: Done.

comment:5 Changed 8 years ago by asn

quiet_lib_versions looks like this:
[notice] Tor v0.2.4.0-alpha-dev (git-96637771846351be) running on Linux with Libevent 2.0.19-stable and OpenSSL 1.0.1c 10 May 2012

The OpenSSL string is a bit verbose. The date on its end might confuse people into thinking that it's the date that Tor was released or something. Maybe we should enclose that message into quotes (and also the libevent message)?

Also, maybe add a period in the end of the log message.

comment:6 Changed 8 years ago by nickm

Status: needs_reviewnew

Tweaked and merged that branch. Let's look for more stuff to quiet, if we can find any.

comment:7 Changed 8 years ago by arma

For comparison, here we are now:

Sep 10 03:06:05.338 [notice] Tor v0.2.4.1-alpha-dev (git-139a81c96d4af2f5) running on Linux with Libevent 2.0.19-stable and OpenSSL 1.0.1c.
Sep 10 03:06:05.338 [notice] Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning
Sep 10 03:06:05.338 [notice] This version is not a stable Tor release. Expect more bugs than usual.
Sep 10 03:06:05.338 [notice] Configuration file "/usr/local/etc/tor/torrc" not present, using reasonable defaults.
Sep 10 03:06:05.341 [notice] Opening Socks listener on 127.0.0.1:9050
Sep 10 03:06:05.000 [notice] Parsing GEOIP file /usr/local/share/tor/geoip.
Sep 10 03:06:05.000 [notice] This version of OpenSSL has a known-good EVP counter-mode implementation. Using it.
Sep 10 03:06:05.000 [notice] We now have enough directory information to build circuits.
Sep 10 03:06:05.000 [notice] Bootstrapped 80%: Connecting to the Tor network.
Sep 10 03:06:06.000 [notice] Bootstrapped 85%: Finishing handshake with first hop.
Sep 10 03:06:07.000 [notice] Bootstrapped 90%: Establishing a Tor circuit.
Sep 10 03:06:12.000 [notice] Tor has successfully opened a circuit. Looks like client functionality is working.
Sep 10 03:06:12.000 [notice] Bootstrapped 100%: Done.

I don't think I care that I have a "known-good EVP counter-mode implementation", do I?

comment:8 in reply to:  7 ; Changed 8 years ago by nickm

Replying to arma:

I don't think I care that I have a "known-good EVP counter-mode implementation", do I?

You don't. Fixed in 7ff5c3f2322217a0fe5d24ba26a0192106594e0f.

arma, what do you think of asn's note above about the "successfully opened a circuit" message?

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

Replying to nickm:

arma, what do you think of asn's note above about the "successfully opened a circuit" message?

I think

Sep 10 03:06:12.000 [notice] Tor has successfully opened a circuit. Looks like client functionality is working.
Sep 10 03:06:12.000 [notice] Bootstrapped 100%: Done.

are probably two of the most important startup messages, in that we've trained a lot of people to look for them. We should keep them both if we can.

comment:10 Changed 8 years ago by nickm

Keywords: tor-client added

comment:11 Changed 8 years ago by nickm

Component: Tor ClientTor

comment:12 Changed 8 years ago by nickm

Resolution: fixed
Status: newclosed

I think we did okay here. Please reopen or make new tickets if there are more ideas for quieting startup down.

Note: See TracTickets for help on using tickets.