Mailman 3 Verbose traceback formatting - Python-ideas

Verbose traceback formatting

Mike Graham

28 Aug 2012 28 Aug '12

10:26 p.m.

It's possible to give a lot more on error than the default traceback gives you. I propose that Python should ship a more verbose formatter and a command line switch to use it. Here's an example of IPython's verbose formatter. I wrote a buggy program:

...

def f(a): x = a * 4 y = a - 4 return x / y

def main(): for i in xrange(100): f(i)

main()

and then ran it in IPython with verbose tracebacks and got the following output:

...

ZeroDivisionError Traceback (most recent call last)

/home/mike/foo.py in <module>() 8 f(i) 9 ---> 10 main() global main = 11 12

/home/mike/foo.py in main() 6 def main(): 7 for i in xrange(100): ----> 8 f(i) global f = i = 4 9 10 main()

/home/mike/foo.py in f(a=4) 2 x = a * 4 3 y = a - 4 ----> 4 return x / y x = 16 y = 0 5 6 def main():

ZeroDivisionError: integer division or modulo by zero

This is very handy! The reprs of all locals are input so I can see what the values of a, x, and y were when I had my error and there are a few lines of code on either side of the line that matters to help me get oriented. The former feature is the more powerful one, although enabling this by default is a bad idea; (first and foremost, this can be a security hazard). I can't count how many trips into pdb this would have saved me. I think having this feature be part of Python itself would be very helpful to new learners and to those helping them. I constantly deal with learners seeking help who are unable to clearly provide the actual values and types of the objects in the code they're having trouble with; it would be nice simply to say, "Show me a verbose traceback" and might even help them to debug their code without assistance. Mike

Show replies by date

Oleg Broytman

29 Aug 29 Aug

12:05 a.m.

Hi! On Tue, Aug 28, 2012 at 06:26:04PM -0400, Mike Graham wrote:

...

It's possible to give a lot more on error than the default traceback gives you. I propose that Python should ship a more verbose formatter

Good idea!

...

and a command line switch to use it.

And an environment variable, as usual: PYTHONTRACEBACK=verbose.

...

Here's an example of IPython's verbose formatter. I wrote a buggy program:

...
def f(a): x = a * 4 y = a - 4 return x / y

def main(): for i in xrange(100): f(i)

main()

and then ran it in IPython with verbose tracebacks and got the following output:

...
ZeroDivisionError Traceback (most recent call last)

/home/mike/foo.py in <module>() 8 f(i) 9 ---> 10 main() global main = 11 12

/home/mike/foo.py in main() 6 def main(): 7 for i in xrange(100): ----> 8 f(i) global f = i = 4 9 10 main()

/home/mike/foo.py in f(a=4) 2 x = a * 4 3 y = a - 4 ----> 4 return x / y x = 16 y = 0 5 6 def main():

ZeroDivisionError: integer division or modulo by zero

This is very handy!

100% agree! py.test produces even more verbose tracebacks and I found them very helpful in debugging. Here is a short example and below is much bigger one. ___________________________ test_transaction_delete ____________________________ close = False def test_transaction_delete(close=False): if not supports('transactions'): return setupClass(TestSOTrans) trans = TestSOTrans._connection.transaction() try: TestSOTrans(name='bob') bIn = TestSOTrans.byName('bob', connection=trans) bIn.destroySelf() bOut = TestSOTrans.select(TestSOTrans.q.name=='bob')

...

assert bOut.count() == 1

E assert 0 == 1 E + where 0 = <SelectResults at a6eb7cc>.count() test_transactions.py:65: AssertionError Longer and more verbose: _______________________________ test_transaction _______________________________ def test_transaction(): if not supports('transactions'): return

...

setupClass(TestSOTrans)

test_transactions.py:17: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ soClasses = [] force = False def setupClass(soClasses, force=False): """ Makes sure the classes have a corresponding and correct table. This won't recreate the table if it already exists. It will check that the table is properly defined (in case you change your table definition). You can provide a single class or a list of classes; if a list then classes will be created in the order you provide, and destroyed in the opposite order. So if class A depends on class B, then do setupClass([B, A]) and B won't be destroyed or cleared until after A is destroyed or cleared. If force is true, then the database will be recreated no matter what. """ global hub if not isinstance(soClasses, (list, tuple)): soClasses = [soClasses] connection = getConnection() for soClass in soClasses: ## This would be an alternate way to register connections... #try: # hub #except NameError: # hub = sqlobject.dbconnection.ConnectionHub() #soClass._connection = hub #hub.threadConnection = connection #hub.processConnection = connection soClass._connection = connection

...

installOrClear(soClasses, force=force)

dbtest.py:83: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ cls = soClasses = [] force = False @classmethod def installOrClear(cls, soClasses, force=False): cls.setup() reversed = list(soClasses)[:] reversed.reverse() # If anything needs to be dropped, they all must be dropped # But if we're forcing it, then we'll always drop if force: any_drops = True else: any_drops = False for soClass in reversed: table = soClass.sqlmeta.table

...

if not soClass._connection.tableExists(table):

dbtest.py:140: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ self = tableName = 'test_so_trans' def tableExists(self, tableName): result = self.queryOne("SELECT COUNT(relname) FROM pg_class WHERE relname = %s"

...

% self.sqlrepr(tableName))

../postgres/pgconnection.py:235: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ self = s = "SELECT COUNT(relname) FROM pg_class WHERE relname = 'test_so_trans'" def queryOne(self, s):

...

return self._runWithConnection(self._queryOne, s)

../dbconnection.py:457: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ self = meth = > def _runWithConnection(self, meth, *args):

...

conn = self.getConnection()

../dbconnection.py:325: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ self = def getConnection(self): self._poolLock.acquire() try: if not self._pool:

...

conn = self.makeConnection()

../dbconnection.py:336: _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ _ self = def makeConnection(self): try: if self.use_dsn: conn = self.module.connect(self.dsn) else: conn = self.module.connect(**self.dsn_dict) except self.module.OperationalError, e:

...

raise OperationalError("%s; used connection string %r" % (e, self.dsn))

E OperationalError: could not connect to server: No such file or directory E Is the server running locally and accepting E connections on Unix domain socket "/var/run/postgresql/.s.PGSQL.5432"? E ; used connection string 'dbname=test' ../postgres/pgconnection.py:142: OperationalError Oleg. -- Oleg Broytman http://phdru.name/ phd@phdru.name Programmers don't die, they just GOSUB without RETURN.

Masklinn

5:15 a.m.

On 2012-08-29, at 00:26 , Mike Graham wrote:

...

It's possible to give a lot more on error than the default traceback gives you. I propose that Python should ship a more verbose formatter

It already does: http://docs.python.org/py3k/library/cgitb.html > cat > test.py import cgitb cgitb.enable(format='text') def a(): b() def b(): c() def c(): assert False, "blow up" a() ^C > python3 test.py AssertionError Python 3.2.3: python Wed Aug 29 07:08:14 2012 A problem occurred in a Python script. Here is the sequence of function calls leading up to the error, in the order they occurred. test.py in <module>() 7 c() 8 def c(): 9 assert False, "blow up" 10 11 a() a = <function a> test.py in a() 3 4 def a(): 5 b() 6 def b(): 7 c() global b = <function b> test.py in b() 5 b() 6 def b(): 7 c() 8 def c(): 9 assert False, "blow up" global c = <function c> test.py in c() 7 c() 8 def c(): 9 assert False, "blow up" 10 11 a() AssertionError: blow up __cause__ = None __class__ = __context__ = None __delattr__ = __dict__ = {} __doc__ = 'Assertion failed.' __eq__ = __format__ = <built-in method __format__ of AssertionError object> __ge__ = __getattribute__ = __gt__ = __hash__ = __init__ = __le__ = __lt__ = __ne__ = __new__ = <built-in method __new__ of type object> __reduce__ = <built-in method __reduce__ of AssertionError object> __reduce_ex__ = <built-in method __reduce_ex__ of AssertionError object> __repr__ = __setattr__ = __setstate__ = <built-in method __setstate__ of AssertionError object> __sizeof__ = <built-in method __sizeof__ of AssertionError object> __str__ = __subclasshook__ = <built-in method __subclasshook__ of type object> __traceback__ = <traceback object> args = ('blow up',) with_traceback = <built-in method with_traceback of AssertionError object> The above is a description of an error in a Python program. Here is the original traceback: Traceback (most recent call last): File "test.py", line 11, in <module> a() File "test.py", line 5, in a b() File "test.py", line 7, in b c() File "test.py", line 9, in c assert False, "blow up" AssertionError: blow up

...

and a command line switch to use it.

Adding the hook on `python -mcgitb script`? In the style of -mpdb?

Masklinn

6:11 a.m.

On 2012-08-29, at 07:15 , Masklinn wrote:

...

...
and a command line switch to use it.

Adding the hook on `python -mcgitb script`? In the style of -mpdb?

Thinking about it more, this could be a nice starting point for a `traceback2` project: * Add stack frame formatting (by name, format string and function) to traceback's functions * Add formatting exechook handling (and -m switch) to traceback * Move/reimplement the meat of cgitb using traceback's stack frame formats * Maybe move the `html` formatter to wsgiref and add a trace-formatting middleware which could be dropped in about any WSGI stack

Mike Graham

1:13 p.m.

On Wed, Aug 29, 2012 at 1:15 AM, Masklinn wrote:

...

It already does: http://docs.python.org/py3k/library/cgitb.html

Wow, nice! I vaguely knew cgitb existed as an HTML formatter, but I didn't realize how much information it showed. On Wed, Aug 29, 2012 at 2:11 AM, Masklinn wrote:

...

* Maybe move the `html` formatter to wsgiref and add a trace-formatting middleware which could be dropped in about any WSGI stack

On an orthogonal note, I think it may be a bad idea to take steps that seem to encourage this sort of thing in a web app. Although there is some tradition of displaying stacktraces on errors on the web, this a) provides information the user shouldn't worry about and b) can introduce security holes (and has many times). Printing out locals, the problem only gets worse; it's easy to imagine a password or private data getting displayed on screen or transmitted via plaintext. It's of course possible to use this sort of tooling and turn it off in production, but it's not really necessary and I think it is a bad idea to make it too easy. Mike

Masklinn

1:34 p.m.

On 29 août 2012, at 15:13, Mike Graham wrote:

...

On Wed, Aug 29, 2012 at 1:15 AM, Masklinn wrote:

...
It already does: http://docs.python.org/py3k/library/cgitb.html

Wow, nice! I vaguely knew cgitb existed as an HTML formatter, but I didn't realize how much information it showed.

On Wed, Aug 29, 2012 at 2:11 AM, Masklinn wrote:

...
* Maybe move the `html` formatter to wsgiref and add a trace-formatting middleware which could be dropped in about any WSGI stack

On an orthogonal note, I think it may be a bad idea to take steps that seem to encourage this sort of thing in a web app. Although there is some tradition of displaying stacktraces on errors on the web, this a) provides information the user shouldn't worry about and b) can introduce security holes (and has many times). Printing out locals, the problem only gets worse; it's easy to imagine a password or private data getting displayed on screen or transmitted via plaintext. It's of course possible to use this sort of tooling and turn it off in production, but it's not really necessary and I think it is a bad idea to make it too easy.

I don't think having middleware which needs to be added to the stack and configure makes things "too easy". Most frameworks make it way easier via a simple flag (in a settings file for django, and passed to .run for flask). In fact, once you know of the feature's existence I'd argue a wsgi middleware is still way harder that "cgitb.enable()", and way easier *not* to enable in production.

Ned Batchelder

12:53 p.m.

...

...
and a command line switch to use it. Adding the hook on `python -mcgitb script`? In the style of -mpdb? This could also be a use for the proposed PYTHON_RUN_FIRST mechanism (http://bugs.python.org/issue14803). Instead of expecting cgitb to know how to be the main and run Python files, let the user specify a few

On 8/29/2012 1:15 AM, Masklinn wrote: lines of Python to run before their actual program. This has other uses as well, as outlined in the ticket. --Ned.

Masklinn

1:51 p.m.

On 29 août 2012, at 14:53, Ned Batchelder wrote:

...

On 8/29/2012 1:15 AM, Masklinn wrote:

...
...
and a command line switch to use it. Adding the hook on `python -mcgitb script`? In the style of -mpdb? This could also be a use for the proposed PYTHON_RUN_FIRST mechanism (http://bugs.python.org/issue14803). Instead of expecting cgitb to know how to be the main and run Python files, let the user specify a few lines of Python to run before their actual program. This has other uses as well, as outlined in the ticket.

Indeed, it could be.

Terry Reedy

9:24 p.m.

On 8/28/2012 6:26 PM, Mike Graham wrote:

...

It's possible to give a lot more on error than the default traceback gives you. I propose that Python should ship a more verbose formatter and a command line switch to use it.

Part of the problem is in the overly skimpy exception instances themselves. They should contain the needed runtime info that one cannot find in the code. I would rather you push for more such changes.

...

...
... x = 16 y = 0 ... ZeroDivisionError: integer division or modulo by zero

This could and, imo, should be changed to include the numerator, which is the main extra info included the the verbose traceback. Most of the rest strikes me as noise. ZeroDivisionError: integer division or modulo of 16 by 0 http://bugs.python.org/issue15815 -- Terry Jan Reedy

Mike Graham

1 Sep 1 Sep

12:35 a.m.

On Wed, Aug 29, 2012 at 5:24 PM, Terry Reedy wrote:

...

Part of the problem is in the overly skimpy exception instances themselves. They should contain the needed runtime info that one cannot find in the code. I would rather you push for more such changes.

...
...
... x = 16 y = 0 ...

...
...
ZeroDivisionError: integer division or modulo by zero

This could and, imo, should be changed to include the numerator, which is the main extra info included the the verbose traceback. Most of the rest strikes me as noise.

I think you have read the example too narrowly. Having the locals of each frame is _very_ useful--just because I know the terms of the division does not mean that I can easily connect that information back five calls ago when I passed the wrong thing. Currently you have to spin up the debugger (or insert print statements or similar) to get this information, which is more work than it is to read it and requires another run of your code (and getting to the same point could be expensive or tricky). Mike

Calvin Spealman

30 Aug 30 Aug

1:56 p.m.

On Tue, Aug 28, 2012 at 6:26 PM, Mike Graham wrote:

...

It's possible to give a lot more on error than the default traceback gives you. I propose that Python should ship a more verbose formatter and a command line switch to use it.

Here's an example of IPython's verbose formatter. I wrote a buggy program:

...
def f(a): x = a * 4 y = a - 4 return x / y

def main(): for i in xrange(100): f(i)

main()

and then ran it in IPython with verbose tracebacks and got the following output:

...
ZeroDivisionError Traceback (most recent call last)

/home/mike/foo.py in <module>() 8 f(i) 9 ---> 10 main() global main = 11 12

/home/mike/foo.py in main() 6 def main(): 7 for i in xrange(100): ----> 8 f(i) global f = i = 4 9 10 main()

/home/mike/foo.py in f(a=4) 2 x = a * 4 3 y = a - 4 ----> 4 return x / y x = 16 y = 0 5 6 def main():

ZeroDivisionError: integer division or modulo by zero

This is very handy! The reprs of all locals are input so I can see what the values of a, x, and y were when I had my error and there are a few lines of code on either side of the line that matters to help me get oriented. The former feature is the more powerful one, although enabling this by default is a bad idea; (first and foremost, this can be a security hazard). I can't count how many trips into pdb this would have saved me.

I think having this feature be part of Python itself would be very helpful to new learners and to those helping them. I constantly deal with learners seeking help who are unable to clearly provide the actual values and types of the objects in the code they're having trouble with; it would be nice simply to say, "Show me a verbose traceback" and might even help them to debug their code without assistance.

+1 on the more verbose formatter in stdlib Rather than a glad, I'd like to see the path to a formatter, so you can use more than just the two builtin. It would be great to easily define my own and have that used in all cases. python -t traceback.VerboseFormatter my_broken_script.py

...

Mike _______________________________________________ Python-ideas mailing list Python-ideas@python.org http://mail.python.org/mailman/listinfo/python-ideas

-- Read my blog! I depend on your acceptance of my opinion! I am interesting! http://techblog.ironfroggy.com/ Follow me if you're into that sort of thing: http://www.twitter.com/ironfroggy

Steven D'Aprano

2:18 p.m.

On 29/08/12 08:26, Mike Graham wrote:

...

It's possible to give a lot more on error than the default traceback gives you. I propose that Python should ship a more verbose formatter and a command line switch to use it.

There's no command line switch, but the Time Machine strikes again. Save your buggy script in a file "foo.py", then start up the interactive interpreter and run this: import cgitb cgitb.enable(format='text') import foo Personally, I find the IPython verbose formatter more readable and useful. To revert to ordinary tracebacks: sys.excepthook = sys.__excepthook__ -- Steven

4248

Age (days ago)

4252

Last active (days ago)

List overview

Download

11 comments

7 participants

participants (7)

Calvin Spealman
Masklinn
Mike Graham
Ned Batchelder
Oleg Broytman
Steven D'Aprano
Terry Reedy

Verbose traceback formatting

tags

participants (7)