Exceptions, Logging and Defensive Code

The try statement in full

You have used try and except to stop a program crashing. The full statement has four parts, and each has a job:

try:        the code that might fail
except:     what to do if it does
else:       what to do if it did NOT fail
finally:    what must happen either way

def divide(a, b):
    try:
        result = a / b
    except ZeroDivisionError:
        print("cannot divide by zero")
        return None
    except TypeError as problem:
        print("bad types:", problem)
        return None
    else:
        print("division worked")
        return result
    finally:
        print("done with", repr(a), repr(b))

print(divide(10, 2))
print(divide(1, 0))
print(divide("a", 2))

Watch the order of the output. else runs only when there was no exception, so the success code goes there, which keeps try as short as possible and stops it hiding unrelated errors. finally runs always, even if the function returns or an error is not caught, which is why it is where clean-up goes.

def f():
    try:
        return "try"
    finally:
        print("finally runs before the function returns")

print(f())

Exceptions form a family tree

Every exception is a class, and they inherit from each other. Catching a parent catches all its children:

for kind in (ZeroDivisionError, KeyError, FileNotFoundError):
    parents = " <- ".join(c.__name__ for c in kind.__mro__[1:-1])
    print(kind.__name__, "<-", parents)

except LookupError catches both KeyError and IndexError. except Exception catches nearly everything. That is why order matters: put the specific handlers first, because Python uses the first one that fits.

try:
    {}["x"]
except LookupError:
    print("LookupError caught first")
except KeyError:
    print("never reached: a KeyError is also a LookupError")

Raising, re-raising and chaining

raise throws an exception of your own. Inside an except block, a bare raise re-throws the one being handled, which is useful for logging an error and then letting it carry on. raise ... from ... throws a new exception while keeping the original as its cause, so nothing is lost:

def load_age(text):
    try:
        return int(text)
    except ValueError as problem:
        raise ValueError("age must be a whole number, got " + repr(text)) from problem

try:
    load_age("abc")
except ValueError as error:
    print(error)
    print("caused by:", repr(error.__cause__))

The new message is meaningful to whoever called load_age, and the technical reason is still attached.

Custom exceptions and where to catch them

The built-in exceptions describe Python's problems: ValueError, KeyError. Your program has its own: an overdrawn account, an unknown product, a game that is over. A custom exception is a class that inherits from Exception, and it names a problem in your program's own words.

class BankError(Exception):
    '''Everything that can go wrong in the bank.'''

class InsufficientFunds(BankError):
    def __init__(self, balance, wanted):
        super().__init__("balance " + str(balance) + " is less than " + str(wanted))
        self.balance = balance                 # keep the facts, for whoever catches it
        self.wanted = wanted

class AccountClosed(BankError):
    pass

class Account:
    def __init__(self, balance):
        self.balance = balance
        self.open = True

    def withdraw(self, amount):
        if not self.open:
            raise AccountClosed("account is closed")
        if amount > self.balance:
            raise InsufficientFunds(self.balance, amount)
        self.balance -= amount
        return self.balance

account = Account(50)
for amount in (20, 100):
    try:
        print("left:", account.withdraw(amount))
    except InsufficientFunds as problem:
        print("short by", problem.wanted - problem.balance, "|", problem)
    except BankError as problem:               # anything else the bank can raise
        print("bank problem:", problem)

account.open = False
try:
    account.withdraw(1)
except BankError as problem:
    print(type(problem).__name__, "-", problem)

A hierarchy with one base class (BankError) lets a caller choose how precisely to catch. Handle InsufficientFunds to offer a loan. Handle BankError to show a generic apology. And an exception object can carry data, so the handler does not have to parse a message.

Where should an exception be caught?

Catch an exception at the level that knows what to do about it. The function that discovers the problem usually does not: withdraw cannot know whether to show a message, ask for another amount or cancel an order. So it raises, the exception travels up the call stack through the callers that cannot deal with it, and the first one that can, catches it.

Ask forgiveness, not permission

There are two styles for code that might fail:

EAFP avoids a gap in time. If you check that a file exists and then open it, the file might be deleted in between. Opening it and handling FileNotFoundError has no gap.

Assertions and defensive design

An assertion states something that must be true. If it is false, the program stops at once with an AssertionError:

def average(marks):
    assert len(marks) > 0, "average needs at least one mark"
    return sum(marks) / len(marks)

print(average([7, 9]))
try:
    average([])
except AssertionError as problem:
    print("assertion failed:", problem)

An assertion is not input validation

Exceptions and assertions look alike but answer different questions:

Python can remove assertions when it runs with the -O option, to save time. A program that relies on an assert to reject bad input would then accept it. See it happen:

source = "assert False, 'boom'\nprint('the assertion was skipped')"

try:
    exec(compile(source, "<demo>", "exec"))
except AssertionError as problem:
    print("normal run:", problem)

exec(compile(source, "<demo>", "exec", optimize=1))       # what python -O does

So check user input with if and raise, and use assert for your own sanity checks while developing.

Design by contract

A useful way to think about a function is as a contract:

• a precondition: what must be true when it is called (the caller's duty)
• a postcondition: what will be true when it returns (the function's duty)
• an invariant: something that stays true throughout, such as "the balance is never negative"

def integer_sqrt(n):
    assert n >= 0, "precondition: n must not be negative"
    result = 0
    while (result + 1) * (result + 1) <= n:
        result += 1
    assert result * result <= n < (result + 1) * (result + 1), "postcondition failed"
    return result

print(integer_sqrt(50), integer_sqrt(64))

Defensive programming

Defensive programming assumes things will go wrong, and arranges for them to fail safely and visibly:

• validate at the boundary, where data enters the program (input, files, the network), and then trust it inside
• fail fast: stop at the first sign of trouble instead of carrying bad data further
• use safe defaults, and never silently swallow an error
• do not trust the caller, or the client, or the file
• write the tests for the failure paths as well as for the normal ones

Logging

Debugging with print is quick, and it has problems. The output cannot be switched off without editing the code, it all looks the same, it mixes with the real output, and it goes nowhere once the program is running on a server. The logging module is the professional answer.

Each message has a level, saying how serious it is. A logger has a threshold and ignores anything below it:

There are three parts to set up. A logger receives your messages, a handler decides where they go (the screen, a file, the network), and a formatter decides how they look.

import logging
import sys

class Short(logging.Formatter):                       # keeps this demo's output short
    def formatException(self, exc_info):
        return "  (a traceback would follow: " + exc_info[0].__name__ + ")"

def make_logger(name, level):
    logger = logging.getLogger(name)
    logger.setLevel(level)
    logger.propagate = False
    handler = logging.StreamHandler(sys.stdout)
    handler.setFormatter(Short("%(levelname)-8s %(name)s: %(message)s"))
    logger.handlers = [handler]
    return logger

log = make_logger("orders", logging.DEBUG)
log.debug("checking stock")
log.info("order %d accepted", 17)
log.warning("stock for %s is low", "pens")
log.error("payment failed for order %d", 17)

try:
    1 / 0
except ZeroDivisionError:
    log.exception("unexpected error")                  # logs at ERROR, with the traceback

quiet = make_logger("quiet", logging.WARNING)
quiet.info("this is below the threshold, so it is hidden")
quiet.warning("this is shown")

Notice log.info("order %d accepted", 17): the values are passed separately from the message, so Python only builds the string if the message is actually going to be used.

log.exception is meant for use inside an except block, and records the full traceback, which a print of the error message does not.

Logging to a file

On your own computer, a real program logs to a file, so that you can read what happened after it has run. A rotating handler starts a new file when the old one is full, so that logs never fill the disk:

import logging
from logging.handlers import RotatingFileHandler

handler = RotatingFileHandler("app.log", maxBytes=100000, backupCount=3)
handler.setFormatter(logging.Formatter("%(asctime)s %(levelname)s %(name)s: %(message)s"))

log = logging.getLogger("shop")
log.setLevel(logging.INFO)
log.addHandler(handler)

log.info("server started")
log.warning("disk space is low")

Logger names

A common pattern is logging.getLogger(__name__) at the top of each module. Each module then logs under its own name, and you can turn up the detail for just one of them while debugging, leaving the rest quiet.

Reading tracebacks and debugging professionally

When an exception is not caught, Python prints a traceback: the chain of calls that led to it, oldest first, ending with the error itself:

Traceback (most recent call last):
  File "shop.py", line 22, in <module>
    total = checkout(basket)
  File "shop.py", line 14, in checkout
    return sum(price_of(item) for item in basket)
  File "shop.py", line 9, in price_of
    return PRICES[item]
KeyError: 'pencil'

Read it from the bottom. The last line says what happened: a KeyError for 'pencil'. The line above says where: price_of, line 9. The frames above that explain how the program got there. The bug is at the bottom, but the cause might be anywhere above it. Perhaps checkout was given an item that was never in the price list.

A program can examine a traceback too:

import traceback

def level3():
    return 1 / 0

def level2():
    return level3()

def level1():
    return level2()

try:
    level1()
except ZeroDivisionError as error:
    frames = traceback.extract_tb(error.__traceback__)
    print([frame.name for frame in frames])
    print(type(error).__name__, "-", error)

A method for debugging

1. Reproduce it. If you cannot make it fail, you cannot know you have fixed it.
2. Isolate it. Cut the program down to the smallest version that still fails. Half the bugs are found at this stage.
3. Read the evidence: the traceback, the logs, the values of the variables.
4. Form a hypothesis, a specific guess about the cause, and test one thing at a time.
5. Fix the cause, not the symptom.
6. Write a test that fails without the fix and passes with it, so the bug cannot come back.

For step 3 the debugger is better than scattered prints. Call breakpoint() where you want to stop, and Python opens an interactive prompt there:

def total(prices):
    result = 0
    for price in prices:
        breakpoint()          # the program pauses here
        result += price
    return result

total([3, 4, 5])

At the (Pdb) prompt: p price prints a variable, n runs the next line, s steps into a call, c continues, l lists the code around you and q quits.

Test the failure paths

The tests that matter most are often the ones for what should go wrong. assertRaises checks that the right exception is raised:

import io
import unittest

class InsufficientFunds(Exception):
    pass

class AccountClosed(Exception):
    pass

class Account:
    def __init__(self, balance):
        self.balance = balance
        self.open = True

    def withdraw(self, amount):
        if not self.open:
            raise AccountClosed("account is closed")
        if amount > self.balance:
            raise InsufficientFunds("not enough money")
        self.balance -= amount
        return self.balance

class TestAccount(unittest.TestCase):
    def test_too_much(self):
        with self.assertRaises(InsufficientFunds):
            Account(50).withdraw(100)

    def test_normal(self):
        self.assertEqual(Account(50).withdraw(20), 30)

    def test_closed(self):
        account = Account(50)
        account.open = False
        with self.assertRaises(AccountClosed):
            account.withdraw(1)

suite = unittest.defaultTestLoader.loadTestsFromTestCase(TestAccount)
result = unittest.TextTestRunner(stream=io.StringIO(), verbosity=0).run(suite)
print("tests run:", result.testsRun, "| failures:", len(result.failures), "| errors:", len(result.errors))

Key terms you must be able to define

Exception

An object that represents an error or unusual event, which interrupts normal flow until it is caught.

try / except / else / finally

The statement that runs code, handles errors, runs code only on success, and always runs clean-up code.

Custom exception

A class that inherits from Exception and names a problem specific to a program.

Exception chaining

Raising a new exception from inside a handler while keeping the original as its cause, with raise ... from ...

Assertion

A statement that a condition must be true, which stops the program with an AssertionError if it is false.

Precondition and postcondition

What must be true when a subprogram is called, and what it promises will be true when it returns.

Invariant

A condition that stays true throughout the execution of a part of a program.

Defensive programming

Writing code that expects errors and unreliable input, and handles them safely.

Logging

Recording messages with a level and a destination as a program runs, so that its behaviour can be reviewed.

Traceback

The list of calls that were active when an exception occurred, printed with the error.

Flashcards

Say the definition out loud before you flip the card. Retrieving it from memory is what builds recall, reading it again is not.

Reach the top grade on this topic

Error handling questions reward knowing which tool is for which job.

• Say that else runs only when no exception was raised and finally always runs
• Put the specific except clauses before the general one, and say why
• Distinguish exceptions (bad input and run-time failures) from assertions (programmer mistakes, which can be switched off)
• For logging, name the level and say what the handler and formatter do
• For a traceback, say you read it from the bottom: the error first, then where

Mistakes that cost marks here

def divide(a, b):
    try:
        result = a / b
    except ZeroDivisionError:
        print("cannot divide by zero")
        return None
    except TypeError as problem:
        print("bad types:", problem)
        return None
    else:
        print("division worked")
        return result
    finally:
        print("done with", repr(a), repr(b))

print(divide(10, 2))
print(divide(1, 0))
print(divide("a", 2))

class InvalidAgeError(Exception):
    pass

def check_age(age):
    if age < 0 or age > 130:
        raise InvalidAgeError("age must be between 0 and 130, not " + str(age))
    return age

print(check_age(15))
try:
    check_age(200)
except InvalidAgeError as problem:
    print(problem)