Opened 9 months ago

#29621 new defect

Systemd Tor service starts too early

Reported by: tomreyn Owned by:
Priority: Low Milestone:
Component: Core Tor Version: Tor: 0.3.5.8
Severity: Minor Keywords: systemd packaging
Cc: Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

Defect description:
Tor 0.3.5.8 (.deb packages from deb.torproject.org) on Ubuntu 18.04 amd64 (systemd), starts too early during the boot process, (reproducibly) resulting in "Problem bootstrapping" messages:

$ journalctl --utc -b | sed -e 's/'$HOSTNAME'/myhostname/' -e 's/ Tor[\[0-9\]*]/ Tor[1234]/' | grep 'myhostname Tor'
Feb 28 17:17:42 myhostname Tor[1234]: Tor 0.3.5.8 running on Linux with Libevent 2.1.8-stable, OpenSSL 1.1.0g, Zlib 1.2.11, Liblzma 5.2.2, and Libzstd 1.3.3.
Feb 28 17:17:42 myhostname Tor[1234]: Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning
Feb 28 17:17:42 myhostname Tor[1234]: Read configuration file "/usr/share/tor/tor-service-defaults-torrc".
Feb 28 17:17:42 myhostname Tor[1234]: Read configuration file "/etc/tor/torrc".
Feb 28 17:17:42 myhostname Tor[1234]: Opening Socks listener on 127.0.0.1:9050
Feb 28 17:17:42 myhostname Tor[1234]: Opened Socks listener on 127.0.0.1:9050
Feb 28 17:17:42 myhostname Tor[1234]: Parsing GEOIP IPv4 file /usr/share/tor/geoip.
Feb 28 17:17:42 myhostname Tor[1234]: Parsing GEOIP IPv6 file /usr/share/tor/geoip6.
Feb 28 17:17:42 myhostname Tor[1234]: Bootstrapped 0%: Starting
Feb 28 17:17:43 myhostname Tor[1234]: Starting with guard context "default"
Feb 28 17:17:43 myhostname Tor[1234]: Signaled readiness to systemd
Feb 28 17:17:43 myhostname Tor[1234]: Problem bootstrapping. Stuck at 0%: Starting. (Network is unreachable; NOROUTE; count 1; recommendation warn; host A59B27226496443A93D25E8D87BFCB8ADEDB4862 at 51.75.125.233:9001)
Feb 28 17:17:43 myhostname Tor[1234]: Opening Socks listener on /run/tor/socks
Feb 28 17:17:43 myhostname Tor[1234]: Opened Socks listener on /run/tor/socks
Feb 28 17:17:43 myhostname Tor[1234]: Opening Control listener on /run/tor/control
Feb 28 17:17:43 myhostname Tor[1234]: Opened Control listener on /run/tor/control
Feb 28 17:17:43 myhostname Tor[1234]: Bootstrapped 5%: Connecting to directory server
Feb 28 17:17:43 myhostname Tor[1234]: Problem bootstrapping. Stuck at 5%: Connecting to directory server. (Network is unreachable; NOROUTE; count 2; recommendation warn; host 617314F0CD8B8EA76B4963AC6C6BA3773DA63594 at 144.76.91.135:9001)
Feb 28 17:17:43 myhostname Tor[1234]: Problem bootstrapping. Stuck at 5%: Connecting to directory server. (Network is unreachable; NOROUTE; count 3; recommendation warn; host A0F39D32028CEC7F35419E9570401DE15B1B4564 at 5.196.58.96:9001)
Feb 28 17:17:44 myhostname Tor[1234]: Problem bootstrapping. Stuck at 5%: Connecting to directory server. (Network is unreachable; NOROUTE; count 4; recommendation warn; host BCC9FA5994200032E9CD04866B823B6D929F22A8 at 78.31.65.92:443)
Feb 28 17:17:45 myhostname Tor[1234]: Bootstrapped 10%: Finishing handshake with directory server
Feb 28 17:17:45 myhostname Tor[1234]: Bootstrapped 80%: Connecting to the Tor network
Feb 28 17:17:45 myhostname Tor[1234]: Bootstrapped 90%: Establishing a Tor circuit
Feb 28 17:17:47 myhostname Tor[1234]: Bootstrapped 100%: Done

Impact:
As seen, Tor does finally bootstrap successfully, and functionality is not impacted.

Correction:
This issue appears to be caused by imperfect service dependencies as set in /lib/systemd/system/tor@.service and /lib/systemd/system/tor@…:

[Unit]
After=network.target nss-lookup.target

My interpretation of the systemd documentation is that this should correctly say:

[Unit]
After=network-online.target nss-lookup.target
Want=network-online.target nss-lookup.target

I suspect that using "network-online.target" (instead of "network.target") may also allow for removing the "nss-lookup.target" dependency, but have not attempted to verify this.

Related:

Child Tickets

Change History (0)

Note: See TracTickets for help on using tickets.