Opened 2 months ago

Last modified 7 days ago

#31810 merge_ready defect

Bug: ../src/lib/process/process_unix.c:265: process_unix_exec: Assertion line should be unreached failed; aborting.

Reported by: Parckwart Owned by: ahf
Priority: Very High Milestone: Tor: 0.4.1.x-final
Component: Core Tor/Tor Version: Tor: 0.4.0.1-alpha
Severity: Normal Keywords: 042-must, 041-regression, 042-backport, 041-backport, 040-backport, consider-backport-after-0425
Cc: ahf Actual Points:
Parent ID: Points:
Reviewer: nickm Sponsor:

Description

I am on Debian Buster, x86_64, trying to run Tor (installed from deb.torproject.org).

Sep 20 00:18:33 jennis Tor[1481]: Tor 0.4.1.5 running on Linux with Libevent 2.1.8-stable, OpenSSL 1.1.1c, Zlib 1.2.11, Liblzma 5.2.4, and Libzstd 1.3.8.
Sep 20 00:18:33 jennis Tor[1481]: Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning
Sep 20 00:18:33 jennis Tor[1481]: Read configuration file "/usr/share/tor/tor-service-defaults-torrc".
Sep 20 00:18:33 jennis Tor[1481]: Read configuration file "/etc/tor/torrc".
Sep 20 00:18:33 jennis Tor[1481]: Opening Socks listener on 127.0.0.1:9050
Sep 20 00:18:33 jennis Tor[1481]: Opened Socks listener on 127.0.0.1:9050
Sep 20 00:18:33 jennis Tor[1481]: Opening DNS listener on 127.0.0.1:53
Sep 20 00:18:33 jennis Tor[1481]: Opened DNS listener on 127.0.0.1:53
Sep 20 00:18:33 jennis Tor[1481]: Opening DNS listener on [::1]:53
Sep 20 00:18:33 jennis Tor[1481]: Opened DNS listener on [::1]:53
Sep 20 00:18:33 jennis Tor[1481]: Opening Transparent pf/netfilter listener on 127.0.0.1:9040
Sep 20 00:18:33 jennis Tor[1481]: Opened Transparent pf/netfilter listener on 127.0.0.1:9040
Sep 20 00:18:33 jennis Tor[1481]: Opening Transparent pf/netfilter listener on [::1]:9040
Sep 20 00:18:33 jennis Tor[1481]: Opened Transparent pf/netfilter listener on [::1]:9040
Sep 20 00:18:33 jennis Tor[1481]: Opening Control listener on 127.0.0.1:9051
Sep 20 00:18:33 jennis Tor[1481]: Opened Control listener on 127.0.0.1:9051
Sep 20 00:18:33 jennis Tor[1481]: Parsing GEOIP IPv4 file /usr/share/tor/geoip.
Sep 20 00:18:33 jennis Tor[1482]: tor_assertion_failed_(): Bug: ../src/lib/process/process_unix.c:265: process_unix_exec: Assertion line should be unreached failed; aborting. (on Tor 0.4.1.5 )
Sep 20 00:18:33 jennis Tor[1482]: Bug: Assertion line should be unreached failed in process_unix_exec at ../src/lib/process/process_unix.c:265: . Stack trace: (on Tor 0.4.1.5 )
Sep 20 00:18:33 jennis Tor[1482]: Bug:     /usr/bin/tor(log_backtrace_impl+0x46) [0x556988adb106] (on Tor 0.4.1.5 )
Sep 20 00:18:33 jennis Tor[1482]: Bug:     /usr/bin/tor(tor_assertion_failed_+0x147) [0x556988ad6297] (on Tor 0.4.1.5 )
Sep 20 00:18:33 jennis Tor[1482]: Bug:     /usr/bin/tor(process_unix_exec+0x274) [0x556988ab06c4] (on Tor 0.4.1.5 )
Sep 20 00:18:33 jennis Tor[1482]: Bug:     /usr/bin/tor(process_exec+0x5b) [0x556988aaea7b] (on Tor 0.4.1.5 )
Sep 20 00:18:33 jennis Tor[1482]: Bug:     /usr/bin/tor(pt_configure_remaining_proxies+0x563) [0x5569889a0093] (on Tor 0.4.1.5 )
Sep 20 00:18:33 jennis Tor[1482]: Bug:     /usr/bin/tor(set_options+0x18ba) [0x556988a5405a] (on Tor 0.4.1.5 )
Sep 20 00:18:33 jennis Tor[1482]: Bug:     /usr/bin/tor(options_init_from_string+0x382) [0x556988a55292] (on Tor 0.4.1.5 )
Sep 20 00:18:33 jennis Tor[1482]: Bug:     /usr/bin/tor(options_init_from_torrc+0x38a) [0x556988a5581a] (on Tor 0.4.1.5 )
Sep 20 00:18:33 jennis Tor[1482]: Bug:     /usr/bin/tor(tor_init+0x3c7) [0x556988927567] (on Tor 0.4.1.5 )
Sep 20 00:18:33 jennis Tor[1482]: Bug:     /usr/bin/tor(tor_run_main+0xb4) [0x556988927e74] (on Tor 0.4.1.5 )
Sep 20 00:18:33 jennis Tor[1482]: Bug:     /usr/bin/tor(tor_main+0x3a) [0x55698892638a] (on Tor 0.4.1.5 )
Sep 20 00:18:33 jennis Tor[1482]: Bug:     /usr/bin/tor(main+0x19) [0x556988925f49] (on Tor 0.4.1.5 )
Sep 20 00:18:33 jennis Tor[1482]: Bug:     /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xeb) [0x7f49509c609b] (on Tor 0.4.1.5 )
Sep 20 00:18:33 jennis Tor[1482]: Bug:     /usr/bin/tor(_start+0x2a) [0x556988925f9a] (on Tor 0.4.1.5 )
Sep 20 00:18:33 jennis Tor[1481]: Parsing GEOIP IPv6 file /usr/share/tor/geoip6.
Sep 20 00:18:33 jennis Tor[1481]: Bootstrapped 0% (starting): Starting
Sep 20 00:18:33 jennis Tor[1481]: Starting with guard context "default"
Sep 20 00:18:33 jennis Tor[1481]: Signaled readiness to systemd
Sep 20 00:18:34 jennis Tor[1481]: Bootstrapped 5% (conn): Connecting to a relay
Sep 20 00:18:34 jennis Tor[1481]: Opening Control listener on /run/tor/control
Sep 20 00:18:34 jennis Tor[1481]: Opened Control listener on /run/tor/control
Sep 20 00:18:34 jennis Tor[1481]: Bootstrapped 10% (conn_done): Connected to a relay
Sep 20 00:18:34 jennis Tor[1481]: Bootstrapped 14% (handshake): Handshaking with a relay
Sep 20 00:18:34 jennis Tor[1481]: Bootstrapped 15% (handshake_done): Handshake with a relay done
Sep 20 00:18:34 jennis Tor[1481]: Bootstrapped 75% (enough_dirinfo): Loaded enough directory info to build circuits
Sep 20 00:18:34 jennis Tor[1481]: Bootstrapped 90% (ap_handshake_done): Handshake finished with a relay to build circuits
Sep 20 00:18:34 jennis Tor[1481]: Bootstrapped 95% (circuit_create): Establishing a Tor circuit
Sep 20 00:18:35 jennis Tor[1481]: Bootstrapped 100% (done): Done

Child Tickets

Change History (12)

comment:1 Changed 2 months ago by teor

Cc: ahf added
Keywords: 042-must 041-regression added
Milestone: Tor: 0.4.2.x-final

Thanks for reporting this bug.

Does it still happen in 0.4.1.6, which was released yesterday?

comment:2 Changed 2 months ago by ahf

Owner: set to ahf
Status: newassigned

What do you have in your torrc? Do you have a path to a PT that does not exist or is not executable?

I think we should remove that unreachable assertion and replace it with a message type that the parent process can read and understand that there was an error during startup of the binary.

comment:3 Changed 2 months ago by Parckwart

Sorry, I wasn't aware of 0.4.1.6 beacause it's not yet on deb.torproject.org.

I don't know how to trigger this bug and I wasn't able to reproduce it with 0.4.1.6 (manually compiled), however I was able to reproduce with the current git version:

Sep 20 03:08:47 jennis Tor[30798]: Tor 0.4.2.1-alpha-dev (git-e6c5b248aea3e70e) running on Linux with Libevent 2.1.8-stable, OpenSSL 1.1.1c, Zlib 1.2.11, Liblzma N/A, and Libzstd N/A.
Sep 20 03:08:47 jennis Tor[30798]: Tor can't help you if you use it wrong! Learn how to be safe at https://www.torproject.org/download/download#warning
Sep 20 03:08:47 jennis Tor[30798]: This version is not a stable Tor release. Expect more bugs than usual.
Sep 20 03:08:47 jennis Tor[30798]: Read configuration file "/usr/share/tor/tor-service-defaults-torrc".
Sep 20 03:08:47 jennis Tor[30798]: Read configuration file "/etc/tor/torrc".
Sep 20 03:08:47 jennis Tor[30798]: Opening Socks listener on 127.0.0.1:9050
Sep 20 03:08:47 jennis Tor[30798]: Opened Socks listener on 127.0.0.1:9050
Sep 20 03:08:47 jennis Tor[30798]: Opening DNS listener on 127.0.0.1:53
Sep 20 03:08:47 jennis Tor[30798]: Opened DNS listener on 127.0.0.1:53
Sep 20 03:08:47 jennis Tor[30798]: Opening DNS listener on [::1]:53
Sep 20 03:08:47 jennis Tor[30798]: Opened DNS listener on [::1]:53
Sep 20 03:08:47 jennis Tor[30798]: Opening Transparent pf/netfilter listener on 127.0.0.1:9040
Sep 20 03:08:47 jennis Tor[30798]: Opened Transparent pf/netfilter listener on 127.0.0.1:9040
Sep 20 03:08:47 jennis Tor[30798]: Opening Transparent pf/netfilter listener on [::1]:9040
Sep 20 03:08:47 jennis Tor[30798]: Opened Transparent pf/netfilter listener on [::1]:9040
Sep 20 03:08:47 jennis Tor[30798]: Opening Control listener on 127.0.0.1:9051
Sep 20 03:08:47 jennis Tor[30798]: Opened Control listener on 127.0.0.1:9051
Sep 20 03:08:47 jennis Tor[30799]: tor_assertion_failed_(): Bug: src/lib/process/process_unix.c:265: process_unix_exec: Assertion line should be unreached failed; aborting. (on Tor 0.4.2.1-alpha-dev e6c5b248aea3e
Sep 20 03:08:47 jennis Tor[30799]: Bug: Tor 0.4.2.1-alpha-dev (git-e6c5b248aea3e70e): Assertion line should be unreached failed in process_unix_exec at src/lib/process/process_unix.c:265: . Stack trace: (on Tor 0
Sep 20 03:08:47 jennis Tor[30799]: Bug:     /usr/bin/tor(log_backtrace_impl+0x46) [0x55e4ed462846] (on Tor 0.4.2.1-alpha-dev e6c5b248aea3e70e)
Sep 20 03:08:47 jennis Tor[30799]: Bug:     /usr/bin/tor(tor_assertion_failed_+0x147) [0x55e4ed45d967] (on Tor 0.4.2.1-alpha-dev e6c5b248aea3e70e)
Sep 20 03:08:47 jennis Tor[30799]: Bug:     /usr/bin/tor(process_unix_exec+0x274) [0x55e4ed437104] (on Tor 0.4.2.1-alpha-dev e6c5b248aea3e70e)
Sep 20 03:08:47 jennis Tor[30799]: Bug:     /usr/bin/tor(process_exec+0x5b) [0x55e4ed4354bb] (on Tor 0.4.2.1-alpha-dev e6c5b248aea3e70e)
Sep 20 03:08:47 jennis Tor[30799]: Bug:     /usr/bin/tor(pt_configure_remaining_proxies+0x563) [0x55e4ed327fc3] (on Tor 0.4.2.1-alpha-dev e6c5b248aea3e70e)
Sep 20 03:08:47 jennis Tor[30799]: Bug:     /usr/bin/tor(set_options+0x17d2) [0x55e4ed3dcdb2] (on Tor 0.4.2.1-alpha-dev e6c5b248aea3e70e)
Sep 20 03:08:47 jennis Tor[30799]: Bug:     /usr/bin/tor(options_init_from_string+0x17d) [0x55e4ed3dddcd] (on Tor 0.4.2.1-alpha-dev e6c5b248aea3e70e)
Sep 20 03:08:47 jennis Tor[30799]: Bug:     /usr/bin/tor(options_init_from_torrc+0x404) [0x55e4ed3de464] (on Tor 0.4.2.1-alpha-dev e6c5b248aea3e70e)
Sep 20 03:08:47 jennis Tor[30799]: Bug:     /usr/bin/tor(tor_init+0x3c7) [0x55e4ed2af157] (on Tor 0.4.2.1-alpha-dev e6c5b248aea3e70e)
Sep 20 03:08:47 jennis Tor[30799]: Bug:     /usr/bin/tor(tor_run_main+0xb4) [0x55e4ed2af9a4] (on Tor 0.4.2.1-alpha-dev e6c5b248aea3e70e)
Sep 20 03:08:47 jennis Tor[30799]: Bug:     /usr/bin/tor(tor_main+0x3a) [0x55e4ed2adfaa] (on Tor 0.4.2.1-alpha-dev e6c5b248aea3e70e)
Sep 20 03:08:47 jennis Tor[30799]: Bug:     /usr/bin/tor(main+0x19) [0x55e4ed2adb69] (on Tor 0.4.2.1-alpha-dev e6c5b248aea3e70e)
Sep 20 03:08:47 jennis Tor[30799]: Bug:     /lib/x86_64-linux-gnu/libc.so.6(__libc_start_main+0xeb) [0x7ff3fa56f09b] (on Tor 0.4.2.1-alpha-dev e6c5b248aea3e70e)
Sep 20 03:08:47 jennis Tor[30799]: Bug:     /usr/bin/tor(_start+0x2a) [0x55e4ed2adbba] (on Tor 0.4.2.1-alpha-dev e6c5b248aea3e70e)
Sep 20 03:08:47 jennis Tor[30798]: Bootstrapped 0% (starting): Starting
Sep 20 03:08:47 jennis Tor[30798]: Starting with guard context "default"
Sep 20 03:08:47 jennis Tor[30798]: Pluggable Transport process terminated with status code 6

afh's guess is correct: There is indeed this line in my torrc:

ClientTransportPlugin meek exec /opt/meek/meek-client/meek-client

I copied the torrc file from another machine not noticing, that on this machine I don't have meek-client installed.

comment:4 Changed 2 months ago by nickm

Priority: MediumVery High

comment:5 Changed 8 weeks ago by ahf

Status: assignedneeds_review

https://github.com/torproject/tor/pull/1359 might be a good solution to this.

comment:6 Changed 8 weeks ago by nickm

Reviewer: nickm
Status: needs_reviewneeds_revision

I've added a couple comments to the patch; this looks like a plausible beginning.

More general questions:

1) Is there any way we can add a test for this case?

2) Should this be based on 0.4.0.x and marked as a backport candidate?

comment:7 Changed 5 weeks ago by ahf

1) I have added a test case to test for how we handle process termination in general. During this I discovered that we had an API difference where on Windows the exit callback of a given process_t would NOT be called when CreateProcessA() failed (with for example the no such file or directory error).

2) I have based the patches on maint-0.4.0 now, but also created a PR for 0.4.2 and master with an added practracker exception.

0.4.0, 0.4.1 PR: https://github.com/torproject/tor/pull/1424
0.4.2, master PR: https://github.com/torproject/tor/pull/1426

Let's see what CI says to both of them.

comment:8 Changed 5 weeks ago by dcf

#32033 was closed as a duplicate.

comment:9 Changed 5 weeks ago by ahf

Status: needs_revisionneeds_review

CI looks happy. Let's get this reviewed.

comment:10 Changed 5 weeks ago by nickm

Status: needs_reviewmerge_ready

This LGTM. Merging to 0.4.2 and forward; marking for backport.

comment:11 Changed 7 days ago by nickm

Milestone: Tor: 0.4.2.x-finalTor: 0.4.1.x-final

comment:12 Changed 7 days ago by teor

Component: Core TorCore Tor/Tor
Keywords: 042-backport 041-backport 040-backport consider-backport-after-0425 added
Version: Tor: 0.4.1.5Tor: 0.4.0.1-alpha
Note: See TracTickets for help on using tickets.