Exceptions when a thread exits

@tim-one

BPO	754449
Nosy	@tim-one, @brettcannon, @doko42
Files	tracer.py: Contains trace_currentThread which logs to stderr when (threading.)?currentThread becomes None

^{Note: these values reflect the state of the issue at the time it was migrated and might not reflect the current state.}

Show more details

GitHub fields:

assignee = 'https://github.com/brettcannon'
closed_at = <Date 2005-11-04.13:33:25.000>
created_at = <Date 2003-06-14.10:32:05.000>
labels = ['interpreter-core']
title = 'Exceptions when a thread exits'
updated_at = <Date 2005-11-04.13:33:25.000>
user = 'https://github.com/doko42'

bugs.python.org fields:

activity = <Date 2005-11-04.13:33:25.000>
actor = 'justincjohnson'
assignee = 'brett.cannon'
closed = True
closed_date = None
closer = None
components = ['Interpreter Core']
creation = <Date 2003-06-14.10:32:05.000>
creator = 'doko'
dependencies = []
files = ['919']
hgrepos = []
issue_num = 754449
keywords = []
message_count = 26.0
messages = ['16385', '16386', '16387', '16388', '16389', '16390', '16391', '16392', '16393', '16394', '16395', '16396', '16397', '16398', '16399', '16400', '16401', '16402', '16403', '16404', '16405', '16406', '16407', '16408', '16409', '16410']
nosy_count = 7.0
nosy_names = ['tim.peters', 'brett.cannon', 'doko', 'jgoerzen', 'carlosayam', 'gjb1002', 'justincjohnson']
pr_nums = []
priority = 'low'
resolution = 'fixed'
stage = None
status = 'closed'
superseder = None
type = None
url = 'https://bugs.python.org/issue754449'
versions = ['Python 2.3']

[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

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?

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

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.

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.

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.

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?

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.

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.

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.

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.

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.

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.

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.

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.

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?

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.

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.

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.

Logged In: YES
user_id=357491

Python 2.2 is no longer actively maintained, so I wouldn't count on the fix
being backported.

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

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.

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.

Navigation Menu

Repository navigation

Exceptions when a thread exits #38648

3 remaining items

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Exceptions when a thread exits #38648

Description

Activity

doko42 commented on Jun 14, 2003

brettcannon commented on Jun 15, 2003

doko42 commented on Jun 15, 2003

brettcannon commented on Jun 15, 2003

tim-one commented on Jun 16, 2003

brettcannon commented on Jun 16, 2003

brettcannon commented on Jun 16, 2003

jgoerzen commented on Jun 16, 2003

brettcannon commented on Feb 10, 2004

3 remaining items

brettcannon commented on Mar 8, 2004

brettcannon commented on May 16, 2004

brettcannon commented on May 17, 2004

carlosayam commented on Jun 3, 2004

brettcannon commented on Jun 3, 2004

tim-one commented on Jun 3, 2004

carlosayam commented on Jun 3, 2004

brettcannon commented on Jul 3, 2004

brettcannon commented on Jul 3, 2004

gjb1002 commented on Sep 17, 2004

brettcannon commented on Sep 17, 2004

justincjohnson commented on Nov 3, 2005

brettcannon commented on Nov 4, 2005

justincjohnson commented on Nov 4, 2005

Metadata

Metadata

Assignees

Labels

Projects

Milestone

Relationships

Development

Issue actions