classification
Title: Exceptions when a thread exits
Type: Stage:
Components: Interpreter Core Versions: Python 2.3
process
Status: closed Resolution: fixed
Dependencies: Superseder:
Assigned To: brett.cannon Nosy List: brett.cannon, carlosayam, doko, gjb1002, jgoerzen, justincjohnson, tim.peters
Priority: low Keywords:

Created on 2003-06-14 10:32 by doko, last changed 2005-11-04 13:33 by justincjohnson. This issue is now closed.

Files
File name Uploaded Description Edit
tracer.py brett.cannon, 2003-06-15 23:44 Contains trace_currentThread which logs to stderr when (threading.)?currentThread becomes None
Messages (26)
msg16385 - (view) Author: Matthias Klose (doko) * (Python committer) Date: 2003-06-14 10:32
[forwarded from http://bugs.debian.org/195812]

The application mentioned is offlineimap, available
from ftp://ftp.debian.org/dists/unstable/main/source/.

This behavior is new to Python 2.3.

When my application exits, I get a lot of these messages:

Traceback (most recent call last):
  File "/usr/lib/python2.3/threading.py", line 426, in
__bootstrap
    self.__stop()
  File "/usr/lib/python2.3/threading.py", line 435, in
__stop
    self.__block.notifyAll()
  File "/usr/lib/python2.3/threading.py", line 239, in
notifyAll
    self.notify(len(self.__waiters))
  File "/usr/lib/python2.3/threading.py", line 221, in
notify
    currentThread() # for side-effect
TypeError: 'NoneType' object is not callable
jgoerzen@christoph:~/tree/offlineimap-3.99.18$
./offlineimap.py  -l log -d maildir -a Personal,Excel
Unhandled exception in thread started by <bound method
ExitNotifyThread.__bootstrap of <ExitNotifyThread(Keep
alive LocalExcel, stopped daemon)>>
Traceback (most recent call last):
  File "/usr/lib/python2.3/threading.py", line 426, in
__bootstrap
    self.__stop()
  File "/usr/lib/python2.3/threading.py", line 435, in
__stop
    self.__block.notifyAll()
  File "/usr/lib/python2.3/threading.py", line 239, in
notifyAll
    self.notify(len(self.__waiters))
  File "/usr/lib/python2.3/threading.py", line 221, in
notify
    currentThread() # for side-effect
TypeError: 'NoneType' object is not callable
Unhandled exception in thread started by <bound method
ExitNotifyThread.__bootstrap of <ExitNotifyThread(Keep
alive RemoteExcel, stopped daemon)>>
Traceback (most recent call last):
  File "/usr/lib/python2.3/threading.py", line 426, in
__bootstrap
    self.__stop()
  File "/usr/lib/python2.3/threading.py", line 435, in
__stop
    self.__block.notifyAll()
  File "/usr/lib/python2.3/threading.py", line 239, in
notifyAll
    self.notify(len(self.__waiters))
  File "/usr/lib/python2.3/threading.py", line 221, in
notify
    currentThread() # for side-effect
TypeError: 'NoneType' object is not callable
msg16386 - (view) Author: Brett Cannon (brett.cannon) * (Python committer) Date: 2003-06-15 08:19
Logged In: YES 
user_id=357491

I went to the FTP site and all I found was some huge, 
compressed files (after changing the path to ftp://ftp.debian.org/
debian/dists/sid/main/source); no specific program called 
offlinemap.  If it is in one of those files can you just add the file 
to the bug report?

As for the reported bug, it looks like currentThread is being 
redefined, although how that is happening is beyond me.  I 
checked the 'threading' module and no where is currentThread 
redefined which could lead to None.  Has the app being run been 
changed at all since Python 2.2 was released?
msg16387 - (view) Author: Matthias Klose (doko) * (Python committer) Date: 2003-06-15 08:44
Logged In: YES 
user_id=60903

Please see
http://packages.debian.org/unstable/mail/offlineimap.html

or for the tarball:
http://ftp.debian.org/debian/pool/main/o/offlineimap/offlineimap_3.99.18.tar.gz
msg16388 - (view) Author: Brett Cannon (brett.cannon) * (Python committer) Date: 2003-06-15 23:44
Logged In: YES 
user_id=357491

Well, I'm stumped.  I checked the diff from when 2.2 was initially 
released until now and the only change that seems to be related 
to any of this is that what is returned by currentThread is not 
saved in a variable.  But since the error is the calling of 
currentThread itself and not saving the return value I don't see 
how that would affect anything.

I also went through offlineimap but I didn't see anything there 
that seemed to be setting currentThread to None.  Although 
since several files do ``import *`` so there still is a possibility of 
overwriting currentThread locally.

So, for my owning learning and to help solve this, I have written 
a tracing function that writes to stderr using the logging package 
when it detects that either currentThread or 
threading.currentThread has been set to None, locally or globally 
(I assume the code is not injecting into builtins so I didn't bother 
checking there).  The file is named tracer.py and I have attached 
it to this bug report.  If you can execute 
``sys.settrace(tracer.trace_currentThread)`` before offlinemap 
starts executing and immediately within each thread (it has to be 
called in *every* thread since tracing functions are no inherited 
from the main thread) it should print out a message when 
currentThread becomes None.  If you *really* want to make this 
robust you can also have it check sys.modules['threading'] every 
time as well, but I figure there is not going to be much renaming 
and masking of currentThread.
msg16389 - (view) Author: Tim Peters (tim.peters) * (Python committer) Date: 2003-06-16 01:05
Logged In: YES 
user_id=31435

Note that the OP said "when my application exits".  When 
Python is tearing down the universe, it systematically sets 
module-global bindings to None.  currentThread() is a module 
global.  I can't make more time for this now, so for more info 
talk about it on Python-Dev.
msg16390 - (view) Author: Brett Cannon (brett.cannon) * (Python committer) Date: 2003-06-16 06:19
Logged In: YES 
user_id=357491

Nuts.  For some reason I thought the OP had said when threads 
were exiting.

I will ask on python-dev for a good explanation of what happens 
when Python is shutting down.
msg16391 - (view) Author: Brett Cannon (brett.cannon) * (Python committer) Date: 2003-06-16 06:58
Logged In: YES 
user_id=357491

OK, following Tim's advice I checked and it seems that Thread 
calls a method while shutting itself down that calls 
Condition.notifyAll which calls currentThread which is a global.  It 
would appear that offlineimap is leaving its threads running, the 
program gets shut down, the threads raise an error while 
shutting down (probably because things are being torn down), 
this triggers the stopping method in Thread, and this raises its 
own exception because of the teardown which is what we are 
seeing as the TypeError.

So the question is whether Condition should store a local 
reference to currentThread or not.  It is not the most pure 
solution since this shutdown issue is not Condition's, but the only 
other solution I can think of is to have Thread keep a reference 
to currentThread, inject it into the current frame's global 
namespace, call Condition.notifyAll, and then remove the 
reference from the frame again.  I vote for the cleaner, less pure 
solution.  =)

Am I insane on this or does it at least sound like this is the 
problem and proper solution?
msg16392 - (view) Author: John Goerzen (jgoerzen) Date: 2003-06-16 13:26
Logged In: YES 
user_id=491567

I can confirm that this behavior is not present in Python 2.2 in 
the same version that I am using to test against Python 2.3. 
 
I will be on vacation for most of this and next week.  I'll try to 
get to the logging script before I leave, but I might not get to it 
until I return. 
 
FYI, you can also obtain OfflineIMAP at 
http://quux.org/devel/offlineimap. 
 
 
msg16393 - (view) Author: Brett Cannon (brett.cannon) * (Python committer) Date: 2004-02-10 01:18
Logged In: YES 
user_id=357491

After staring at the code, I am not even sure if the calls for its side-
effect are needed.  If you call currentThread(), it either returns a value 
from _active which is a dict of running Thread instances indexed by 
thread idents, or a new _DummyThread instance that inserts itself into 
_active.  Now the two calls in the _Condition class are purely for this 
possible side-effect.

And yet at no point is anything from _active, through currentThread or 
direct access, even touched by a _Condition method.  The only chance 
this might be an issue is if a _Condition instance uses an RLock instance 
for its locking, which is the default behavior.

But this still makes the side-effect need useless.  RLocks will call 
currentThread on their own and since this is all in the same thread the 
result won't change.  And in this specific case of this bug, the _Condition 
instance is created with a Lock instance since that is what the Thread 
instance uses for constructing the _Condition instance it use, which is just 
thread.allocate_lock() which is obviously not an RLock.

In other words I can't find the point to the side-effect in _Condition.  I 
will try to come up with some testing code that reproduces the error and 
then see if just removing the calls in _Condition remove the error and 
still pass the regression tests.
msg16394 - (view) Author: Brett Cannon (brett.cannon) * (Python committer) Date: 2004-02-17 04:59
Logged In: YES 
user_id=357491

Does anyone know how to cause this error in isolation?  I have tried a 
bunch of different ways but cannot cause an exception to be raised at the 
correct point in Threading.__bootstrap() to lead to self.__stop() to be 
called while the interpreter is tearing itself down.
msg16395 - (view) Author: Brett Cannon (brett.cannon) * (Python committer) Date: 2004-03-03 04:29
Logged In: YES 
user_id=357491

To force this error I inserted code to set all attributes of the threading 
module to None and then throw and exception.  After commenting out 
the two calls to currentThread in _Condition the thrown exception to 
trigger the problem propogated to the top correctly.

I did have the clean-up function give out since I set *everything* to 
None, but it doesn't look like a normal issue as shown in the exception 
traceback in the OP.  I don't think it is an issue.

So it seems commenting the two calls to currentThread in _Condition 
solves the problem.  But since this is threading code and the comment 
explicitly states it is for the side-effect I am going to try to get a second 
opinion.
msg16396 - (view) Author: Brett Cannon (brett.cannon) * (Python committer) Date: 2004-03-08 22:32
Logged In: YES 
user_id=357491

OK, this has been fixed in Python 2.4 (rev. 1.41 of Lib/threading.py; just 
removed the two calls to currentThread in the _Condition class that were 
commented to be for their side-effect).

Just because I don't feel rock-solid on my fix to the point of it not 
changing some obscure semantics that I would be willing to put a gun to 
my head over it I am not going to backport this until I hear from 
someone who had this bug and reports that they have not had any issues 
for a long time.  Otherwise I will just leave the fix in 2.4 only.
msg16397 - (view) Author: Brett Cannon (brett.cannon) * (Python committer) Date: 2004-03-08 22:36
Logged In: YES 
user_id=357491

OK, this has been fixed in Python 2.4 (rev. 1.41 of Lib/threading.py; just 
removed the two calls to currentThread in the _Condition class that were 
commented to be for their side-effect).

Just because I don't feel rock-solid on my fix to the point of it not 
changing some obscure semantics that I would be willing to put a gun to 
my head over it I am not going to backport this until I hear from 
someone who had this bug and reports that they have not had any issues 
for a long time.  Otherwise I will just leave the fix in 2.4 only.
msg16398 - (view) Author: Brett Cannon (brett.cannon) * (Python committer) Date: 2004-05-16 18:45
Logged In: YES 
user_id=357491

Discovered this is not fixed after all (previous fix didn't go far enough; 
still needed, though).  Patch 954922 is the second attempt to fix this.  
This time, though, I had code that could trigger the problem reliably and 
thus this should be the proper, and final, fix.
msg16399 - (view) Author: Brett Cannon (brett.cannon) * (Python committer) Date: 2004-05-17 04:36
Logged In: YES 
user_id=357491

How to reproduce the bug:

* Follow the instructions at http://mnetproject.org/repos/ on how to get a 
copy of the in-dev version of mnet (I used the instructions for using wget 
and it worked fine).

* Run ``python setup.py``.  Do realize that this app will download other 
Python code (crypto stuff mostly) to finish its install.  Takes up about 54 
MB on my machine after it is compiled.

* Run ``python setup.py test -a``.  This executes the testing suite.  The 
bug manifests itself after the testing suite finishes execution.

This will consistently cause the bug every time.
msg16400 - (view) Author: k (carlosayam) Date: 2004-06-03 03:01
Logged In: YES 
user_id=990060

bcannon said on 2004-02-17
>> Does anyone know how to cause this error in isolation?

I'm getting the same error when I start a new thread,
daemonise it and the thread goes into a very slow database
operation (loading a large object); meanwhile the main
thread starts a GUI; then I close the window, exiting the
main loop and the python interpreter ends (or tries to end.)

In relation to bcannon comment on how to reproduce the error
(setting all variables to None in the module), my guess is
that while exiting, the python interpreter is somehow
freeing all variables in the module (cleaning the module or
something), but the module is still running and that raises
the error... is this possible?

Note: if the thread is not daemonised, the problem desapears
but the script (the python interpreter) takes a while to finish.
msg16401 - (view) Author: Brett Cannon (brett.cannon) * (Python committer) Date: 2004-06-03 05:08
Logged In: YES 
user_id=357491

Yep, that is how Python cleans up a module; sets everything in the 
module to None and then removes it from sys.modules .

As for your case, I don't know enough about daemonized threads.  My 
patch for this only tries to let the exception make it to the top without 
'threading' hiding the exception by causing its own exception from 
interpreter shutdown.  In other words I don't know if this is a related 
issue or not.
msg16402 - (view) Author: Tim Peters (tim.peters) * (Python committer) Date: 2004-06-03 05:25
Logged In: YES 
user_id=31435

Brett, FYI, a daemon thread differs from a non-daemon 
thread in only one respect:  Python shuts down when only 
daemon threads remain.  It waits for non-daemon threads to 
finish.  So a daemon thread can keep running after the 
interpreter has torn itself down completely.  For that reason, 
problems in daemon threads doing non-trivial things are 
almost guaranteed.
msg16403 - (view) Author: k (carlosayam) Date: 2004-06-03 06:05
Logged In: YES 
user_id=990060

I don't understand one thing: how can python shut down
itself and, at the same time, keep a python code running in
a daemonised thread? or is that thread running in a
different "threaded" python byte-code interpreter?
msg16404 - (view) Author: Brett Cannon (brett.cannon) * (Python committer) Date: 2004-07-03 03:57
Logged In: YES 
user_id=357491

Fixed in 2.4 thanks to rev. 1.42 to Lib/threading.  Don't know if this will 
be backported to 2.3 .  Possible, but need someone else to agree first.
msg16405 - (view) Author: Brett Cannon (brett.cannon) * (Python committer) Date: 2004-07-03 20:01
Logged In: YES 
user_id=357491

For 2.3, rev.1.38.6.1 has the required fixes (required also backporting 
rev. 1.41 from HEAD).

Thanks to everyone who tried to help with this nasty thing.  And a special 
thanks to the Mnet guys for giving me a way to reproduce this bug 
consistently.
msg16406 - (view) Author: Geoffrey Bache (gjb1002) Date: 2004-09-17 07:15
Logged In: YES 
user_id=769182

I have this bug on Python 2.2.3 : occasionally getting a
very similar stack when my daemon thread exits.  I don't get
the error for non-daemon threads. My problem seems pretty
similar to carlosayam's problem, described in June.
msg16407 - (view) Author: Brett Cannon (brett.cannon) * (Python committer) Date: 2004-09-17 16:33
Logged In: YES 
user_id=357491

Python 2.2 is no longer actively maintained, so I wouldn't count on the fix 
being backported.
msg16408 - (view) Author: Justin Johnson (justincjohnson) Date: 2005-11-03 18:47
Logged In: YES 
user_id=1049561

I'm seeing this problem still in Python 2.4.1 on Windows.

Python 2.4.1 (#65, Mar 30 2005, 09:13:57) [MSC v.1310 32 
bit (Intel)] on win32


C:\src\Twisted>trial -r iocp twisted.test.test_iutils
Using twisted.internet.iocpreactor reactor
Running 6 tests.
  twisted.test.test_iutils
    UtilsTestCase
      testOutput ...                                                       ?
[32;1m[OK]?[0m
      testOutputAndValue ...                                               ?
[32;1m[OK]?[0m
      testOutputSignal ...                                                 ?
[32;1m[OK]?[0m
      
testOutputWithErrorCollected ...                                     ?
[32;1m[OK]?[0m
      
testOutputWithErrorIgnored ...                                       ?
[32;1m[OK]?[0m
      testValue ...                                                        ?
[32;1m[OK]?[0m

-------------------------------------------------------------------------------
Ran 6 tests in 1.513s

PASSED (successes=6)
Exception in thread 
iocpreactor.process_waiter.ProcessWaiter.waitForProcessExi
t
pid=2156 (most likely raised during interpreter shutdown):
Traceback (most recent call last):
  File "C:\Python24\lib\threading.py", line 442, in __bootstrap
  File "C:\Python24\lib\threading.py", line 422, in run
  
File "C:\src\Twisted\twisted\internet\iocpreactor\process_wait
er.py", line 165, in doWaitForProcessExit
exceptions.TypeError: 'NoneType' object is not callable
msg16409 - (view) Author: Brett Cannon (brett.cannon) * (Python committer) Date: 2005-11-04 01:51
Logged In: YES 
user_id=357491

This is not Python's fault.  If you look at what triggers
the exception it is code from Twisted.  All of this is
happening because the threads being run by the test are not
being properly torn down before the interpreter begins to
tear itself down.

If you make sure all the threads have terminated before
ending the test I am sure the error will go away.
msg16410 - (view) Author: Justin Johnson (justincjohnson) Date: 2005-11-04 13:33
Logged In: YES 
user_id=1049561

Oh, I see.  I realized the interpreter was shutting down, but I 
thought it was shutting down because of an exception in one 
of the threads, and that the bug in Python was preventing me 
from seeing the original exception raised in the thread.  Now I 
see the light.

Thanks for the response.
History
Date User Action Args
2003-06-14 10:32:05dokocreate