Opened 4 years ago

Closed 4 years ago

Last modified 3 years ago

#16398 closed defect (fixed)

systemd startup timeout on v0.2.6.9 (git-145b2587d1269af4)

Reported by: maxxer Owned by:
Priority: High Milestone:
Component: Core Tor/Tor Version: Tor: 0.2.6.9
Severity: Normal Keywords: systemd
Cc: io@… Actual Points:
Parent ID: Points:
Reviewer: Sponsor:

Description

I'm using experimental builds on Ubuntu 15.04. Since the last update systemd is looping forever in restarting Tor, because it detects a start timeout:

Jun 18 12:26:27 dharma systemd[1]: Starting Anonymizing overlay network for TCP...
Jun 18 12:26:27 dharma tor[11487]: Jun 18 12:26:27.321 [notice] Tor v0.2.6.9 (git-145b2587d1269af4) running on Linux with Libevent 2.0.21-stable, OpenSSL 1.0.1f and Zlib 1.2.8.
Jun 18 12:26:27 dharma tor[11487]: Jun 18 12:26:27.321 [notice] Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning
Jun 18 12:26:27 dharma tor[11487]: Jun 18 12:26:27.321 [notice] Read configuration file "/usr/share/tor/tor-service-defaults-torrc".
Jun 18 12:26:27 dharma tor[11487]: Jun 18 12:26:27.321 [notice] Read configuration file "/etc/tor/torrc".
Jun 18 12:26:27 dharma tor[11487]: Configuration was valid
Jun 18 12:26:27 dharma tor[11490]: Jun 18 12:26:27.393 [notice] Tor v0.2.6.9 (git-145b2587d1269af4) running on Linux with Libevent 2.0.21-stable, OpenSSL 1.0.1f and Zlib 1.2.8.
Jun 18 12:26:27 dharma tor[11490]: Jun 18 12:26:27.393 [notice] Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning
Jun 18 12:26:27 dharma tor[11490]: Jun 18 12:26:27.393 [notice] Read configuration file "/usr/share/tor/tor-service-defaults-torrc".
Jun 18 12:26:27 dharma tor[11490]: Jun 18 12:26:27.393 [notice] Read configuration file "/etc/tor/torrc".
Jun 18 12:26:27 dharma tor[11490]: Jun 18 12:26:27.400 [notice] Opening Socks listener on 127.0.0.1:9050
Jun 18 12:26:27 dharma tor[11490]: Jun 18 12:26:27.400 [notice] Opening Control listener on /var/run/tor/control
Jun 18 12:27:12 dharma systemd[1]: tor.service start operation timed out. Terminating.
Jun 18 12:27:12 dharma systemd[1]: Failed to start Anonymizing overlay network for TCP.
Jun 18 12:27:12 dharma systemd[1]: Unit tor.service entered failed state.
Jun 18 12:27:12 dharma systemd[1]: tor.service failed.
Jun 18 12:27:12 dharma systemd[1]: tor.service holdoff time over, scheduling restart.
Jun 18 12:27:12 dharma systemd[1]: Starting Anonymizing overlay network for TCP...
Jun 18 12:27:12 dharma tor[11572]: Jun 18 12:27:12.796 [notice] Tor v0.2.6.9 (git-145b2587d1269af4) running on Linux with Libevent 2.0.21-stable, OpenSSL 1.0.1f and Zlib 1.2.8.
Jun 18 12:27:12 dharma tor[11572]: Jun 18 12:27:12.796 [notice] Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning
Jun 18 12:27:12 dharma tor[11572]: Jun 18 12:27:12.796 [notice] Read configuration file "/usr/share/tor/tor-service-defaults-torrc".
Jun 18 12:27:12 dharma tor[11572]: Jun 18 12:27:12.796 [notice] Read configuration file "/etc/tor/torrc".
Jun 18 12:27:12 dharma tor[11572]: Configuration was valid
Jun 18 12:27:12 dharma tor[11575]: Jun 18 12:27:12.874 [notice] Tor v0.2.6.9 (git-145b2587d1269af4) running on Linux with Libevent 2.0.21-stable, OpenSSL 1.0.1f and Zlib 1.2.8.
Jun 18 12:27:12 dharma tor[11575]: Jun 18 12:27:12.874 [notice] Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning
Jun 18 12:27:12 dharma tor[11575]: Jun 18 12:27:12.874 [notice] Read configuration file "/usr/share/tor/tor-service-defaults-torrc".
Jun 18 12:27:12 dharma tor[11575]: Jun 18 12:27:12.875 [notice] Read configuration file "/etc/tor/torrc".
Jun 18 12:27:12 dharma tor[11575]: Jun 18 12:27:12.881 [notice] Opening Socks listener on 127.0.0.1:9050
Jun 18 12:27:12 dharma tor[11575]: Jun 18 12:27:12.882 [notice] Opening Control listener on /var/run/tor/control

... and goes on like this forever. This wasn't happening until few days ago, where this last update was distirbuted.

Child Tickets

Attachments (1)

0001-Raise-TimeoutSec-to-120.patch (761 bytes) - added by dncook 4 years ago.
Patch: Raise TimeoutSec to 120

Download all attachments as: .zip

Change History (15)

comment:1 Changed 4 years ago by maxxer

Cc: io@… added

comment:2 Changed 4 years ago by maxxer

I just downgraded to v0.2.6.8 (git-69b46cf274f35955) and it works fine

comment:3 Changed 4 years ago by weasel

Please provide proper debian package versions for working and not-working packages.

comment:4 Changed 4 years ago by maxxer

Working: tor_0.2.6.8-5~vivid+1_amd64.deb
Not working: tor_0.2.6.9-1~vivid+1_amd64.deb

comment:5 Changed 4 years ago by crazysane

Any movement on this? I rolled back to the last version I could find in the Ubuntu Repo, 0.2.5.10-1. I tried all manner of getting the service to complete, it seems like it just hangs after startup and never returns control back to systemd/the shell. So systemd believes it hung and sends a hup.

Lost my stable flag in the process of debugging this tho. :(

Last edited 4 years ago by crazysane (previous) (diff)

comment:6 Changed 4 years ago by kernelcorn

What's the contents of Tor's log when this happens? Is there anything useful in there?

comment:7 Changed 4 years ago by rl1987

Milestone: Tor: 0.2.8.x-final

comment:8 Changed 4 years ago by nickm

Status: newneeds_information

comment:9 Changed 4 years ago by nickm

Milestone: Tor: 0.2.8.x-finalTor: 0.2.???

Move a few tickets out of 0.2.8. I would take a good patch for most of these if somebody writes one. (If you do, please make the ticket needs_review and move it back into maint-0.2.8 milestone. :) )

comment:10 Changed 4 years ago by dncook

I believe I had the same problem on my machine, a Raspberry Pi Model 1 B running Raspbian. I have been compiling Tor from source, using the deb.torproject.org repository. For me, the problem arose after upgrading from wheezy to jessie.

The output from journalctl includes "tor.service start operation timed out," followed by the service getting killed and restarted. The Tor logs on my machine didn't have anything unusual, they looked normal until ending abruptly partway through bootstrapping.

I solved the problem by editing the systemd unit file (copied from /lib/systemd/system/tor.service to /etc/systemd/system/tor.service) to change TimeoutSec from 45 seconds to way longer. (and then loading the new unit file with systemctl daemon-reload) According to the log files, it takes between 40 and 80 seconds for Tor to "signal readiness to systemd" on my machine.

Last edited 4 years ago by dncook (previous) (diff)

Changed 4 years ago by dncook

Patch: Raise TimeoutSec to 120

comment:11 Changed 4 years ago by dncook

I just uploaded a tiny patch against the debian/tor repo to raise the timeout from 45 seconds to 120 seconds. How does this look? Please let me know if there's anything else I can do to help out.

comment:12 Changed 4 years ago by weasel

Resolution: fixed
Severity: Normal
Status: needs_informationclosed

This patch is now part of the debian-0.2.7 branch.

comment:13 Changed 3 years ago by teor

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

Milestone renamed

comment:14 Changed 3 years ago by nickm

Milestone: Tor: 0.3.???

Milestone deleted

Note: See TracTickets for help on using tickets.