The suggestion is to add something roughly like this:

def print_full_exception(type, value, traceback, file):
.   _print(sys.stderr, 'Traceback (most recent call
last):')
.   print_stack(traceback.tb_frame.f_back, file=file)
.   print_tb(traceback, file=file)
.
.   lines = format_exception_only(type, value)
.   for line in lines[:-1]:
.       _print(file, line, ' ')
.   _print(file, lines[-1], '')


to the traceback module, to print the exception not
just downward from the calling point, but also upward
all the way to the top of the stack. This would be
useful in, e.g. logging, where exceptions are caught
and printed, but right now no information is given as
to where they occurred in user code.

Logged In: YES 
user_id=987664

Hmmm, my indentation didn't work very well. Hopefully you
should be able to figure it out though. :)

Logged In: YES 
user_id=987664

Here's some test code that might indicate how this is useful:

def x(n=0):
.....try:
..........y(n+1)
.....except:
..........ei = sys.exc_info()
..........print_full_exception(ei[0], ei[1], ei[2], sys.stderr)

def y(n):
.....if n > 10:
..........raise IOError, "test"
.....
.....x(n+1)

x()

What's the status of this (imo quite useful) new traceback function ?
Shall I provide some help ?

It would be very nice if logging.info('...', exc_info=True)
shows the calling/upper frames, too.

Related #9427

Here's a proof of concept patch that adds a 'fullstack' option to print_exception.  The problem with this concept is what happens when you use it on an exception caught at the top level of a module.  I'm not entirely clear on why tracebacks work the way they do, so I don't know how to fix that case (it's also late, maybe in the morning I'll be able to figure it out :)

Writing unit tests for this may also be a bit tricky.

I'm raising the priority to normal because I think this would be really useful for logging, as pointed out by Thomas.

David Murray, where is the patch?

Morning does make a difference.  Revised patch that also works at the top level of a module.  (Let's see if I can manage to actually attach it this time...)

Updated patch with unit tests and docs.  I realized that I'd forgotten to test chained exceptions.  It looks like when the Interpreter prints a traceback all the exceptions in the chain are printed fully, which makes sense.  Adopting that strategy for this patch simplified it into three lines (the signature change and an if/print in the loop).

I'm pretty satisfied with this patch.  I have two questions: should the 'fullstack' option really be implemented in print_tb instead?  And is there a better name for the option?  Would just 'full' be acceptable?

This functionality would be useful in format_exception(), too.

I prefer "fullstack" to "full" as it's clearer what the 'full' pertains to. An alternative might be "upperframes" or "allframes".

Is that normal to have two methods "test_full_traceback_is_full" at the same place, in full_traceback.patch / r.david.murray / 2010-08-04 02:32 ?

format_exception should have the same semantic as print_exception indeed.

No, that would be a bug, thanks.

Also thanks for reminding me about this issue.

I like 'allframes', so I changed to that.  The updated patch also adds the allframes parameter to format_exception.

In going over the tests I realized that I'm not sure the output for the case of chain=True is correct.  Opinions?  If it is not correct it is not obvious to me how to fix it.

Indeed I don't understand the following part :

+                Traceback (most recent call last):
+                  File "testmod.py", line 16, in <module>
+                    {exception_action}
+                  File "testmod.py", line 6, in foo
+                    bar()
+                  File "testmod.py", line 11, in bar
+                    raise Exception
+                Exception

Why does the f_back of the first exception, when chain=True, leads back to the {exception_action} part, in the except: black, instead of the initial foo() call inside the try: block ?

The regression tests are failing for me, see

http://gist.github.com/618117

Also, "fullstack" remains in one place in the docs. Should now say "allframes".

Pascal: my question exactly.  The question is whether the code is accurately reflecting the state of the python stack at exception time (which it seems like it ought to), in which case I don't understand how Python handles the chained exception, or it doesn't, in which case (more likely) I'm not understanding how the stack frame is put together.

Vinay: so in your run the subprocess call is not producing the final 'exception detail' line...it looks like the last line of the output from subprocess is getting lost.  I've updated the patch to add a p.wait() before the assert...can you see if that fixes it?  I also fixed the doc nit, thanks.

After giving this some thought, I'm sure that the observed results are not what we want, so I've changed the test to be the result that we want.  I haven't been able to figure out what is causing it, and am starting to wonder if it represents an actual bug in exception handling.

It's still failing - the existing gist has been updated with the output from the new run:

http://gist.github.com/618117

vinay: duh.  I'm using a debug build and my test is slicing off the refount line.  I think there's a helping in test.support for that...

David, I don't think it's that - I think it's the subprocess comms. This works:

    def _do_test(self, program, exc_text):
        with open(self.testfn, 'w') as testmod:
            testmod.writelines(program.format(
                exception_action=self.exception_action))
        p = subprocess.Popen([sys.executable, 'testmod.py'],
                              stderr=subprocess.PIPE)
        streams = p.communicate()
        v1 = streams[1].decode('utf-8') # this shouldn't be hardcoded!
        v2 = exc_text.format(exception_action=self.exception_action)
        self.assertEqual(v1, v2)

But I don't think the 'utf-8' encoding should be hardcoded. Not sure what to use - sys.getfilesystemencoding()? locale.getpreferredencoding()? 

Decisions, decisions :-(

Also, the use of literal 'testmod.py' in _do_test should probably be replaced by self.testfn.

On reflection, perhaps we should use sys.stdin.encoding to decode the value received from the subprocess. What do you think?

Attached a patch which works on my machine.

Vinay, your example with communicate only works because you removed the [:-1].  If you run your version against a debug build, the tests will fail.

I'm updating the patch with a version that works with both a non-debug and a debug build, and adds an additional test that shows that the chained full traceback fails even if the exception handler is not at the top level.  Tomorrow I'll post a request for help to python-dev, since I've nowhere near the knowledge of the CPython internals needed to figure out what is going on here.  (It is possible the traceback is in fact correct, but if so it is certainly unexpected and makes allframes a bit less useful.)

As per my response to RDM on python-dev, I think the patch is misguided as it currently stands.

The traceback on an exception is built up as the stack unwinds. The stack above the frame containing the exception handler obviously hasn't been unwound yet, so it isn't included in the traceback object.

Since the frame containing the exception handler is live, it and the frame stack above it reflect the state of the exception handler, while the tracebacks on the chain of exceptions currently being handled reflect the parts of the stack that have already been unwound.

For explicit printing, a separate section printing the stack with print_stack() is a better option than trying to embed the information in the stack trace of the exception currently being handled.

For the logging use case, a separate "stack_trace" flag to request inclusion of stack trace details independent of the exception state seems like a preferable option.

If the allframes flag is pursued further, then the stack trace should be added (with an appropriate header clause) after the entire exception chain has been printed (including the exception currently being handled).

Note that after the loop over the values is complete, the final value of tb should correctly refer to the traceback for the exception currently being handled regardless of whether or not any chaining is involved.

So moving the stack printing code that is currently inside the loop after the loop should do the right thing.

With my suggested change in the display layout, I think this idea is still worthwhile (getting it right in handling code is tricky, especially if the exception is passed around before being displayed).

I've implemented an optional keyword argument stack_info (defaulting to False) for all logging calls. If specified as True, a line 

Stack (most recent call last):

is printed, followed by the output of traceback.print_stack(). This is output after any exception information.

Checked into py3k (r86467), please can interested parties check if it meets the logging use case mentioned when the ticket was created?

Regression tests pass OK, and docs updated in this checkin.

Re. the change in r86467, you can test using this simple script:

http://pastebin.com/ZXs3sXDW

I dont understand, if we use traceback.print_stack(), it's the stack at the exception handling point which will be displayed.

In my view, the interesting think was not the stack trace at the point where the exception is being handled, but where the unwinding stopped (i.e, a snapshot of the stack at the moment the exception was caught).

I agree that most of the time these stacks are quite close, but if you happen to move the traceback object all around, in misc. treatment functions (or even, if it has been returned by functions to their caller - let's be fool), it can be handy to still be able to output a full exception stack, like if the exception had flowed up to the root of the program. At least that's what'd interest me for debugging.

try:
   myfunction() #<- that's the point of which I'd likle a stack trace
except Exception, e:
   handle_my_exception(e) #<- not of that point, some recursion levels deeper

Am I the only one viewing it as this ?

I agree with you, Pascal, but I think Nick is saying that that information is not actually available.  I don't fully understand why, but he knows vastly more about Python internals than I do so I'll take his word for it.

It might be interesting to try saving the traceback and printing out the allframes traceback elsewhere, since that should prove to you and I that it doesn't work :)

Note that my suggestion was to move the if statement out of the loop as-is: you would still be pulling the traceback to display from the caught exception rather than displaying the stack from the current point of execution. If you want the bottom most point to display where the actual exception occurred rather than the last line executed in the frame that caught it you need to be even smarter than that, though.

The information to construct the full stack trace properly is actually available, but it is necessary to be very careful as to how it is stitched together at the point where the traceback and the stack trace meet up.

For a full stack trace, this stitching actually needs to occur every time there is a jump from one exception to another. For finally clauses and reraised exceptions, the interpreter handles this internally so the traceback reflects the appropriate lines, but recreating a complete stack trace for the original exception in the face of PEP 3134 is going to require a bit of work in the traceback module.

Alternatively, you could just provide the full stack trace for the very last exception caught, leaving it to the reader to follow the traceback chain back down to the original exception.

Here's some useful code to explore this (I just spent some time playing with it to make sure I was giving the right answer here):

import sys
from traceback import print_exc, print_stack, print_tb
def f(n):
  this = "F%d" % n
  if n:
    try:
      f(n-1)
    except:
      print("*** Traceback in", this)
      print_exc(chain=False)
      print("*** Call stack in", this)
      print_stack()
      print("*** Replacing exception in", this)
      raise RuntimeError(this)
  print("*** Call stack in", this)
  print_stack()
  raise RuntimeError(this)

try:
  f(2)
except:
  etype, ex, tb = sys.exc_info()

"raise ex" will then show you the native display of that exception.

You can then use the context attributes to see what state is available to you:
>>> ex
RuntimeError('F2',)
>>> ex.__context__
RuntimeError('F1',)
>>> ex.__context__.__context__
RuntimeError('F0',)

In particular, we can see that the two inner exceptions are attached to frame objects which were used to run the nested function calls and hence have a frame that called them:
>>> ex.__traceback__.tb_frame.f_back
>>> ex.__context__.__traceback__.tb_frame.f_back
<frame object at 0x2118ff0>
>>> ex.__context__.__context__.__traceback__.tb_frame.f_back
<frame object at 0x2115b80>

The issue we have is that landing in the exception handlers means the state of those frames has been altered by the stack unwinding process. Let's compare the traceback for each exception with the current state of the corresponding frame (we skip the first traceback entry for our outermost function - it is there courtesy of the interactive loop and irrelevant to the current exploration):

>>> ex.__traceback__.tb_next.tb_lineno # Top level exception line
2
>>> ex.__traceback__.tb_next.tb_frame.f_lineno # Last executed line
4
>>> ex.__context__.__traceback__.tb_lineno # f(2) exception line
5
>>> ex.__context__.__traceback__.tb_frame.f_lineno # Last executed line
12
>>> ex.__context__.__context__.__traceback__.tb_lineno # f(1) exception line
5
>>> ex.__context__.__context__.__traceback__.tb_frame.f_lineno # Last executed line
12

f(0) avoids triggering the exception handler and we can see that the traceback line and the last executed line match in that case:

>>> ex.__context__.__context__.__traceback__.tb_next.tb_lineno
15
>>> ex.__context__.__context__.__traceback__.tb_next.tb_frame.f_lineno
15

So yes, the idea proposed is possible, but no, a simple call to print_stack isn't going to do the right thing.

Changeset ba014543ed2c (3.2a4) references this issue.

I recently re-wrote something like this, so I think this is useful.
I wonder if it wouldn't be nice to add a caret or some similar marker indicating the frame where the exception was caught, e.g.:


Traceback (most recent call last, catch point highlighted):
  File "testmod.py", line 13, in <module>
    upper()
> File "testmod.py", line 11, in upper
    foo()
  File "testmod.py", line 6, in foo
    raise Exception
Exception

The functionality described here certainly seems wanted and there's been some other work on the traceback module recently so could we get this into 3.5?

Adding Robert Collins to the nosy list to see if the recent traceback changes make it easier to implement this one correctly.

Robert, for context, the general idea here is to be able to stitch the traceback for a caught exception together with the stack trace for the current frame in order to give a full stack trace for the caught exception, rather than just the stack trace up to the frame where it was caught.

That should be straightforward - its just sequence suffix/prefix overlap detection, and FrameSummary (unlike frames) can be compared with ==. So yes, I think it makes it easier. It's not on my immediate itch-scratching though, but if someone were to poke at it and need any feedback / thoughts I'd be delighted to do so.