How can I modify a Python traceback object when raising an exception?
I’m working on a Python library used by third-party developers to write extensions for our core application. I’d like to know if it’s possible to modify the traceback when raising exceptions, so the last stack frame is the call to the library function in the developer’s code, rather than the line in the library that raised the exception. There are also a few frames at the bottom of the stack containing references to functions used when first loading the code that I’d ideally like to remove too. Thanks in advance for any advice!
7 Answers 7
You can remove the top of the traceback easily with by raising with the tb_next element of the traceback:
except: ei = sys.exc_info() raise ei[0], ei[1], ei[2].tb_next tb_next is a read_only attribute, so I don’t know of a way to remove stuff from the bottom. You might be able to screw with the properties mechanism to allow access to the property, but I don’t know how to do that.
That’s not what he’s asking. The causal chain was never mentioned. This guy wants to change, what is shown in the stack trace. put in some extra «virtual calls» etc.
Take a look at what jinja2 does here:
It’s ugly, but it seems to do what you need done. I won’t copy-paste the example here because it’s long.
Starting with Python 3.7, you can instantiate a new traceback object and use the .with_traceback() method when throwing. Here’s some demo code using either sys._getframe(1) (or a more robust alternative) that raises an AssertionError while making your debugger believe the error occurred in myassert(False) : sys._getframe(1) omits the top stack frame.
What I should add is that while this looks fine in the debugger, the console behavior unveils what this is really doing:
Traceback (most recent call last): File ".\test.py", line 35, in myassert_false() File ".\test.py", line 31, in myassert_false myassert(False) File ".\test.py", line 26, in myassert raise AssertionError().with_traceback(back_tb) File ".\test.py", line 31, in myassert_false myassert(False) AssertionError Rather than removing the top of the stack, I have added a duplicate of the second-to-last frame.
Anyway, I focus on how the debugger behaves, and it seems this one works correctly:
"""Modify traceback on exception. See also https://github.com/python/cpython/commit/e46a8a """ import sys import types def myassert(condition): """Throw AssertionError with modified traceback if condition is False.""" if condition: return # This function . is not guaranteed to exist in all implementations of Python. # https://docs.python.org/3/library/sys.html#sys._getframe # back_frame = sys._getframe(1) try: raise AssertionError except AssertionError: traceback = sys.exc_info()[2] back_frame = traceback.tb_frame.f_back back_tb = types.TracebackType(tb_next=None, tb_frame=back_frame, tb_lasti=back_frame.f_lasti, tb_lineno=back_frame.f_lineno) raise AssertionError().with_traceback(back_tb) def myassert_false(): """Test myassert(). Debugger should point at the next line.""" myassert(False) if __name__ == "__main__": myassert_false() Log exception with traceback in Python
Use logging.exception from within the except: handler/block to log the current exception along with the trace information, prepended with a message.
import logging LOG_FILENAME = '/tmp/logging_example.out' logging.basicConfig(filename=LOG_FILENAME, level=logging.DEBUG) logging.debug('This message should go to the log file') try: run_my_stuff() except: logging.exception('Got exception on main handler') raise Now looking at the log file, /tmp/logging_example.out :
DEBUG:root:This message should go to the log file ERROR:root:Got exception on main handler Traceback (most recent call last): File "/tmp/teste.py", line 9, in run_my_stuff() NameError: name 'run_my_stuff' is not defined Looked over the django code for this, and I’m assuming the answer is no, but is there a way to limit the traceback to a certain amount of either characters or depth? The problem is that for large tracebacks, it takes pretty long.
Note that if you define a logger with logger = logging.getLogger(‘yourlogger’) you have to write logger.exception(‘. ‘) to have this working.
Note that for certain external apps, such as Azure insight, the trackback is not stored in the logs. It is then necessary to pass them explicitly to the message string as show below.
I had always thought logging.exception(. ) (or logger.exception(. ) if so configured) would do it. But I’ve become a bit confused with this method exception in the context of an exception hook handler: it doesn’t seem to print out the traceback in this context. Beginning to suspect your calling code has to be in an except block for this to work.
Use exc_info options may be better, remains warning or error title:
try: # coode in here except Exception as e: logging.error(e, exc_info=True) This is identical to logging.exception, with the exception that the type is redundantly logged twice. Just use logging.exception unless you want a level other than error.
logging.exception is calling logging.error so theoretically this could be written as logging.exception(e) and one can still avoid passing in a message.
My job recently tasked me with logging all the tracebacks/exceptions from our application. I tried numerous techniques that others had posted online such as the one above but settled on a different approach. Overriding traceback.print_exception .
I have a write up at http://www.bbarrows.com/ That would be much easier to read but Ill paste it in here as well.
When tasked with logging all the exceptions that our software might encounter in the wild I tried a number of different techniques to log our python exception tracebacks. At first I thought that the python system exception hook, sys.excepthook would be the perfect place to insert the logging code. I was trying something similar to:
import traceback import StringIO import logging import os, sys def my_excepthook(excType, excValue, traceback, logger=logger): logger.error("Logging an uncaught exception", exc_info=(excType, excValue, traceback)) sys.excepthook = my_excepthook This worked for the main thread but I soon found that the my sys.excepthook would not exist across any new threads my process started. This is a huge issue because most everything happens in threads in this project.
After googling and reading plenty of documentation the most helpful information I found was from the Python Issue tracker.
The first post on the thread shows a working example of the sys.excepthook NOT persisting across threads (as shown below). Apparently this is expected behavior.
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() The messages on this Python Issue thread really result in 2 suggested hacks. Either subclass Thread and wrap the run method in our own try except block in order to catch and log exceptions or monkey patch threading.Thread.run to run in your own try except block and log the exceptions.
The first method of subclassing Thread seems to me to be less elegant in your code as you would have to import and use your custom Thread class EVERYWHERE you wanted to have a logging thread. This ended up being a hassle because I had to search our entire code base and replace all normal Threads with this custom Thread . However, it was clear as to what this Thread was doing and would be easier for someone to diagnose and debug if something went wrong with the custom logging code. A custome logging thread might look like this:
class TracebackLoggingThread(threading.Thread): def run(self): try: super(TracebackLoggingThread, self).run() except (KeyboardInterrupt, SystemExit): raise except Exception, e: logger = logging.getLogger('') logger.exception("Logging an uncaught exception") The second method of monkey patching threading.Thread.run is nice because I could just run it once right after __main__ and instrument my logging code in all exceptions. Monkey patching can be annoying to debug though as it changes the expected functionality of something. The suggested patch from the Python Issue tracker was:
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 It was not until I started testing my exception logging I realized that I was going about it all wrong.
somewhere in my code. However, wrapping a a method that called this method was a try except block that printed out the traceback and swallowed the exception. This was very frustrating because I saw the traceback bring printed to STDOUT but not being logged. It was I then decided that a much easier method of logging the tracebacks was just to monkey patch the method that all python code uses to print the tracebacks themselves, traceback.print_exception. I ended up with something similar to the following:
def add_custom_print_exception(): old_print_exception = traceback.print_exception def custom_print_exception(etype, value, tb, limit=None, file=None): tb_output = StringIO.StringIO() traceback.print_tb(tb, limit, tb_output) logger = logging.getLogger('customLogger') logger.error(tb_output.getvalue()) tb_output.close() old_print_exception(etype, value, tb, limit=None, file=None) traceback.print_exception = custom_print_exception This code writes the traceback to a String Buffer and logs it to logging ERROR. I have a custom logging handler set up the ‘customLogger’ logger which takes the ERROR level logs and send them home for analysis.