6 ms·

Add variables to Python traceback

149 points by untech 6y ago

masklinn 6y ago
Odd that cgitb.text is not mentioned anywhere as the core feature (format tracebacks including local variables referenced from the expression the exception comes from) is what it does.
- pininja 6y ago
  Opening an issue to ask for a FAQ comparison might help people evaluate the differences. For those like me who didn’t know about this: https://docs.python.org/3/library/cgitb.html https://docs.python.org/3/library/cgitb.html While the function seems similar, the interfaces seem very different. cgitb seems to need to be wrapped and configured to match the fully headless/logger use case. I think they could focus on that in the FAQ.
est 6y ago
I wonder what would happen if extracting value from a 2GB JSON "variable" went wrong....
- bostonsre 6y ago
  Yea, seems like a neat library but I'm not sure if it would be a good idea to turn it on for all stack traces globally. Could see issues like the one you mentioned and others like variables that are secrets that shouldn't be logged.
  - bostonsre 6y ago
    Or.. I guess for your example you can set a max string length. max_value_str_len max length of each variable string, -1 to disable, default=1000
bostonsre 6y ago
Maybe I missed it when reading through, but does this library have a method similar to traceback.format_exc()?
- bostonsre 6y ago
  I guess the iterator example would give similar results. I usually like to include an easy to read log message when I catch an exception to give more context about the error. return '\n'.join(iter_tb_lines(e))
mkj 6y ago
This reminds me of a trick Monotone VCS in C++ had to print out specific variables upon failure. Usually they'd do nothing, but upon hitting an invariant or similar it would dump all the listed ones out. A bit harder to do cheaply in a safe language like Rust I guess... MM(variabletodump); example https://github.com/graydon/monotone/blob/master/graph.cc#L495 https://github.com/graydon/monotone/blob/master/graph.cc#L49... docs https://github.com/graydon/monotone/blob/master/HACKING#L252 https://github.com/graydon/monotone/blob/master/HACKING#L252 The implementation was a bit hairy https://github.com/graydon/monotone/blob/master/sanity.hh#L469 https://github.com/graydon/monotone/blob/master/sanity.hh#L4...
- Nullabillity 6y ago
  The usual Rust answer would be to build a structured wrapper error (which you'd usually have to do anyway, once you have more than one error source). Then you can just add whatever debug data you want to it.
andreareina 6y ago
I use stackprinter[1] for the same. It's advisable to suppress printing of library functions (`suppressed_paths=["lib/python"])`) otherwise deep stack traces (as some libraries---hello pandas---like to produce) will cause the actually-problematic code to be elided. Long reprs are also truncated so your 2GB JSON buffer isn't going to blow up your trace. this: Traceback (most recent call last): File "demo.py", line 12, in <module> dangerous_function(somelist + anotherlist) File "demo.py", line 6, in dangerous_function return sorted(blub, key=lambda xs: sum(xs)) File "demo.py", line 6, in <lambda> return sorted(blub, key=lambda xs: sum(xs)) TypeError: unsupported operand type(s) for +: 'int' and 'str' becomes: File demo.py, line 12, in <module> 9 somelist = [[1,2], [3,4]] 10 anotherlist = [['5', 6]] 11 spam = numpy.zeros((3,3)) --> 12 dangerous_function(somelist + anotherlist) 13 except: .................................................. somelist = [[1, 2, ], [3, 4, ], ] anotherlist = [['5', 6, ], ] spam = 3x3 array([[0. 0. 0.] [0. 0. 0.] [0. 0. 0.]]) .................................................. [...] File demo.py, line 6, in <lambda> 3 4 5 def dangerous_function(blub): --> 6 return sorted(blub, key=lambda xs: sum(xs)) 7 .................................................. xs = ['5', 6, ] .................................................. TypeError: unsupported operand type(s) for +: 'int' and 'str' [1] https://github.com/cknd/stackprinter https://github.com/cknd/stackprinter
vbernat 6y ago
An alternative is to reuse pytest version: exc_info = ExceptionInfo.from_current() print(exc_info.getrepr(style="long", showlocals=True))
arafsheikh 6y ago
Neat idea but it doesn’t look like something I’d be comfortable using in production. A useful feature to have would be to selectively tag the variables I want to track (in the decorator perhaps?). This way one can prevent printing sensitive info or potentially large variables in the logs.
- StavrosK 6y ago
  I wrote https://github.com/skorokithakis/tbvaccine https://github.com/skorokithakis/tbvaccine years ago for the same purpose, and the fix is simple: Just don't install it on production. It requires no changes to your code, you can install it system-wide and all tracebacks will be prettified.
- aiiane 6y ago
  +1 this seems like a GDPR/CCPA nightmare when it comes to potentially spewing user data into logs.
- pininja 6y ago
  Do you think having a set of opt-out functions/decorators for sensitive variables would be comforting? I could see it going either way. I would probably not use this globally on programs using secrets, but would consider opting-in occasionally where chances are low and value high.
  - arafsheikh 6y ago
    > Do you think having a set of opt-out functions/decorators for sensitive variables would be comforting? Opt-out is risky and I’d not want to use it in sensitive applications. Instead, opt-in would be as good as deliberately logging variables but without the additional log/print statements and try/catch blocks.
  - cricalix 6y ago
    Consider the scenario where you develop a daemon that does something, has no secrets that you worry about. You implement this concept of automatic logging of variables, and all is well in the world. You leave. New person takes over ownership, doesn't notice the import. Urgent business need says "add this feature to the daemon" and now it's processing secrets. Now, you can argue that the person who took ownership should have read the code more carefully, but perhaps it's their 5th day on the job when that request comes in, or they misread the import as something else. I suppose you could do a code standard of "variables that containe a secret must always have 'secret' as a prefix", and could then do pattern matching, but humans are going to human and make a mistake. I'd probably lean towards opt-in, decorator/context only - maybe "@traceback_with_variables_can_log_secrets" as the name...
txomon 6y ago
Funny, I discovered that I could uses sysexcepthook to do some funny stuff long ago, documented it in my twitter, and everytime I have stuff like this I go to my twitter to copy paste. https://twitter.com/txomon/status/1128330566531788800 https://twitter.com/txomon/status/1128330566531788800
reegnz 6y ago
A former colleague of mine did something similar several years ago for Java, intended to be used for failing unit tests: https://github.com/dodie/scott https://github.com/dodie/scott
foreigner 6y ago
Neat idea. I wonder if it's possible to do something like this for JavaScript/NodeJS?
xiwenc 6y ago
Looks interesting for dev mode. But will keep sentry for production environments.
londons_explore 6y ago
Does this have runtime overhead when not printing stack traces? I imagine some optimizations might not be do-able if you need to keep around all this data in case it needs to be shown, but perhaps pythons optimizations aren't that advanced...
- StavrosK 6y ago
  It shouldn't, what you do is hook the traceback function, though the method is fiddly to get right. I wrote a utility to do the same years ago: https://github.com/skorokithakis/tbvaccine https://github.com/skorokithakis/tbvaccine
albertzeyer 6y ago
Some self advertisement: I implemented some very similar Python module a while ago (more than 9 years ago actually, but updated all the time): better_exchook: https://pypi.org/project/better-exchook/ https://pypi.org/project/better-exchook/ / https://github.com/albertz/py_better_exchook https://github.com/albertz/py_better_exchook It's just a single file, so you can easily copy it into your project. It's a bit more advanced than this as well, as it has some further logic about what variables it actually shows: * It shows only those which are used in the statement of the active line. In bigger functions, you often have other unrelated locals, and this would become incredibly spammy otherwise. Also, the use locals in the current line are almost always exactly those you are interested in. * It also shows globals (this one only shows locals). Like the original traceback and this one, it shows the current active line, and not the context around (e.g. like in IPython or stackprinter). However, it has an extension: If the current statement goes over multiple lines, it will print them as well. It also has an extension for DomTerm that you can fold away the variables.
msackmann 6y ago
I usually use import ipdb; ipdb.pm() for quick post mortem debugging, which also allows to see the variables at the moment where the exception was raised (Command locals()). Is there a scenario where this adds value?

149 points by untech 6y ago

Odd that cgitb.text is not mentioned anywhere as the core feature (format tracebacks including local variables referenced from the expression the exception comes from) is what it does.

pininja 6y ago
Opening an issue to ask for a FAQ comparison might help people evaluate the differences. For those like me who didn’t know about this: https://docs.python.org/3/library/cgitb.html https://docs.python.org/3/library/cgitb.html While the function seems similar, the interfaces seem very different. cgitb seems to need to be wrapped and configured to match the fully headless/logger use case. I think they could focus on that in the FAQ.

est 6y ago

I wonder what would happen if extracting value from a 2GB JSON "variable" went wrong....

bostonsre 6y ago
Yea, seems like a neat library but I'm not sure if it would be a good idea to turn it on for all stack traces globally. Could see issues like the one you mentioned and others like variables that are secrets that shouldn't be logged.
- bostonsre 6y ago
  Or.. I guess for your example you can set a max string length. max_value_str_len max length of each variable string, -1 to disable, default=1000

bostonsre 6y ago

Maybe I missed it when reading through, but does this library have a method similar to traceback.format_exc()?

bostonsre 6y ago
I guess the iterator example would give similar results. I usually like to include an easy to read log message when I catch an exception to give more context about the error. return '\n'.join(iter_tb_lines(e))

mkj 6y ago

This reminds me of a trick Monotone VCS in C++ had to print out specific variables upon failure. Usually they'd do nothing, but upon hitting an invariant or similar it would dump all the listed ones out. A bit harder to do cheaply in a safe language like Rust I guess... MM(variabletodump); example https://github.com/graydon/monotone/blob/master/graph.cc#L495 https://github.com/graydon/monotone/blob/master/graph.cc#L49... docs https://github.com/graydon/monotone/blob/master/HACKING#L252 https://github.com/graydon/monotone/blob/master/HACKING#L252 The implementation was a bit hairy https://github.com/graydon/monotone/blob/master/sanity.hh#L469 https://github.com/graydon/monotone/blob/master/sanity.hh#L4...

Nullabillity 6y ago
The usual Rust answer would be to build a structured wrapper error (which you'd usually have to do anyway, once you have more than one error source). Then you can just add whatever debug data you want to it.

andreareina 6y ago

I use stackprinter[1] for the same. It's advisable to suppress printing of library functions (`suppressed_paths=["lib/python"])`) otherwise deep stack traces (as some libraries---hello pandas---like to produce) will cause the actually-problematic code to be elided. Long reprs are also truncated so your 2GB JSON buffer isn't going to blow up your trace. this: Traceback (most recent call last): File "demo.py", line 12, in <module> dangerous_function(somelist + anotherlist) File "demo.py", line 6, in dangerous_function return sorted(blub, key=lambda xs: sum(xs)) File "demo.py", line 6, in <lambda> return sorted(blub, key=lambda xs: sum(xs)) TypeError: unsupported operand type(s) for +: 'int' and 'str' becomes: File demo.py, line 12, in <module> 9 somelist = [[1,2], [3,4]] 10 anotherlist = [['5', 6]] 11 spam = numpy.zeros((3,3)) --> 12 dangerous_function(somelist + anotherlist) 13 except: .................................................. somelist = [[1, 2, ], [3, 4, ], ] anotherlist = [['5', 6, ], ] spam = 3x3 array([[0. 0. 0.] [0. 0. 0.] [0. 0. 0.]]) .................................................. [...] File demo.py, line 6, in <lambda> 3 4 5 def dangerous_function(blub): --> 6 return sorted(blub, key=lambda xs: sum(xs)) 7 .................................................. xs = ['5', 6, ] .................................................. TypeError: unsupported operand type(s) for +: 'int' and 'str' [1] https://github.com/cknd/stackprinter https://github.com/cknd/stackprinter

vbernat 6y ago

An alternative is to reuse pytest version: exc_info = ExceptionInfo.from_current() print(exc_info.getrepr(style="long", showlocals=True))

arafsheikh 6y ago

Neat idea but it doesn’t look like something I’d be comfortable using in production. A useful feature to have would be to selectively tag the variables I want to track (in the decorator perhaps?). This way one can prevent printing sensitive info or potentially large variables in the logs.

StavrosK 6y ago
I wrote https://github.com/skorokithakis/tbvaccine https://github.com/skorokithakis/tbvaccine years ago for the same purpose, and the fix is simple: Just don't install it on production. It requires no changes to your code, you can install it system-wide and all tracebacks will be prettified.
aiiane 6y ago
+1 this seems like a GDPR/CCPA nightmare when it comes to potentially spewing user data into logs.
pininja 6y ago
Do you think having a set of opt-out functions/decorators for sensitive variables would be comforting? I could see it going either way. I would probably not use this globally on programs using secrets, but would consider opting-in occasionally where chances are low and value high.
- arafsheikh 6y ago
  > Do you think having a set of opt-out functions/decorators for sensitive variables would be comforting? Opt-out is risky and I’d not want to use it in sensitive applications. Instead, opt-in would be as good as deliberately logging variables but without the additional log/print statements and try/catch blocks.
- cricalix 6y ago
  Consider the scenario where you develop a daemon that does something, has no secrets that you worry about. You implement this concept of automatic logging of variables, and all is well in the world. You leave. New person takes over ownership, doesn't notice the import. Urgent business need says "add this feature to the daemon" and now it's processing secrets. Now, you can argue that the person who took ownership should have read the code more carefully, but perhaps it's their 5th day on the job when that request comes in, or they misread the import as something else. I suppose you could do a code standard of "variables that containe a secret must always have 'secret' as a prefix", and could then do pattern matching, but humans are going to human and make a mistake. I'd probably lean towards opt-in, decorator/context only - maybe "@traceback_with_variables_can_log_secrets" as the name...

txomon 6y ago

Funny, I discovered that I could uses sysexcepthook to do some funny stuff long ago, documented it in my twitter, and everytime I have stuff like this I go to my twitter to copy paste. https://twitter.com/txomon/status/1128330566531788800 https://twitter.com/txomon/status/1128330566531788800

reegnz 6y ago

A former colleague of mine did something similar several years ago for Java, intended to be used for failing unit tests: https://github.com/dodie/scott https://github.com/dodie/scott

foreigner 6y ago

Neat idea. I wonder if it's possible to do something like this for JavaScript/NodeJS?

xiwenc 6y ago

Looks interesting for dev mode. But will keep sentry for production environments.

londons_explore 6y ago

Does this have runtime overhead when not printing stack traces? I imagine some optimizations might not be do-able if you need to keep around all this data in case it needs to be shown, but perhaps pythons optimizations aren't that advanced...

StavrosK 6y ago
It shouldn't, what you do is hook the traceback function, though the method is fiddly to get right. I wrote a utility to do the same years ago: https://github.com/skorokithakis/tbvaccine https://github.com/skorokithakis/tbvaccine

albertzeyer 6y ago

Some self advertisement: I implemented some very similar Python module a while ago (more than 9 years ago actually, but updated all the time): better_exchook: https://pypi.org/project/better-exchook/ https://pypi.org/project/better-exchook/ / https://github.com/albertz/py_better_exchook https://github.com/albertz/py_better_exchook It's just a single file, so you can easily copy it into your project. It's a bit more advanced than this as well, as it has some further logic about what variables it actually shows: * It shows only those which are used in the statement of the active line. In bigger functions, you often have other unrelated locals, and this would become incredibly spammy otherwise. Also, the use locals in the current line are almost always exactly those you are interested in. * It also shows globals (this one only shows locals). Like the original traceback and this one, it shows the current active line, and not the context around (e.g. like in IPython or stackprinter). However, it has an extension: If the current statement goes over multiple lines, it will print them as well. It also has an extension for DomTerm that you can fold away the variables.

msackmann 6y ago

I usually use import ipdb; ipdb.pm() for quick post mortem debugging, which also allows to see the variables at the moment where the exception was raised (Command locals()). Is there a scenario where this adds value?