lesson 116 Debugging & Logging · intermediate

Read a traceback

When a program crashes, Python prints a traceback: the error's name and message, and the chain of calls that led there. Read from the bottom up and it tells you what went wrong and where.

You'll be able to

Find the error type, the message and the line that failed in a real traceback
Follow the frames from the program's top level down to the function that failed
Use traceback.format_exc and traceback.extract_tb to record where a caught error came from

The idea

A crash ends with a block of text that starts Traceback (most recent call last):. It is a list of frames: one per function call that was in progress, oldest first. Each frame names the file, the line number and the function, then repeats the line of code (newer Pythons underline the exact part that failed with ~~~^^^). The last line is the error type and its message.

So read it bottom up: the last line says *what* (ZeroDivisionError: division by zero); the frame just above it says *where* (the line that divided); the frames above that say *how the program got there*. The cause of the bug is often in a caller, not on the line that failed: a zero quantity was passed in from somewhere.

The traceback module gives you the same text inside a program. traceback.format_exc(), called in an except block, returns the traceback of the error being handled. The example uses it so the traceback appears in the output you can read.

Run each example to see what it prints. Running examples doesn't count toward progress.

example-1.py · A unit price that divides by zero

import traceback

def unit_price(line):
    return line["total"] / line["quantity"]

def price_report(lines):
    prices = []
    for line in lines:
        prices.append(unit_price(line))
    return prices

lines = [{"sku": "21329", "total": 23.4, "quantity": 12}, {"sku": "85048", "total": 0.0, "quantity": 0}]
try:
    price_report(lines)
except ZeroDivisionError:
    print(traceback.format_exc())

The message on the last line is worth reading word for word. For a KeyError it is the key that was missing, quotes and all, which often reveals a spelling or capitalisation mistake.

example-2.py · A key with the wrong capital

def total_quantity(rows):
    total = 0
    for row in rows:
        total += row["Quantity"]
    return total

rows = [{"invoice": "489434", "quantity": 12}, {"invoice": "489435", "quantity": 4}]
print(total_quantity(rows))

A long-running job usually shouldn't stop at the first bad record. It catches the error, keeps going, and records each failure. Keeping only str(err) loses where it happened. traceback.extract_tb(err.__traceback__) returns the frames as objects; the last one is where the error was raised, with .name (the function) and .lineno (the line).

example-3.py · Where each bad line failed

import traceback

def parse_line(text):
    invoice, quantity, price = text.split(",")
    return {"invoice": invoice, "quantity": int(quantity), "price": float(price)}

def load(lines):
    good = []
    failures = []
    for number, text in enumerate(lines, start=1):
        try:
            good.append(parse_line(text))
        except ValueError as err:
            frame = traceback.extract_tb(err.__traceback__)[-1]
            failures.append((number, frame.name, frame.lineno, str(err)))
    return good, failures

good, failures = load(["489434,12,2.55", "489435,six,1.25", "489436,4", "C489449,-1,4.95"])
print(len(good), "lines loaded")
for failure in failures:
    print(failure)

When to use it: every crash. Read the last line, then the lowest frame in *your* code, then walk up to find where the bad value came from. Use the traceback module when a program handles an error but someone still needs to know where it came from.

Mistakes to avoid: reading only the first frame (that's just where the program started); fixing the line that failed when the bad value came from a caller; and except Exception: pass or printing only "something went wrong", which throws the traceback away.

Review

Read a traceback bottom up: error and message, the line that failed, then the callers above it.
The message names the exact value or key involved; the cause is often in a caller.
traceback.format_exc() returns the text; traceback.extract_tb(err.__traceback__)[-1] is the frame where it was raised.
Next: a method for finding a bug when there is no crash at all, only a wrong answer.

Practise this