Hi, I sent a SIGHUP to the tor process after altering the torrc and got this effect: Jan 19 00:47:42.000 [notice] Tor 0.2.9.8 opening log file. Jan 19 00:47:55.000 [warn] Server managed proxy encountered a method error. (obfs3 Could not set up listener (0.0.0.0:xxxxx) for 'obfs3' (Address already in use).) Jan 19 00:47:55.000 [warn] Managed proxy at '/usr/bin/obfsproxy' failed the configuration protocol and will be destroyed.
It did it again when I restored the torrc and SIGHUPed again. Obfs3 is still running and listening afaict: tor 17356 0.0 0.2 49944 1736 ?? S 20Dec16 0:13.04 /opt/local/Library/Frameworks/Python.... Python 17356 tor 3u IPv4 0x02eb32a4 0t0 TCP *:xxxxx (LISTEN)
Bug or !Bug ?
GD
On 19 Jan 2017, at 12:00, Geoff Down geoffdown@fastmail.net wrote:
Hi, I sent a SIGHUP to the tor process after altering the torrc and got this effect: Jan 19 00:47:42.000 [notice] Tor 0.2.9.8 opening log file. Jan 19 00:47:55.000 [warn] Server managed proxy encountered a method error. (obfs3 Could not set up listener (0.0.0.0:xxxxx) for 'obfs3' (Address already in use).) Jan 19 00:47:55.000 [warn] Managed proxy at '/usr/bin/obfsproxy' failed the configuration protocol and will be destroyed.
It did it again when I restored the torrc and SIGHUPed again. Obfs3 is still running and listening afaict: tor 17356 0.0 0.2 49944 1736 ?? S 20Dec16 0:13.04 /opt/local/Library/Frameworks/Python.... Python 17356 tor 3u IPv4 0x02eb32a4 0t0 TCP *:xxxxx (LISTEN)
Bug or !Bug ?
This could be a bug in tor in pt_configure_remaining_proxies(), or it could be a bug in obfsproxy, or it could not be a bug.
What are the ServerTransport* lines in your torrc, default torrc, and command-line? What are the info-level log lines around the lines you quoted?
For example, do you see something like: Preparing managed proxy '%s' for restart. (If so, this could be a bug in proxy_prepare_for_restart().) Nothing changed for managed proxy '%s' after HUP: not restarting.
T
-- Tim Wilson-Brown (teor)
teor2345 at gmail dot com PGP C855 6CED 5D90 A0C5 29F6 4D43 450C BA7F 968F 094B ricochet:ekmygaiu4rzgsk6n xmpp: teor at torproject dot org ------------------------------------------------------------------------
On Thu, Jan 19, 2017, at 01:14 AM, teor wrote:
On 19 Jan 2017, at 12:00, Geoff Down geoffdown@fastmail.net wrote: Jan 19 00:47:42.000 [notice] Tor 0.2.9.8 opening log file. Jan 19 00:47:55.000 [warn] Server managed proxy encountered a method error. (obfs3 Could not set up listener (0.0.0.0:xxxxx) for 'obfs3' (Address already in use).) Jan 19 00:47:55.000 [warn] Managed proxy at '/usr/bin/obfsproxy' failed the configuration protocol and will be destroyed.
This could be a bug in tor in pt_configure_remaining_proxies(), or it could be a bug in obfsproxy, or it could not be a bug.
What are the ServerTransport* lines in your torrc, default torrc, and command-line?
In the torrc I have been using for at least a year: ServerTransportPlugin obfs3 exec /usr/bin/obfsproxy managed -none elsewhere. I should have said that previous (stable) versions of tor didn't show this behaviour.
What are the info-level log lines around the lines you quoted?
For example, do you see something like: Preparing managed proxy '%s' for restart. (If so, this could be a bug in proxy_prepare_for_restart().) Nothing changed for managed proxy '%s' after HUP: not restarting.
I had to stop and restart tor to change log level: the same thing happens on startup.
Jan 19 01:48:07.000 [info] launch_managed_proxy(): Managed proxy at '/usr/bin/obfsproxy' has spawned with PID '16433'. Jan 19 02:14:22.000 [info] notify_waitpid_callback_by_pid(): Child process 16433 has exited; running callback. Jan 19 02:14:23.000 [info] handle_proxy_line(): Got a line from managed proxy '/usr/bin/obfsproxy': (VERSION 1) Jan 19 02:14:23.000 [info] handle_proxy_line(): Got a line from managed proxy '/usr/bin/obfsproxy': (SMETHOD-ERROR obfs3 Could not set up listener (0.0.0.0:xxxxx) for 'obfs3' (Address already in use).) Jan 19 02:14:23.000 [warn] Server managed proxy encountered a method error. (obfs3 Could not set up listener (0.0.0.0:xxxxx) for 'obfs3' (Address already in use).) Jan 19 02:14:23.000 [warn] Managed proxy at '/usr/bin/obfsproxy' failed the configuration protocol and will be destroyed. Jan 19 02:14:23.000 [info] tor_process_handle_destroy(): Terminated process with PID '16433'.
Then a HUP produced the same sequence (but a different PID), with no sign of the lines you mention above regarding 'restart'. The original obsfproxy process 17356 is still in the same state.
On 19 Jan 2017, at 13:30, Geoff Down geoffdown@fastmail.net wrote:
On Thu, Jan 19, 2017, at 01:14 AM, teor wrote:
On 19 Jan 2017, at 12:00, Geoff Down geoffdown@fastmail.net wrote: Jan 19 00:47:42.000 [notice] Tor 0.2.9.8 opening log file. Jan 19 00:47:55.000 [warn] Server managed proxy encountered a method error. (obfs3 Could not set up listener (0.0.0.0:xxxxx) for 'obfs3' (Address already in use).) Jan 19 00:47:55.000 [warn] Managed proxy at '/usr/bin/obfsproxy' failed the configuration protocol and will be destroyed.
This could be a bug in tor in pt_configure_remaining_proxies(), or it could be a bug in obfsproxy, or it could not be a bug.
What are the ServerTransport* lines in your torrc, default torrc, and command-line?
In the torrc I have been using for at least a year: ServerTransportPlugin obfs3 exec /usr/bin/obfsproxy managed -none elsewhere. I should have said that previous (stable) versions of tor didn't show this behaviour.
What are the info-level log lines around the lines you quoted?
For example, do you see something like: Preparing managed proxy '%s' for restart. (If so, this could be a bug in proxy_prepare_for_restart().) Nothing changed for managed proxy '%s' after HUP: not restarting.
I had to stop and restart tor to change log level: the same thing happens on startup.
Jan 19 01:48:07.000 [info] launch_managed_proxy(): Managed proxy at '/usr/bin/obfsproxy' has spawned with PID '16433'. Jan 19 02:14:22.000 [info] notify_waitpid_callback_by_pid(): Child process 16433 has exited; running callback. Jan 19 02:14:23.000 [info] handle_proxy_line(): Got a line from managed proxy '/usr/bin/obfsproxy': (VERSION 1) Jan 19 02:14:23.000 [info] handle_proxy_line(): Got a line from managed proxy '/usr/bin/obfsproxy': (SMETHOD-ERROR obfs3 Could not set up listener (0.0.0.0:xxxxx) for 'obfs3' (Address already in use).) Jan 19 02:14:23.000 [warn] Server managed proxy encountered a method error. (obfs3 Could not set up listener (0.0.0.0:xxxxx) for 'obfs3' (Address already in use).) Jan 19 02:14:23.000 [warn] Managed proxy at '/usr/bin/obfsproxy' failed the configuration protocol and will be destroyed. Jan 19 02:14:23.000 [info] tor_process_handle_destroy(): Terminated process with PID '16433'.
Then a HUP produced the same sequence (but a different PID), with no sign of the lines you mention above regarding 'restart'. The original obsfproxy process 17356 is still in the same state.
Is this error reproducible once the process 17356 is killed?
T
-- Tim Wilson-Brown (teor)
teor2345 at gmail dot com PGP C855 6CED 5D90 A0C5 29F6 4D43 450C BA7F 968F 094B ricochet:ekmygaiu4rzgsk6n xmpp: teor at torproject dot org ------------------------------------------------------------------------
On Thu, Jan 19, 2017, at 02:33 AM, teor wrote:
On 19 Jan 2017, at 13:30, Geoff Down geoffdown@fastmail.net wrote:
Then a HUP produced the same sequence (but a different PID), with no sign of the lines you mention above regarding 'restart'. The original obsfproxy process 17356 is still in the same state.
Is this error reproducible once the process 17356 is killed?
In that case, after sending a HUP the transport was registered with no problem, just the normal messages to that effect. After sending *another* HUP, I did indeed get Nothing changed for managed proxy '/usr/bin/obfsproxy' after HUP: not restarting
Where does that leave us? Cosmic rays?
On 19 Jan 2017, at 13:46, Geoff Down geoffdown@fastmail.net wrote:
On Thu, Jan 19, 2017, at 02:33 AM, teor wrote:
On 19 Jan 2017, at 13:30, Geoff Down geoffdown@fastmail.net wrote:
Then a HUP produced the same sequence (but a different PID), with no sign of the lines you mention above regarding 'restart'. The original obsfproxy process 17356 is still in the same state.
Is this error reproducible once the process 17356 is killed?
In that case, after sending a HUP the transport was registered with no problem, just the normal messages to that effect. After sending *another* HUP, I did indeed get Nothing changed for managed proxy '/usr/bin/obfsproxy' after HUP: not restarting
Where does that leave us? Cosmic rays?
Occasionally, the tor process fails to shut down a pluggable transport process when tor exits. I believe this is an unavoidable consequence of unexpected or unclean tor shutdowns or crashes.
If the pluggable transport is written to die when this happens, it is a bug in the pluggable transport. (Does obfsproxy have an option to die when the controlling process dies?)
If not, it's a missing feature in the pluggable transport.
T
-- Tim Wilson-Brown (teor)
teor2345 at gmail dot com PGP C855 6CED 5D90 A0C5 29F6 4D43 450C BA7F 968F 094B ricochet:ekmygaiu4rzgsk6n xmpp: teor at torproject dot org ------------------------------------------------------------------------
On Thu, Jan 19, 2017 at 01:55:10PM +1100, teor wrote:
Occasionally, the tor process fails to shut down a pluggable transport process when tor exits. I believe this is an unavoidable consequence of unexpected or unclean tor shutdowns or crashes.
Right. This is why we changed the design in 0.2.7.1-alpha to make it easier for pluggable transports to realize that they need to die:
- When launching managed pluggable transports, setup a valid open stdin in the child process that can be used to detect if tor has terminated. The "TOR_PT_EXIT_ON_STDIN_CLOSE" environment variable can be used by implementations to detect this new behavior. Resolves ticket 15435.
If the pluggable transport is written to die when this happens, it is a bug in the pluggable transport. (Does obfsproxy have an option to die when the controlling process dies?)
If not, it's a missing feature in the pluggable transport.
I think the python obfsproxy has never gotten any updates to adapt to the new Tor feature.
So, one option is to use the go obfsproxy implementation. Another option is for somebody to patch the python obfsproxy. And who knows, maybe there's a third good option too. :)
--Roger
tor-relays@lists.torproject.org
-
Geoff Down -
Roger Dingledine -
teor