[tor-bugs] #32032 [Core Tor/Tor]: Assertion mp->conf_state == PT_PROTO_COMPLETED failed in managed_proxy_stdout_callback

[Tor Bug Tracker & Wiki]

#32032: Assertion mp->conf_state == PT_PROTO_COMPLETED failed in
managed_proxy_stdout_callback
------------------------------+--------------------------------
     Reporter:  dcf           |      Owner:  (none)
         Type:  defect        |     Status:  new
     Priority:  Medium        |  Milestone:
    Component:  Core Tor/Tor  |    Version:  Tor: 0.4.2.2-alpha
     Severity:  Normal        |   Keywords:
Actual Points:                |  Parent ID:
       Points:                |   Reviewer:
      Sponsor:                |
------------------------------+--------------------------------
 I'm using commit 0d82a8be77ae8d7fb06c8702bfbf1ebbaf370c94.

 Create a fake server transport plugin called "test.sh" that only exits
 with an SMETHOD-ERROR. `chmod +x` it.
 {{{#!sh
 #!/bin/sh
 echo "VERSION 1"
 echo "SMETHOD-ERROR testpt failing ABCD"
 }}}

 Create a configuration file called "torrc.testpt".

 {{{
 PublishServerDescriptor 0
 AssumeReachable
 SOCKSPort 0

 ORPort auto
 ServerTransportPlugin testpt exec ./testpt.sh
 Bridge testpt 127.0.0.1:9999
 }}}

 Run `tor -f torrc.testpt` and observe the following assertion failure:

 {{{
 Oct 10 15:56:22.000 [notice] Starting with guard context "default"
 Oct 10 15:56:22.000 [warn] Server managed proxy encountered a method
 error. (testpt failing ABCD)
 Oct 10 15:56:22.000 [warn] Managed proxy at './testpt.sh' failed the
 configuration protocol and will be destroyed.
 Oct 10 15:56:22.000 [err] tor_assertion_failed_(): Bug:
 src/feature/client/transports.c:1836: managed_proxy_stdout_callback:
 Assertion mp->conf_state == PT_PROTO_COMPLETED failed; aborting. (on Tor
 0.4.2.2-alpha-dev 0d82a8be77ae8d7f)
 Oct 10 15:56:22.000 [err] Bug: Tor 0.4.2.2-alpha-dev (git-
 0d82a8be77ae8d7f): Assertion mp->conf_state == PT_PROTO_COMPLETED failed
 in managed_proxy_stdout_callback at src/feature/client/transports.c:1836:
 . Stack trace: (on Tor 0.4.2.2-alpha-dev 0d82a8be77ae8d7f)
 Oct 10 15:56:22.000 [err] Bug:     ./src/app/tor(log_backtrace_impl+0x56)
 [0x563a200ffaa6] (on Tor 0.4.2.2-alpha-dev 0d82a8be77ae8d7f)
 Oct 10 15:56:22.000 [err] Bug:
 ./src/app/tor(tor_assertion_failed_+0x147) [0x563a200fab27] (on Tor
 0.4.2.2-alpha-dev 0d82a8be77ae8d7f)
 Oct 10 15:56:22.000 [err] Bug:     ./src/app/tor(+0xd7994)
 [0x563a1ffbf994] (on Tor 0.4.2.2-alpha-dev 0d82a8be77ae8d7f)
 Oct 10 15:56:22.000 [err] Bug:     ./src/app/tor(+0x1e6883)
 [0x563a200ce883] (on Tor 0.4.2.2-alpha-dev 0d82a8be77ae8d7f)
 Oct 10 15:56:22.000 [err] Bug:     /usr/lib/x86_64-linux-
 gnu/libevent-2.1.so.6(+0x229ba) [0x7f036a38e9ba] (on Tor 0.4.2.2-alpha-dev
 0d82a8be77ae8d7f)
 Oct 10 15:56:22.000 [err] Bug:     /usr/lib/x86_64-linux-
 gnu/libevent-2.1.so.6(event_base_loop+0x5a7) [0x7f036a38f537] (on Tor
 0.4.2.2-alpha-dev 0d82a8be77ae8d7f)
 Oct 10 15:56:22.000 [err] Bug:     ./src/app/tor(do_main_loop+0xdb)
 [0x563a1ff5c15b] (on Tor 0.4.2.2-alpha-dev 0d82a8be77ae8d7f)
 Oct 10 15:56:22.000 [err] Bug:     ./src/app/tor(tor_run_main+0x1105)
 [0x563a1ff49b15] (on Tor 0.4.2.2-alpha-dev 0d82a8be77ae8d7f)
 Oct 10 15:56:22.000 [err] Bug:     ./src/app/tor(tor_main+0x3a)
 [0x563a1ff470ca] (on Tor 0.4.2.2-alpha-dev 0d82a8be77ae8d7f)
 Oct 10 15:56:22.000 [err] Bug:     ./src/app/tor(main+0x19)
 [0x563a1ff46c89] (on Tor 0.4.2.2-alpha-dev 0d82a8be77ae8d7f)
 Oct 10 15:56:22.000 [err] Bug:     /lib/x86_64-linux-
 gnu/libc.so.6(__libc_start_main+0xeb) [0x7f0369dbb09b] (on Tor 0.4.2.2
 -alpha-dev 0d82a8be77ae8d7f)
 Oct 10 15:56:22.000 [err] Bug:     ./src/app/tor(_start+0x2a)
 [0x563a1ff46cda] (on Tor 0.4.2.2-alpha-dev 0d82a8be77ae8d7f)
 Aborted
 }}}

 The same crash happens if you omit `VERSION 1` from testpt.sh.

 {{{#!sh
 #!/bin/sh
 echo "SMETHOD-ERROR testpt failing ABCD"
 }}}

 I encountered this in practice with meek-server when it couldn't open its
 log file. It reports the failure to open a log file as an SMETHOD-ERROR,
 because in older versions of tor that was the only way to cause an error
 message to appear in the tor log file. In my case, the failure looked like
 this:
 {{{
 Oct 10 21:30:26 tor2 Tor-meek[2223]: Server managed proxy encountered a
 method error. (meek error opening log file: open /var/log/meek-server-
 meek.log: read-only file system)
 Oct 10 21:30:26 tor2 Tor-meek[2223]: Managed proxy at '/usr/local/bin
 /meek-server' failed the configuration protocol and will be destroyed.
 Oct 10 21:30:26 tor2 Tor-meek[2223]: tor_assertion_failed_(): Bug:
 ../src/feature/client/transports.c:1836: managed_proxy_stdout_callback:
 Assertion mp->conf_state == PT_PROTO_COMPLETED failed; aborting. (on Tor
 0.4.1.6 )
 Oct 10 21:30:26 tor2 Tor-meek[2223]: Bug: Assertion mp->conf_state ==
 PT_PROTO_COMPLETED failed in managed_proxy_stdout_callback at
 ../src/feature/client/transports.c:1836: . Stack trace: (on Tor 0.4.1.6 )
 ...
 }}}

--
Ticket URL: <https://trac.torproject.org/projects/tor/ticket/32032>
Tor Bug Tracker & Wiki <https://trac.torproject.org/>
The Tor Project: anonymity online