Why don't I get a full traceback from a saved exception - and how do I get and save the full trace?
I have a user submitted data validation interface for a scientific site in django, and I want the user to be able to submit files of scientific data that will aid them in resolving simple problems with their data before they're allowed to make a formal submission (to reduce workload on the curators who actually load the data into our database).
The validation interface re-uses the loading code, which is good for code re-use. It has a "validate mode" that doesn't change the database. Everything is in an atomic transaction block and it gets rolled back in any case when it runs in validate mode.
I'm in the middle of a refactor to alleviate a problem. The problem is that the user has to submit the files multiple times, each time, getting the next error. So I've been refining the code to be able to "buffer" the exceptions in an array and only really stop if any error makes further processing impossible. So far, it's working great.
Since unexpected errors are expected in this interface (because the data is complex and lab users are continually finding new ways to screw up the data), I am catching and buffering any exception and intend to write custom exception classes for each case as I encounter them.
The problem is that when I'm adding new features and encounter a new error, the tracebacks in the buffered exceptions aren't being fully preserved, which makes it annoying to debug - even when I change the code to raise and immediately catch the exception so I can add it to the buffer with the traceback. For example, in my debugging, I may get an exception from a large block of code, and I can't tell what line it is coming from.
I have worked around this problem by saving the traceback as a string inside the buffered exception object, which just feels wrong. I had to play around in the shell to get it to work. Here is my simple test case to demonstrate what's happening. It's reproducible for me, but apparently not for others who try this toy example - and I don't know why:
import traceback class teste(Exception): """This is an exception class I'm going to raise to represent some unanticipated exception - for which I will want a traceback.""" pass def buf(exc, args): """This represents my method I call to buffer an exception, but for this example, I just return the exception and keep it in main in a variable. The actual method in my code appends to a data member array in the loader object.""" try: raise exc(*args) except Exception as e: # This is a sanity check that prints the trace that I will want to get from the buffered exception object later print("STACK:") traceback.print_stack() # This is my workaround where I save the trace as a string in the exception object e.past_tb = "".join(traceback.format_stack()) return e
The above example raises the exception inside
buf. (My original code supports both raising the exception for the first time and buffering an already raised and caught exception. In both cases, I wasn't getting a saved full traceback, so I'm only providing the one example case (where I raise it inside the
And here's what I see when I use the above code in the shell. This first call shows my sanity check - the whole stack, which is what I want to be able to access later:
In : es = buf(teste, ["This is a test"]) STACK: File "/Users/rleach/PROJECT-local/TRACEBASE/tracebase/manage.py", line 22, in <module> main() File "/Users/rleach/PROJECT-local/TRACEBASE/tracebase/manage.py", line 18, in main execute_from_command_line(sys.argv) File "/Users/rleach/PROJECT-local/TRACEBASE/tracebase/.venv/lib/python3.9/site-packages/django/core/management/__init__.py", line 419, in execute_from_command_line utility.execute() File "/Users/rleach/PROJECT-local/TRACEBASE/tracebase/.venv/lib/python3.9/site-packages/django/core/management/__init__.py", line 413, in execute self.fetch_command(subcommand).run_from_argv(self.argv) File "/Users/rleach/PROJECT-local/TRACEBASE/tracebase/.venv/lib/python3.9/site-packages/django/core/management/base.py", line 354, in run_from_argv self.execute(*args, **cmd_options) File "/Users/rleach/PROJECT-local/TRACEBASE/tracebase/.venv/lib/python3.9/site-packages/django/core/management/base.py", line 398, in execute output = self.handle(*args, **options) File "/Users/rleach/PROJECT-local/TRACEBASE/tracebase/.venv/lib/python3.9/site-packages/django/core/management/commands/shell.py", line 100, in handle return getattr(self, shell)(options) File "/Users/rleach/PROJECT-local/TRACEBASE/tracebase/.venv/lib/python3.9/site-packages/django/core/management/commands/shell.py", line 36, in ipython start_ipython(argv=) File "/Users/rleach/PROJECT-local/TRACEBASE/tracebase/.venv/lib/python3.9/site-packages/IPython/__init__.py", line 126, in start_ipython return launch_new_instance(argv=argv, **kwargs) File "/Users/rleach/PROJECT-local/TRACEBASE/tracebase/.venv/lib/python3.9/site-packages/traitlets/config/application.py", line 846, in launch_instance app.start() File "/Users/rleach/PROJECT-local/TRACEBASE/tracebase/.venv/lib/python3.9/site-packages/IPython/terminal/ipapp.py", line 356, in start self.shell.mainloop() File "/Users/rleach/PROJECT-local/TRACEBASE/tracebase/.venv/lib/python3.9/site-packages/IPython/terminal/interactiveshell.py", line 566, in mainloop self.interact() File "/Users/rleach/PROJECT-local/TRACEBASE/tracebase/.venv/lib/python3.9/site-packages/IPython/terminal/interactiveshell.py", line 557, in interact self.run_cell(code, store_history=True) File "/Users/rleach/PROJECT-local/TRACEBASE/tracebase/.venv/lib/python3.9/site-packages/IPython/core/interactiveshell.py", line 2914, in run_cell result = self._run_cell( File "/Users/rleach/PROJECT-local/TRACEBASE/tracebase/.venv/lib/python3.9/site-packages/IPython/core/interactiveshell.py", line 2960, in _run_cell return runner(coro) File "/Users/rleach/PROJECT-local/TRACEBASE/tracebase/.venv/lib/python3.9/site-packages/IPython/core/async_helpers.py", line 78, in _pseudo_sync_runner coro.send(None) File "/Users/rleach/PROJECT-local/TRACEBASE/tracebase/.venv/lib/python3.9/site-packages/IPython/core/interactiveshell.py", line 3185, in run_cell_async has_raised = await self.run_ast_nodes(code_ast.body, cell_name, File "/Users/rleach/PROJECT-local/TRACEBASE/tracebase/.venv/lib/python3.9/site-packages/IPython/core/interactiveshell.py", line 3377, in run_ast_nodes if (await self.run_code(code, result, async_=asy)): File "/Users/rleach/PROJECT-local/TRACEBASE/tracebase/.venv/lib/python3.9/site-packages/IPython/core/interactiveshell.py", line 3457, in run_code exec(code_obj, self.user_global_ns, self.user_ns) File "<ipython-input-5-92f4a0db918d>", line 1, in <module> es = buf(teste, ["This is a test"]) File "<ipython-input-2-86e515dc1ec1>", line 6, in buf traceback.print_stack()
But this is what I see when I want to see the original traceback from the
es object (i.e. the buffered exception) later. It only has the last item from the traceback. This is exactly what I see in the original source code - a single item for the line of code inside the buffer method:
In : traceback.print_exception(type(es), es, es.__traceback__) Traceback (most recent call last): File "<ipython-input-2-86e515dc1ec1>", line 3, in buf raise exc(*args) teste: This is a test
My workaround suffices for now, but I'd like to have a proper traceback object.
I debugged the issue by re-cloning our repo in a second directory to make sure I hadn't messed up my sandbox. I guess I should try this on another computer too - my office mac. But can anyone point me in the right direction to debug this issue? What could be the cause for losing the full traceback?
Python has a really weird way of building exception tracebacks. You might expect it to build the traceback when the exception is created, or when it's raised, but that's not how it works.
Python builds a traceback as an exception propagates. Every time the exception propagates up to a new stack frame, a traceback entry for that stack frame is added to the exception's traceback.
This means that an exception's traceback only goes as far as the exception itself propagates. If you catch it (and don't reraise it), the traceback only goes up to the point where it got caught.
Unfortunately, your workaround is about as good as it gets. You're not really losing the full traceback, because a full traceback was never created. If you want full stack info, you need to record it yourself, with something like the
traceback.format_stack() function you're currently using.