python==3.8.5
Python - Getting more information from Tracebacks
About
This notebook demonstrates what the Python Traceback object is, and how can we get more information out of it to better diagnose exception messages.
Credit
This blog post is based on an article originally written in Python Cookbook
published by O'Reilly Media, Inc.
and released July 2002. In book’s chapter 15, there is a section with the title Getting More Information from Tracebacks
written by Bryn Keller
. An online version of this article is available at https://www.oreilly.com/library/view/python-cookbook/0596001673/ch14s05.html.
The original article uses Python 2.2, but I have adapted it for Python 3.8. Also, I have added some commentary to give more insights on Python Traceback object.
Environment Details
Discussion
Consider the following toy example where we are getting some data from an external source (an API call, a DB call, etc.), and we need to find the length of individual items provided in the list. We know that items in the list will be of type str
so we have used a len()
function on it.
We got an exception when we ran our function on received data, and now we are trying to investigate what caused the error.
##
# let's run our function on "data" received from an external source
try:
get_items_len(data)
except Exception as e:
print(traceback.print_exc())
None
Traceback (most recent call last):
File "<ipython-input-4-42cd486e1858>", line 4, in <module>
get_items_len(data)
File "<ipython-input-3-8421f841ba77>", line 11, in get_items_len
items_len.append(len(i))
TypeError: object of type 'int' has no len()
We got an exception while data processing and the Traceback
message gives us some details. It tells us that we have received some data of type integer instead of string, and we are trying to call len() function on it. But we don’t know the actual data value that caused the exception, and we don’t know the index of the item in the list that caused this error. Depending on the use case, information about the local variables, or input data that caused the error can be crucial in diagnosing the root cause of an error.
Fortunately, all this information is already available to us in the Traceback object, but there are no built-in methods that give this information directly. Let us try some of the built-in methods on the Traceback object to see the kind of information we could get from them.
#collapse-output
# calling traceback module built-in methods
try:
get_items_len(data)
except Exception as e:
print("***** Exception *****")
print(e)
exc_type, exc_value, exc_traceback = sys.exc_info()
print("\n***** print_tb *****")
traceback.print_tb(exc_traceback, limit=1, file=sys.stdout)
print("\n***** print_exception *****")
# exc_type below is ignored on 3.5 and later
traceback.print_exception(exc_type, exc_value, exc_traceback,
limit=2, file=sys.stdout)
print("\n***** print_exc *****")
traceback.print_exc(limit=2, file=sys.stdout)
print("\n***** format_exc, first and last line *****")
formatted_lines = traceback.format_exc().splitlines()
print(formatted_lines[0])
print(formatted_lines[-1])
print("\n***** format_exception *****")
# exc_type below is ignored on 3.5 and later
print(repr(traceback.format_exception(exc_type, exc_value,
exc_traceback)))
print("\n***** extract_tb *****")
print(repr(traceback.extract_tb(exc_traceback)))
print("\n***** format_tb *****")
print(repr(traceback.format_tb(exc_traceback)))
print("\n***** tb_lineno *****", exc_traceback.tb_lineno)
***** Exception *****
object of type 'int' has no len()
***** print_tb *****
File "<ipython-input-5-73d5b316a567>", line 4, in <module>
get_items_len(data)
***** print_exception *****
Traceback (most recent call last):
File "<ipython-input-5-73d5b316a567>", line 4, in <module>
get_items_len(data)
File "<ipython-input-3-8421f841ba77>", line 11, in get_items_len
items_len.append(len(i))
TypeError: object of type 'int' has no len()
***** print_exc *****
Traceback (most recent call last):
File "<ipython-input-5-73d5b316a567>", line 4, in <module>
get_items_len(data)
File "<ipython-input-3-8421f841ba77>", line 11, in get_items_len
items_len.append(len(i))
TypeError: object of type 'int' has no len()
***** format_exc, first and last line *****
Traceback (most recent call last):
TypeError: object of type 'int' has no len()
***** format_exception *****
['Traceback (most recent call last):\n', ' File "<ipython-input-5-73d5b316a567>", line 4, in <module>\n get_items_len(data)\n', ' File "<ipython-input-3-8421f841ba77>", line 11, in get_items_len\n items_len.append(len(i))\n', "TypeError: object of type 'int' has no len()\n"]
***** extract_tb *****
[<FrameSummary file <ipython-input-5-73d5b316a567>, line 4 in <module>>, <FrameSummary file <ipython-input-3-8421f841ba77>, line 11 in get_items_len>]
***** format_tb *****
[' File "<ipython-input-5-73d5b316a567>", line 4, in <module>\n get_items_len(data)\n', ' File "<ipython-input-3-8421f841ba77>", line 11, in get_items_len\n items_len.append(len(i))\n']
***** tb_lineno ***** 4
All these methods are useful but we are still short on information about the state of local variables when the system crashed. Before writing our custom function to get the variables state at the time of exception, let us spend some time to understand the working of Traceback object.
Traceback Module
https://docs.python.org/3/library/traceback.html
This module provides an easy-to-use interface to work with traceback objects
. It provides multiple functions that we can use to extract the required information from traceback. So far, we have used methods from this module in the above examples.
Traceback Objects
https://docs.python.org/3/reference/datamodel.html
On this page search for term “Traceback objects”
Traceback objects represent a stack trace of an exception. A traceback object is implicitly created when an exception occurs and may also be explicitly created by initializing an instance of class types.TracebackType
. traceback object is also an instance of types.TracebackType class. When an exception occurs, a traceback object is initialized for us, and we can obtain it from any of the following two methods. 1. It is available as a third item of the tuple returned by sys.exc_info() “(type, value, traceback)
” 2. It is available as the __traceback__
object of the caught exception. “Exception.__traceback__
”
A traceback object is a linked list of nodes, where each node is a Frame object
. Frame objects form their own linked list but in the opposite direction of traceback objects. Together they work like a doubly-linked list, and we can use them to move back and forth in the stack trace history. It is the frame objects that hold all the stack’s important information. traceback object has some special attributes * tb_next
point to the next level in the stack trace (towards the frame where the exception occurred), or None
if there is no next level * tb_frame
points to the execution frame of the current level * tb_lineno
gives the line number where the exception occurred
##
# method 1: get traceback object using sys.exc_info()
try:
get_items_len(data)
except Exception as e:
print(sys.exc_info()[2])
<traceback object at 0x7f5c6c60e9c0>
##
# method 2: get traceback object using Exception.__traceback__
try:
get_items_len(data)
except Exception as e:
print(e.__traceback__ )
<traceback object at 0x7f5c6c5c0180>
If there is no exception in the system, then calling sys.exc_info() will only return None
values.
Frame Objects
https://docs.python.org/3/reference/datamodel.html
On this page search for term “Frame objects”
Frame objects represent execution frames. It has some special attributes * f_back
is a reference to the previous stack frame (towards the caller), or None if this is the bottom stack frame * f_code
is the code object being executed in this frame. We will discuss Code Objects
in next the section * f_lineno
is the current line number of the frame — writing to this from within a trace function jumps to the given line (only for the bottom-most frame). A debugger can implement a Jump command (aka Set Next Statement) by writing to f_lineno. This attribute will give you the line number in the code on which exception occurred * f_locals
is a dictionary used to lookup local variables. From this dictionary we can get all the local variables and their state at the time of exception * f_globals
is a dictionary for global varaibles
Code Objects
https://docs.python.org/3/reference/datamodel.html
On this page search for term “Code Objects”
Code objects represent byte-compiled executable Python code or bytecode. Some of its attributes include * co_name
gives the function name being executed * co_filename
gives the filename from which the code was compiled
There are many other helpful attributes in this object, and you may read about them from the docs.
Visual representation of Traceback, Frame and Code Objects
*Custom fuction for additional exception info
Now with this additional information on stack trace objects, let us create a function to get variables state at the time of exception.
Code
def exc_info_plus():
"""
Provides the usual traceback information, followed by a listing of all the
local variables in each frame.
"""
tb = sys.exc_info()[2]
# iterate forward to the last (most recent) traceback object.
while 1:
if not tb.tb_next:
break
tb = tb.tb_next
stack = []
# get the most recent traceback frame
f = tb.tb_frame
# iterate backwards from recent to oldest traceback frame
while f:
stack.append(f)
f = f.f_back
# stack.reverse() # uncomment to get innermost (most recent) frame at the last
# get exception information and stack trace entries from most recent traceback object
exc_msg = traceback.format_exc()
exc_msg += "\n*** Locals by frame, innermost first ***"
for frame in stack:
exc_msg += f"\nFrame {frame.f_code.co_name} in {frame.f_code.co_filename} at line {frame.f_lineno}"
for key, value in frame.f_locals.items():
exc_msg += f"\n\t {key:20} = "
try:
data = str(value)
# limit variable's output to a certain number. You can adjust it as per your requirement.
# But not to remove it as output from large objects (e.g. Pandas DataFrame) can be troublesome.
output_limit = 50
exc_msg += (data[:output_limit] + "...") if len(data) > output_limit else data
except:
exc_msg += "<ERROR WHILE PRINTING VALUE>"
return exc_msg
#collapse-output
#now let us try our custom exception function and see the ouput
try:
get_items_len(data)
except Exception as e:
print(exc_info_plus())
Traceback (most recent call last):
File "<ipython-input-10-01264d9e470a>", line 4, in <module>
get_items_len(data)
File "<ipython-input-3-8421f841ba77>", line 11, in get_items_len
items_len.append(len(i))
TypeError: object of type 'int' has no len()
*** Locals by frame, innermost first ***
Frame get_items_len in <ipython-input-3-8421f841ba77> at line 11
items = ['1', '22', 333, '4444']
items_len = [1, 2]
i = 333
Frame <module> in <ipython-input-10-01264d9e470a> at line 6
__name__ = __main__
__doc__ = Automatically created module for IPython interacti...
__package__ = None
__loader__ = None
__spec__ = None
__builtin__ = <module 'builtins' (built-in)>
__builtins__ = <module 'builtins' (built-in)>
_ih = ['', '#collapse-hide\nfrom platform import python_...
_oh = {}
_dh = ['/data/_notebooks']
In = ['', '#collapse-hide\nfrom platform import python_...
Out = {}
get_ipython = <bound method InteractiveShell.get_ipython of <ipy...
exit = <IPython.core.autocall.ZMQExitAutocall object at 0...
quit = <IPython.core.autocall.ZMQExitAutocall object at 0...
_ =
__ =
___ =
_i = #collapse-show
def exc_info_plus():
"""
Pr...
_ii = ##
# no exception is generated so sys.exc_info() w...
_iii = ##
# method 2: get traceback object using Exceptio...
_i1 = #collapse-hide
from platform import python_version...
python_version = <function python_version at 0x7f5c72dbc430>
_i2 = #collapse-hide
# this is intentionally hidden as w...
data = ['1', '22', 333, '4444']
_i3 = ##
# our toy example function.
import sys, traceba...
sys = <module 'sys' (built-in)>
traceback = <module 'traceback' from '/usr/lib/python3.8/trace...
get_items_len = <function get_items_len at 0x7f5c6c62c790>
_i4 = ##
# let's run our function on "data" received fro...
_i5 = #collapse-output
# calling traceback module built-...
exc_type = <class 'TypeError'>
exc_value = object of type 'int' has no len()
exc_traceback = <traceback object at 0x7f5c6c5cf700>
formatted_lines = ['Traceback (most recent call last):', ' File "<i...
_i6 = ##
# method 1: get traceback object using sys.exc_...
_i7 = ##
# method 2: get traceback object using Exceptio...
_i8 = ##
# no exception is generated so sys.exc_info() w...
_i9 = #collapse-show
def exc_info_plus():
"""
Pr...
exc_info_plus = <function exc_info_plus at 0x7f5c6c62cc10>
_i10 = #collapse-output
#now let us try our custom except...
e = object of type 'int' has no len()
Frame run_code in /usr/local/lib/python3.8/dist-packages/IPython/core/interactiveshell.py at line 3418
self = <ipykernel.zmqshell.ZMQInteractiveShell object at ...
code_obj = <code object <module> at 0x7f5c6c62eea0, file "<ip...
result = <ExecutionResult object at 7f5c6c5c88e0, execution...
async_ = False
__tracebackhide__ = __ipython_bottom__
old_excepthook = <bound method IPKernelApp.excepthook of <ipykernel...
outflag = True
Frame run_ast_nodes in /usr/local/lib/python3.8/dist-packages/IPython/core/interactiveshell.py at line 3338
self = <ipykernel.zmqshell.ZMQInteractiveShell object at ...
nodelist = [<_ast.Try object at 0x7f5c6c5c8850>]
cell_name = <ipython-input-10-01264d9e470a>
interactivity = none
compiler = <IPython.core.compilerop.CachingCompiler object at...
result = <ExecutionResult object at 7f5c6c5c88e0, execution...
to_run_exec = [<_ast.Try object at 0x7f5c6c5c8850>]
to_run_interactive = []
mod = <_ast.Module object at 0x7f5c6c5c8430>
compare = <function InteractiveShell.run_ast_nodes.<locals>....
to_run = [(<_ast.Try object at 0x7f5c6c5c8850>, 'exec')]
node = <_ast.Try object at 0x7f5c6c5c8850>
mode = exec
code = <code object <module> at 0x7f5c6c62eea0, file "<ip...
asy = False
_async = False
Frame run_cell_async in /usr/local/lib/python3.8/dist-packages/IPython/core/interactiveshell.py at line 3146
raw_cell = #collapse-output
#now let us try our custom except...
silent = False
shell_futures = True
transformed_cell = #collapse-output
#now let us try our custom except...
preprocessing_exc_tuple = None
info = <ExecutionInfo object at 7f5c6c5c8be0, raw_cell="#...
error_before_exec = <function InteractiveShell.run_cell_async.<locals>...
cell = #collapse-output
#now let us try our custom except...
compiler = <IPython.core.compilerop.CachingCompiler object at...
_run_async = False
cell_name = <ipython-input-10-01264d9e470a>
code_ast = <_ast.Module object at 0x7f5c6c5c85e0>
interactivity = last_expr
result = <ExecutionResult object at 7f5c6c5c88e0, execution...
self = <ipykernel.zmqshell.ZMQInteractiveShell object at ...
store_history = True
Frame _pseudo_sync_runner in /usr/local/lib/python3.8/dist-packages/IPython/core/async_helpers.py at line 68
coro = <coroutine object InteractiveShell.run_cell_async ...
Frame _run_cell in /usr/local/lib/python3.8/dist-packages/IPython/core/interactiveshell.py at line 2923
self = <ipykernel.zmqshell.ZMQInteractiveShell object at ...
raw_cell = #collapse-output
#now let us try our custom except...
store_history = True
silent = False
shell_futures = True
preprocessing_exc_tuple = None
transformed_cell = #collapse-output
#now let us try our custom except...
coro = <coroutine object InteractiveShell.run_cell_async ...
runner = <function _pseudo_sync_runner at 0x7f5c724ba040>
Frame run_cell in /usr/local/lib/python3.8/dist-packages/IPython/core/interactiveshell.py at line 2877
self = <ipykernel.zmqshell.ZMQInteractiveShell object at ...
raw_cell = #collapse-output
#now let us try our custom except...
store_history = True
silent = False
shell_futures = True
result = None
Frame run_cell in /usr/local/lib/python3.8/dist-packages/ipykernel/zmqshell.py at line 539
self = <ipykernel.zmqshell.ZMQInteractiveShell object at ...
args = ('#collapse-output\n#now let us try our custom exc...
kwargs = {'store_history': True, 'silent': False}
__class__ = <class 'ipykernel.zmqshell.ZMQInteractiveShell'>
Frame do_execute in /usr/local/lib/python3.8/dist-packages/ipykernel/ipkernel.py at line 302
self = <ipykernel.ipkernel.IPythonKernel object at 0x7f5c...
code = #collapse-output
#now let us try our custom except...
silent = False
store_history = True
user_expressions = {}
allow_stdin = True
reply_content = {}
run_cell = <bound method InteractiveShell.run_cell_async of <...
should_run_async = <bound method InteractiveShell.should_run_async of...
shell = <ipykernel.zmqshell.ZMQInteractiveShell object at ...
Frame wrapper in /usr/local/lib/python3.8/dist-packages/tornado/gen.py at line 234
args = (<ipykernel.ipkernel.IPythonKernel object at 0x7f5...
kwargs = {}
future = <Future pending>
ctx_run = <built-in method run of Context object at 0x7f5c6c...
result = <generator object IPythonKernel.do_execute at 0x7f...
func = <function IPythonKernel.do_execute at 0x7f5c6f6978...
Frame execute_request in /usr/local/lib/python3.8/dist-packages/ipykernel/kernelbase.py at line 540
self = <ipykernel.ipkernel.IPythonKernel object at 0x7f5c...
stream = <zmq.eventloop.zmqstream.ZMQStream object at 0x7f5...
ident = [b'e2e3826d25fb4c63876268cdc5a787ad']
parent = {'header': {'msg_id': '218114cb9837444cbd29466d87b...
content = {'code': '#collapse-output\n#now let us try our cu...
code = #collapse-output
#now let us try our custom except...
silent = False
store_history = True
user_expressions = {}
allow_stdin = True
stop_on_error = True
metadata = {'started': datetime.datetime(2022, 2, 14, 9, 30, ...
Frame wrapper in /usr/local/lib/python3.8/dist-packages/tornado/gen.py at line 234
args = (<ipykernel.ipkernel.IPythonKernel object at 0x7f5...
kwargs = {}
future = <Future pending>
ctx_run = <built-in method run of Context object at 0x7f5c6c...
result = <generator object Kernel.execute_request at 0x7f5c...
func = <function Kernel.execute_request at 0x7f5c6f747f70...
Frame dispatch_shell in /usr/local/lib/python3.8/dist-packages/ipykernel/kernelbase.py at line 265
self = <ipykernel.ipkernel.IPythonKernel object at 0x7f5c...
stream = <zmq.eventloop.zmqstream.ZMQStream object at 0x7f5...
msg = {'header': {'msg_id': '218114cb9837444cbd29466d87b...
idents = [b'e2e3826d25fb4c63876268cdc5a787ad']
msg_type = execute_request
handler = <bound method Kernel.execute_request of <ipykernel...
Frame wrapper in /usr/local/lib/python3.8/dist-packages/tornado/gen.py at line 234
args = (<ipykernel.ipkernel.IPythonKernel object at 0x7f5...
kwargs = {}
future = <Future pending>
ctx_run = <built-in method run of Context object at 0x7f5c6f...
result = <generator object Kernel.dispatch_shell at 0x7f5c6...
func = <function Kernel.dispatch_shell at 0x7f5c6f7473a0>
Frame process_one in /usr/local/lib/python3.8/dist-packages/ipykernel/kernelbase.py at line 362
self = <ipykernel.ipkernel.IPythonKernel object at 0x7f5c...
wait = True
priority = 10
t = 13
dispatch = <bound method Kernel.dispatch_shell of <ipykernel....
args = (<zmq.eventloop.zmqstream.ZMQStream object at 0x7f...
Frame run in /usr/local/lib/python3.8/dist-packages/tornado/gen.py at line 775
self = <tornado.gen.Runner object at 0x7f5c6c60f8e0>
future = None
exc_info = None
value = (10, 13, <bound method Kernel.dispatch_shell of <i...
Frame inner in /usr/local/lib/python3.8/dist-packages/tornado/gen.py at line 814
f = None
self = <tornado.gen.Runner object at 0x7f5c6c60f8e0>
Frame _run_callback in /usr/local/lib/python3.8/dist-packages/tornado/ioloop.py at line 741
self = <tornado.platform.asyncio.AsyncIOMainLoop object a...
callback = functools.partial(<function Runner.handle_yield.<l...
Frame <lambda> in /usr/local/lib/python3.8/dist-packages/tornado/ioloop.py at line 688
f = <Future finished result=(10, 13, <bound method...7...
callback = <function Runner.handle_yield.<locals>.inner at 0x...
future = <Future finished result=(10, 13, <bound method...7...
self = <tornado.platform.asyncio.AsyncIOMainLoop object a...
Frame _run in /usr/lib/python3.8/asyncio/events.py at line 81
self = <Handle IOLoop.add_future.<locals>.<lambda>(<Futur...
Frame _run_once in /usr/lib/python3.8/asyncio/base_events.py at line 1859
self = <_UnixSelectorEventLoop running=True closed=False ...
sched_count = 0
handle = <Handle IOLoop.add_future.<locals>.<lambda>(<Futur...
timeout = 0
event_list = []
end_time = 113697.83311910101
ntodo = 2
i = 0
Frame run_forever in /usr/lib/python3.8/asyncio/base_events.py at line 570
self = <_UnixSelectorEventLoop running=True closed=False ...
old_agen_hooks = asyncgen_hooks(firstiter=None, finalizer=None)
Frame start in /usr/local/lib/python3.8/dist-packages/tornado/platform/asyncio.py at line 199
self = <tornado.platform.asyncio.AsyncIOMainLoop object a...
old_loop = <_UnixSelectorEventLoop running=True closed=False ...
Frame start in /usr/local/lib/python3.8/dist-packages/ipykernel/kernelapp.py at line 612
self = <ipykernel.kernelapp.IPKernelApp object at 0x7f5c7...
Frame launch_instance in /usr/local/lib/python3.8/dist-packages/traitlets/config/application.py at line 845
cls = <class 'ipykernel.kernelapp.IPKernelApp'>
argv = None
kwargs = {}
app = <ipykernel.kernelapp.IPKernelApp object at 0x7f5c7...
Frame <module> in /usr/local/lib/python3.8/dist-packages/ipykernel_launcher.py at line 16
__name__ = __main__
__doc__ = Entry point for launching an IPython kernel.
This...
__package__ =
__loader__ = <_frozen_importlib_external.SourceFileLoader objec...
__spec__ = ModuleSpec(name='ipykernel_launcher', loader=<_fro...
__annotations__ = {}
__builtins__ = <module 'builtins' (built-in)>
__file__ = /usr/local/lib/python3.8/dist-packages/ipykernel_l...
__cached__ = /usr/local/lib/python3.8/dist-packages/__pycache__...
sys = <module 'sys' (built-in)>
app = <module 'ipykernel.kernelapp' from '/usr/local/lib...
Frame _run_code in /usr/lib/python3.8/runpy.py at line 87
code = <code object <module> at 0x7f5c7317e030, file "/us...
run_globals = {'__name__': '__main__', '__doc__': 'Entry point f...
init_globals = None
mod_name = __main__
mod_spec = ModuleSpec(name='ipykernel_launcher', loader=<_fro...
pkg_name =
script_name = None
loader = <_frozen_importlib_external.SourceFileLoader objec...
fname = /usr/local/lib/python3.8/dist-packages/ipykernel_l...
cached = /usr/local/lib/python3.8/dist-packages/__pycache__...
Frame _run_module_as_main in /usr/lib/python3.8/runpy.py at line 194
mod_name = ipykernel_launcher
alter_argv = 1
mod_spec = ModuleSpec(name='ipykernel_launcher', loader=<_fro...
code = <code object <module> at 0x7f5c7317e030, file "/us...
main_globals = {'__name__': '__main__', '__doc__': 'Entry point f...
Note the output from the first stack frame in the above stack trace. It is easy now to see (items) that we received in our function. The item at index i is also available (333) on which our function crashed. Using our custom function unexpected errors are logged in a format that makes it a lot easier to find and fix the errors. Let’s fix our function to handle unexpected integer values.
##
# let's fix our function to handle unexpected 'int' items by converting them to 'str'
def get_items_len(items: list) -> list:
"""
this function returns the length of items received in a list.
"""
items_len = []
for i in map(str, items):
items_len.append(len(i))
return items_len
# test it again
get_items_len(data)
[1, 2, 3, 4]