Deadlock due to __del__() and ThreadLogObserver queue #25
Description
Crochet deadlock can happen when overridden __del__() method logs while current thread already holds the ThreadLogObserver queue lock.
Analysis: __del__() methods can be called from thread at any time due to garbage collection timing. If the del method attempts to acquire a non-recursive lock that the current thread already has locked, deadlock will occur. In Twisted classes like Deferred override __del__() and can log from the __del__() method.
Key part of Backtrace is as follows:
File: '/home/rmore/work/rmorehea-rcdn-testtng/virtualenv/local/lib/python2.7/site-packages/twisted/python/threadable.py', line 53, in sync
return function(self, *args, **kwargs)
File: '/home/rmore/work/rmorehea-rcdn-testtng/virtualenv/local/lib/python2.7/site-packages/twisted/python/log.py', line 191, in msg
self.observers[i](actualEventDict)
File: '/home/rmore/work/rmorehea-rcdn-testtng/virtualenv/local/lib/python2.7/site-packages/crochet/_eventloop.py', line 288, in __call__
self._queue.put(msg)
File: '/usr/lib/python2.7/Queue.py', line 138, in put
self.not_empty.notify()
File: '/usr/lib/python2.7/threading.py', line 392, in notify
for waiter in waiters:
File: '/home/rmore/work/rmorehea-rcdn-testtng/virtualenv/local/lib/python2.7/site-packages/twisted/internet/defer.py', line 683, in __del__
log.msg("Unhandled error in Deferred:", isError=True)
File: '/home/rmore/work/rmorehea-rcdn-testtng/virtualenv/local/lib/python2.7/site-packages/twisted/python/threadable.py', line 53, in sync
return function(self, *args, **kwargs)
File: '/home/rmore/work/rmorehea-rcdn-testtng/virtualenv/local/lib/python2.7/site-packages/twisted/python/log.py', line 191, in msg
self.observers[i](actualEventDict)
File: '/home/rmore/work/rmorehea-rcdn-testtng/virtualenv/local/lib/python2.7/site-packages/crochet/_eventloop.py', line 288, in __call__
self._queue.put(msg)
File: '/usr/lib/python2.7/Queue.py', line 118, in put
self.not_full.acquire()