[tor-commits] [stem/master] Closed controller could potentially leave lingering notification threads

[atagar at torproject.org]

commit e6e64d94638fe455ebfbc2f33765a36663d94ea3
Author: Damian Johnson <atagar at torproject.org>
Date:   Sat Mar 14 18:50:21 2015 -0700

    Closed controller could potentially leave lingering notification threads
    
    Despite having a notion of a 'daemon thread', python's behavior around it is
    remarkably poor. The point of a daemon is that it can be safely reaped during
    interpreter shutdown, but if one *actually* exists python screams like you're
    kicking it on the balls.
    
    *sigh*
    
    So anyway, it's important to be sure all threads are joined on before shutting
    down. Generally Stem is good about this but forgot that state change
    notifications spawn their own untracked daemons.
    
    As a result if you've registered any state listeners you'll have a good chance
    of a stacktrace. What happens is as follows...
    
      * You call close() on the controller.
    
      * Closing sends a notification in a new thread to your listener to say that
        it's closing.
    
      * Before that thread finishes the interpreter shuts down and wails like a
        baby.
    
    As such, we now track these daemons and close() joins on them before returning.
    
    This was caught thanks to frequent arm stacktraces like...
    
      Exception in thread Closed notification (most likely raised during interpreter shutdown):
      Traceback (most recent call last):
        File "/usr/lib/python2.7/threading.py", line 551, in __bootstrap_inner
        File "/usr/lib/python2.7/threading.py", line 504, in run
        File "/home/atagar/Desktop/seth/seth/header_panel.py", line 372, in reset_listener
        File "/home/atagar/Desktop/seth/seth/header_panel.py", line 376, in _update
        File "/home/atagar/Desktop/seth/seth/header_panel.py", line 403, in get_sampling
        File "/home/atagar/Desktop/seth/stem/control.py", line 392, in wrapped
        File "/home/atagar/Desktop/seth/stem/control.py", line 1445, in get_pid
        File "/home/atagar/Desktop/seth/stem/util/system.py", line 328, in pid_by_name
        File "/home/atagar/Desktop/seth/stem/util/system.py", line 930, in call
        File "/usr/lib/python2.7/subprocess.py", line 754, in communicate
        File "/usr/lib/python2.7/subprocess.py", line 1312, in _communicate
        File "/usr/lib/python2.7/subprocess.py", line 1373, in _communicate_with_poll
      <type 'exceptions.AttributeError'>: 'NoneType' object has no attribute 'POLLOUT'
---
 docs/change_log.rst |    1 +
 stem/connection.py  |    2 +-
 stem/control.py     |   20 +++++++++++++++++++-
 3 files changed, 21 insertions(+), 2 deletions(-)

diff --git a/docs/change_log.rst b/docs/change_log.rst
index 9ae7f77..2154341 100644
--- a/docs/change_log.rst
+++ b/docs/change_log.rst
@@ -54,6 +54,7 @@ conversion (:trac:`14075`).
   * :func:`~stem.process.launch_tor_with_config` avoids writing a temporary torrc to disk if able (:trac:`13865`)
   * :class:`~stem.response.events.CircuitEvent` support for the new SOCKS_USERNAME and SOCKS_PASSWORD arguments (:trac:`14555`, :spec:`2975974`)
   * The 'strict' argument of :func:`~stem.exit_policy.ExitPolicy.can_exit_to` didn't behave as documented (:trac:`14314`)
+  * Threads spawned for status change listeners were never joined on, potentially causing noise during interpreter shutdown
 
  * **Descriptors**
 
diff --git a/stem/connection.py b/stem/connection.py
index 54b89bd..277ba11 100644
--- a/stem/connection.py
+++ b/stem/connection.py
@@ -159,7 +159,7 @@ Tor is using a type of authentication we do not recognize...
 
   {auth_methods}
 
-Please check that arm is up to date and if there is an existing issue on
+Please check that stem is up to date and if there is an existing issue on
 'http://bugs.torproject.org'. If there isn't one then let us know!
 """
 
diff --git a/stem/control.py b/stem/control.py
index 86c84e1..d0e09cc 100644
--- a/stem/control.py
+++ b/stem/control.py
@@ -464,6 +464,8 @@ class BaseController(object):
     self._last_heartbeat = 0.0  # timestamp for when we last heard from tor
     self._is_authenticated = False
 
+    self._state_change_threads = []  # threads we've spawned to notify of state changes
+
     if self._socket.is_alive():
       self._launch_threads()
 
@@ -626,6 +628,17 @@ class BaseController(object):
 
     self._socket.close()
 
+    # Join on any outstanding state change listeners. Closing is a state change
+    # of its own, so if we have any listeners it's quite likely there's some
+    # work in progress.
+    #
+    # It's important that we do this outside of our locks so those daemons have
+    # access to us. This is why we're doing this here rather than _close().
+
+    for t in self._state_change_threads:
+      if t.is_alive() and threading.current_thread() != t:
+        t.join()
+
   def get_socket(self):
     """
     Provides the socket used to speak with the tor process. Communicating with
@@ -665,7 +678,8 @@ class BaseController(object):
     If spawn is **True** then the callback is notified via a new daemon thread.
     If **False** then the notice is under our locks, within the thread where
     the change occurred. In general this isn't advised, especially if your
-    callback could block for a while.
+    callback could block for a while. If still outstanding these threads are
+    joined on as part of closing this controller.
 
     :param function callback: function to be notified when our state changes
     :param bool spawn: calls function via a new thread if **True**, otherwise
@@ -735,6 +749,7 @@ class BaseController(object):
         t.join()
 
     self._notify_status_listeners(State.CLOSED)
+
     self._socket_close()
 
   def _post_authentication(self):
@@ -773,6 +788,8 @@ class BaseController(object):
         if expect_alive is not None and expect_alive != self.is_alive():
           return
 
+        self._state_change_threads = filter(lambda t: t.is_alive(), self._state_change_threads)
+
         for listener, spawn in self._status_listeners:
           if spawn:
             name = '%s notification' % state
@@ -781,6 +798,7 @@ class BaseController(object):
             notice_thread = threading.Thread(target = listener, args = args, name = name)
             notice_thread.setDaemon(True)
             notice_thread.start()
+            self._state_change_threads.append(notice_thread)
           else:
             listener(self, state, change_timestamp)