Add threading.excepthook() to handle uncaught exceptions raised by Thread.run() #42148
Comments
|
simple script to reproduce: import sys, threading
def log_exception(*args):
print 'got exception %s' % (args,)
sys.excepthook = log_exception
def foo():
a = 1 / 0
threading.Thread(target=foo).start()Note that a normal traceback is printed instead of "got |
ellisj
mannequin
added
interpreter-core
|
I've just run into this, and it's very annoying. The stupid part is that threads started with the thread module don't have this problem, it's just a problem with threading.Thread()s trying to be too clever. I would vote for deleting all the code to do with exception printing in threading.py and letting the C machinery take care of it. |
|
Here is a workaround in the meantime: def install_thread_excepthook():
"""
Workaround for sys.excepthook thread bug
(https://sourceforge.net/tracker/?func=detail&atid=105470&aid=1230540&group_id=5470).
Call once from __main__ before creating any threads.
If using psyco, call psycho.cannotcompile(threading.Thread.run)
since this replaces a new-style class method.
"""
import sys
run_old = threading.Thread.run
def run(*args, **kwargs):
try:
run_old(*args, **kwargs)
except (KeyboardInterrupt, SystemExit):
raise
except:
sys.excepthook(*sys.exc_info())
threading.Thread.run = run |
|
I don't see it as a problem or as the threading module trying to be |
|
I found that the workaround suggested doesn't work when you have a Say you have a module with a socket server that spawns a thread on import sys
import logging
from functools import wraps
def myExceptHook(type, value, tb):
""" Redirect tracebacks to error log """
import traceback
rawreport = traceback.format_exception(type, value, tb)
report = '\n'.join(rawreport)
log.error(report)
sys.excepthook = myExceptHook
def use_my_excepthook(view):
""" Redirect any unexpected tracebacks """
@wraps(view)
def run(*args, **kwargs):
try:
return view(*args, **kwargs)
except:
sys.excepthook(*sys.exc_info())
return runThen in your thread subclass: class MyThread(threading.Thread):
def __init__(self, socket_conn):
threading.Thread.__init__(self)
self.my_conn = socket_conn
@use_my_excepthook
def run(self):
""" Do stuff """ |
|
Instead of using decorators, this is a slightly simpler modification to def installThreadExcepthook():
"""
Workaround for sys.excepthook thread bug
From
http://spyced.blogspot.com/2007/06/workaround-for-sysexcepthook-bug.html
(https://sourceforge.net/tracker/?func=detail&atid=105470&aid=1230540&group_id=5470).
Call once from __main__ before creating any threads.
If using psyco, call psyco.cannotcompile(threading.Thread.run)
since this replaces a new-style class method.
"""
init_old = threading.Thread.__init__
def init(self, *args, **kwargs):
init_old(self, *args, **kwargs)
run_old = self.run
def run_with_except_hook(*args, **kw):
try:
run_old(*args, **kw)
except (KeyboardInterrupt, SystemExit):
raise
except:
sys.excepthook(*sys.exc_info())
self.run = run_with_except_hook
threading.Thread.__init__ = init |
|
I too agree that I hate the thread exceptions being printed in the console I would suggest python was to error log it all to a file instead (so it does not spam up the console). I get it a lot with websocket / opus errors and it is annoying because it does not cleanup ffmpeg for me. |
|
personally these exceptions in console can be annoying to me as I hate seeing them. Exception in thread Thread-11:
Traceback (most recent call last):
File "threading.py", line 914, in _bootstrap_inner
File "E:\Users\Elsword\Desktop\DecoraterBot\Async\test\resources\Dependencies\discord\voice_client.py", line 150, in run
super().run()
File "E:\Users\Elsword\Desktop\DecoraterBot\Async\test\resources\Dependencies\discord\voice_client.py", line 108, in run
self.player(data)
File "E:\Users\Elsword\Desktop\DecoraterBot\Async\test\resources\Dependencies\discord\voice_client.py", line 669, in play_audio
sent = self.socket.sendto(packet, (self.endpoint_ip, self.voice_port))
OSError: [WinError 10055] An operation on a socket could not be performed because the system lacked sufficient buffer space or because a queue was full
Exception in thread Thread-21:
Traceback (most recent call last):
File "threading.py", line 914, in _bootstrap_inner
File "E:\Users\Elsword\Desktop\DecoraterBot\Async\test\resources\Dependencies\discord\voice_client.py", line 150, in run
super().run()
File "E:\Users\Elsword\Desktop\DecoraterBot\Async\test\resources\Dependencies\discord\voice_client.py", line 108, in run
self.player(data)
File "E:\Users\Elsword\Desktop\DecoraterBot\Async\test\resources\Dependencies\discord\voice_client.py", line 669, in play_audio
sent = self.socket.sendto(packet, (self.endpoint_ip, self.voice_port))
OSError: [WinError 10038] An operation was attempted on something that is not a socket |
|
Ok, so I just found out you can bypass thread exceptions by wraping the line that actually runs the threads in a try/except block and then using the logging module to log it to a file instead of the console. |
|
Does this affect threads started with the multiprocessing library as well? |
|
Just confirmed, this does affect multiprocessing. script to reproduce: import sys, multiprocessing
def log_exception(*args):
print 'got exception %s' % (args,)
sys.excepthook = log_exception
def foo():
a = 1 / 0multiprocessing.Process(target=foo).start() again, just a normal traceback instead of "got exception" |
|
Apparently the |
pitrou
added
3.7 (EOL)
|
Thank you Antoine Pitrou, I was able to disable this behavior by commenting out some lines of code in 'traceback' and replacing them with the appropriate call to 'sys.excepthook'. Note you also have to comment out a few lines in "Modules/_threadmodule.c" to correspond to this change or else that file complains that there wasn't the expected output printed to stderr. |
|
Matt, do you want to post your patch here? |
|
I've added a PR with a patch I developed during the EuroPython 2018 sprint. I've fixed this issue in a way that is more or less consistent with how '_thread' threads interact with sys.excepthook, but I haven't added the log line they print to sys.stderr about an unhandled exception in a thread: I can add these messages if they are needed. I'd like to mention the issue I discussed with Victor Stinner at the sprints (adding Victor to the nosy list as he requested). The fix could possibly break the de facto contract that has been there for ages that 'theading' threads don't invoke sys.excepthook on uncaught exceptions. If the fact that sys.execepthook doesn't work with threading is considered a feature, then an alternative solution could be a new threading-specific hook: threading.excepthook. |
|
No, I think this is a bug that deserves fixing, at least in 3.8. |
|
Would it be possible to modify the default implementation of sys.excepthook to have a different output when it's not called from the main thread? Mimick the current traceback from threads. Would it be possible to call threading.current_thread() from the default sys.excepthook? The problem is to get the threading module and to decide how to handle error on getting the current thread. An alternative would be to introduce a new hook to log exceptions in threads, ex: sys.threadexcepthook. That hoook would take a 4th parameter. But Andrey Vlasovskikh didn't like this idea. |
I agree it's a good idea to mimic what Unhandled exception in thread started by <function <lambda> at 0x7f6769ca8e18> for all the exceptions: not caught by the sys.excepthook **and** caught by the sys.exceptook.
I'm overall OK with this idea, but I would prefer to make the existing |
|
My concern is more about backward compatibility. Documentation is one thing, but usually users rely on the actual implementation, not on the documentation, to define what is the Python behaviour. Would you mind to open a thread on python-dev about this change? I don't want to take the responsibility alone of such change :-) Moreover, I don't really have the bandwidth to work on this specific issue :-( |
|
To add one more use case for this: concurrent.futures.Future.add_done_callback() currently ignores exceptions for the callback and just logs them which is easy to miss. I assume because it's not clear when and in which thread it gets called, and there is no "right" way to handle it. It would be nice if it would call something like sys.excepthook instead. |
|
See also bpo-36829: I just added sys.unraisablehook(). |
|
I wrote PR 13515 which adds threading.excepthook(). I chose to call threading.excepthook() even when run() raises SystemExit. In this case, threading.excepthook() simply does nothing. The idea is to really give the full control when threading.excepthook() is overriden. For example, log a warning when run() raises SystemExit. By the way, is it really a good idea to call sys.exit() from a thread? It sounds like a bug that should be reported, and not silently ignored, no? Differences between sys.excepthook() and threading.excepthook():
Thread._stderr was added by bpo-754449: commit cc4e935 Note: When sys.stderr is None, threading.excepthook() avoids the traceback module and renders the exception itself. Maybe threading.excepthook() should be reimplemented in C to make it even more reliable and more correct, especially during Python shutdown. Only daemon threads are impacted: Python finalization (Py_Finalize() C function) starts by calling threading._shutdown() which joins all non-daemon threads. IMHO the threading.Thread semantics is too different than sys.excepthook() to reuse sys.excepthook() to handle threading.Thread.run() exception. Another explanation is that sadly sys.excepthook() API uses exactly 3 positional-only arguments, and so the API cannot be easily extended to get a thread argument. When I designed sys.unraisablehook(), I chose to pass only one argument which has attributes, to prevent this issue. I'm not comfortable to attempt to modify sys.excepthook() to make it behave differently if it's called from the main thread or from a different thread. It would have to call threading.current_thread().name to get the name of the current thread. Let's say that in Python 3.8 threading.Thread now calls sys.execpthook() to handle uncaught run() exception. All applications which override sys.excepthook() on purpose will behave differently: start to log exceptions from threads. But existing code is unlikely to be prepared to implement black magic to check if we are a "thread" or the main thread, to decide if we should display a thread name, and also the "black magic" to get the current thread name. One of my concern of reusing sys.excepthook to display threading exceptions is that adding more code to handle threads is a risk of raising a new exception while logging a threading exception :-( IMHO threading.excepthook() is safer since it already has access to the thread. |
|
I dislike PR 8610: threading.Thread doesn't call sys.excepthook to handle run() exception by default, it only calls sys.excepthook if it's overridden. Moreover, when sys.excepthook is called, the hook doesn't get access to the thread object :-( |
|
About threading.excepthook() API, maybe we should not reproduce sys.excepthook() API but instead reuse something closer to sys.unraisablehook() API: use a single parameter which has attributes. It would allow to pass more parameters as new attributes in the future, maybe some new "optional" parameters (None by default). For example, we can imagine calling threading.excepthook() to handle threading.excepthook() failure. We would need an argument to prevent an infine loop :-) |
Note that PyErr_Print() and PyErr_PrintEx() can be called in threads, and CPython itself uses it in some places which can be called in threads and I also use it in thread callbacks in C extensions I work on (PyGObject and pycairo for example). Nothing states currently that it's not allowed to call it in such cases :( |
You can get it with threading.current_thread(), no? |
|
There is a special case. If a thread calls os.fork() and Thread.run() raises an exception, the thread name is still logged even if there is only 1 thread after fork. Try attached fork_thread.py. Output on Python 3.7: main thread: spawn fork thread
thread: before fork [<_MainThread(MainThread, started 140623217481536)>, <ForkThread(Thread-1, started 140622996952832)>]
thread: after fork [<ForkThread(Thread-1, started 140622996952832)>]
thread: after fork: raise
Exception in thread Thread-1:
Traceback (most recent call last):
File "/usr/lib64/python3.7/threading.py", line 917, in _bootstrap_inner
self.run()
File "fork_thread.py", line 17, in run
raise Exception("what happens here?")
Exception: what happens here?main thread: done Moreover, threading.Thread silently ignores SystemExit in run() even if it's the only remaining thread (main thread is gone after fork). I don't think that we *have to* change the current behavior. It's just that we have to take it in account if we modify how exceptions are handled. |
|
I rewrote my PR 13515:
-- First I also added a "stderr" argument to the arguments passed to threading.excepthook(): sys.stderr, or an old copy of sys.stderr if sys.stderr no longer exists or is set to None. But I decided to keep this as an implementation detail instead. |
|
If you want to reuse sys.excepthook to handle uncaught Thread.run() exception, you can now write: def hook(args):
if args.exc_type == SystemExit:
return
sys.excepthook(args.exc_type, args.exc_value, args.exc_traceback)
threading.excepthook = hookTry attached sys_threading_excepthook.py for a full example. |
|
I propose to add the Thead.excepthook() method with the signature compatible with sys.excepthook(). This will allow to set easily per-thread hooks and a global hook. |
|
A Thread.excepthook() method does not allow to notify exceptions raised in C-created threads ("dummy threads"). Also, as I said already, you can get the current thread by calling threading.current_thread() in the except hook. There is no need to pass it explicitly to the except hook. |
The main difference between sys.excepthook and threading.excepthook is that the threading hook displays the thread name. Which output do you expect if you don't pass a threading.Thread object (which has a 'name' attribute)? The thread identifier from _thread.get_ident()? I can easily modify the default hook implementation to support args.thread=None and displays _thread.get_ident() as the name instead.
I understand that your plan is to use sys.excepthook to handle threading.Thread uncaught exception. My main concern is that sys.excepthook can fail on importing the threading module. One solution would be to import threading when the sys module is created and keep a strong reference to threading.current_thread(). But I dislike this idea. I already raised my concern, but so far, you didn't explain how you plan to fix this practical issue. Moreover, the current threading code is quite complex. My guess is that this complexity is needed to display exception very late during Python shutdown, when module attributes are set to None and import no longer works. I would prefer to not move this complexity into sys.excepthook which has currently a simple implementation. -- Daemon threads are evil. We should drop this nasty feature... but I would prefer to not block this issue by the removal of daemon threads, since I'm sure that a lot of code rely on them and so it will be really hard to really remove them. |
|
Serhiy Storchaka:
I don't see the relationship between the API (signature) and the ability to set a per-thread hook. I'm not convinced that a per-thread hook is needed. My proposed global threading.excepthook gets a thread parameter which allows a custom hook to implement a different behavior depending on the thread. You can use a different behavior depending on the thread name, depending on a custom Thread attribute, etc. Would it be acceptable for first add a global hook and see later if a per-thread hook is needed? |
|
Sorry, I had overlooked the issue with global variables at shutdown. Though that issue only occurs with daemonic threads, since non-daemonic threads are joined before global variables are cleared. In any case, I think the namedtuple / structseq solution is elegant, because we can add additional information later (the user must only be careful not to use tuple unpacking). |
|
Le 25/05/2019 à 23:09, STINNER Victor a écrit :
Indeed, if you write your own Thread class, you can add a try...except The only way a per-thread hook could be useful is if you could set it |
Exactly. You can already do you best in your run() method to handle exceptions. threading.excepthook is only there is everything else already failed. FYI in my implementation, if threading.excepthook raises a new exception, it's also handled... by sys.excepthook this time ;-)
I discuss threading excepthook with Pablo and he asked me if it would be possible to have a different behavior depending if the thread is spawn by my application or by "third party code". Using threading.excepthook, you can mark your threads that you spawn directly using a specific name, a special attribute, or you may even track them in a list (maybe using weak references). If sys.excepthook is used to handle threading exceptions, you call threading.current_thread(), but then we come back to the issue to "dying" Python: exception which occurs late in Python finalization, when most modules are already cleared and import no longer works. |
|
Antoine Pitrou:
I modified my PR to use the threading identitifer (threading.get_ident()) as the thread name if args.thread is None. |
I used the same design for the new sys.unraisablehook in bpo-36829 and I'm already working on adding a new 'err_msg' field to the argument passed to this took: PR 13488 :-) I was trapped in the past when I had to modify warnings "hooks" (warnings.showwarning and warnings.formatwarning) when I had to add a new 'source' parameter. I had to write wrappers which are fragile, to keep the backward compatibility.
threading.excepthook doesn't mention the compatibility with tuple on purpose. It only documents attributes with their names. |
|
New changeset cd590a7 by Victor Stinner in branch 'master': |
|
It took 14 years, but this issue is now fixed ;-) I close it. Python 3.8 beta 1 will be released in a few days with threading.excepthook(): please test it to ensure that it works as you expected. As a follow-up, I created bpo-37069: "regrtest: log unraisable exceptions and uncaught thread exceptions". |
|
If we want to support low-level threads created by start_new_thread() we should call excepthook() from t_bootstrap instead of Thread._bootstrap_inner. Otherwise implementing excepthook() as a Thread method would be more convenient. |
vstinner
changed the title
vstinner
changed the title
I created bpo-37076: "_thread.start_new_thread(): call sys.unraisablehook() to handle uncaught exceptions". |
…ose (#16074) Fixes #16070 Summary of the issue: To log unhandled exceptions NVDA relies on a custom except hook installed when initializing logging. Until Python 3.8 custom except hooks were not called for exception which occurred outside of the main thread - they were simply written to stderr (see python/cpython#42148). This worked well for NVDA, since it replaces stderr with a custom object which logs everything written to stderr, so the exceptions ended up in our log, just in a different way. In Python 3.8 it become possible to install a custom hook which gets called for exceptions which are raised in non main threads, but as part of this change the way in which they are handled by default has changed - the traceback is written to stderr line by line, rather than as a single call to print as it used to be. For NVDA it means that each line of the traceback results in a separate log entry making logging extremely noisy. Description of user facing changes Exception from threads different than the main one are logged in the same way as they were in NVDA 2023.3. Description of development approach A custom except hook for exception raised in threads was introduced. It logs them as an exception with additional information explaining in which thread they were raised. Testing strategy: Performed STR from #16070 - ensured that logging looks similarly to the one from 2023.3 and that single exception results in a single log entry. Known issues with p
…ose (nvaccess#16074) Fixes nvaccess#16070 Summary of the issue: To log unhandled exceptions NVDA relies on a custom except hook installed when initializing logging. Until Python 3.8 custom except hooks were not called for exception which occurred outside of the main thread - they were simply written to stderr (see python/cpython#42148). This worked well for NVDA, since it replaces stderr with a custom object which logs everything written to stderr, so the exceptions ended up in our log, just in a different way. In Python 3.8 it become possible to install a custom hook which gets called for exceptions which are raised in non main threads, but as part of this change the way in which they are handled by default has changed - the traceback is written to stderr line by line, rather than as a single call to print as it used to be. For NVDA it means that each line of the traceback results in a separate log entry making logging extremely noisy. Description of user facing changes Exception from threads different than the main one are logged in the same way as they were in NVDA 2023.3. Description of development approach A custom except hook for exception raised in threads was introduced. It logs them as an exception with additional information explaining in which thread they were raised. Testing strategy: Performed STR from nvaccess#16070 - ensured that logging looks similarly to the one from 2023.3 and that single exception results in a single log entry. Known issues with p
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:
bugs.python.org fields:
The text was updated successfully, but these errors were encountered: