Why don't I get a full traceback from a saved exception - and how do I get and save the full tr-CodePudding

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 buf method).

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 [5]: 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 [8]: 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?

CodePudding user response：

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.