lesson 120 Debugging & Logging · intermediate

Warn, skip or stop

Real data has bad records. For each problem a program decides: fix it and note it, skip the record with a warning, or stop. A clear policy, logged, is what makes a long run trustworthy.

You'll be able to

Use logging.warning for problems the program can survive, and say what it did about them
Raise instead when the input as a whole can't be trusted
Stop a run when too many records are bad (an error budget)

The idea

A product feed has 40,000 rows. One has "12,5" as a weight, one has no weight, one says the product weighs -3 kg. Stopping at the first problem means nothing gets imported; ignoring them silently means wrong numbers nobody can explain. A good program has a policy per problem:

Correct and warn: the fix is certain ("12,5" is clearly 12.5). Apply it and log a warning that says so.
Skip and warn: the record is unusable but the rest are fine. Leave it out, warn with the record's identity, and count it.
Stop: the input as a whole is wrong (a missing column, an empty file, a configuration error). Raise, because every result would be wrong.

A WARNING says *something unexpected happened and here is what the program did about it*; it should never be a mystery.

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

example-1.py · One policy per problem

import logging
import sys

logging.basicConfig(stream=sys.stdout, level=logging.INFO, format="%(levelname)s: %(message)s", force=True)

def clean_weights(rows):
    if rows and "weight_kg" not in rows[0]:
        raise ValueError("feed has no weight_kg column")
    cleaned = {}
    for row in rows:
        text = row["weight_kg"].strip()
        if text == "":
            logging.warning("%s: no weight, skipped", row["code"])
            continue
        if "," in text:
            logging.warning("%s: read %r as %s", row["code"], text, text.replace(",", "."))
            text = text.replace(",", ".")
        weight = float(text)
        if weight <= 0:
            logging.warning("%s: weight %s is not positive, skipped", row["code"], weight)
            continue
        cleaned[row["code"]] = weight
    logging.info("%d of %d products kept", len(cleaned), len(rows))
    return cleaned

feed = [
    {"code": "3017620422003", "weight_kg": "0.4"},
    {"code": "5449000000996", "weight_kg": " 12,5 "},
    {"code": "7622210449283", "weight_kg": ""},
    {"code": "8000500310427", "weight_kg": "-3"},
]
print(clean_weights(feed))

Skipping has a limit. If half the rows are bad, the file is probably broken (a wrong delimiter, a shifted column) and importing the good-looking half is worse than stopping. An error budget makes that explicit: process everything, count the bad records, and raise if they exceed an agreed share.

example-2.py · An error budget

import logging
import sys

logging.basicConfig(stream=sys.stdout, level=logging.INFO, format="%(levelname)s: %(message)s", force=True)

def import_quantities(rows, max_bad_share):
    good = []
    bad = 0
    for number, text in enumerate(rows, start=1):
        try:
            good.append(int(text))
        except ValueError:
            bad += 1
            logging.warning("row %d: %r is not a whole number, skipped", number, text)
    if rows and bad / len(rows) > max_bad_share:
        raise ValueError(f"{bad} of {len(rows)} rows are bad (limit {max_bad_share:.0%}); check the file")
    return good

print(import_quantities(["12", "4", "x", "30"], 0.25))
try:
    import_quantities(["12", "4;6", "7;1", "x"], 0.25)
except ValueError as err:
    logging.error("import stopped: %s", err)

When to use it: any program that reads data it didn't create. Write the policy down (even as a comment) and make every warning say what was done.

Mistakes to avoid: a warning without the record's identity (bad value: which one?); skipping silently, so totals drift with no explanation; correcting values you are guessing about; and warning about a problem that should stop the run, such as a missing column.

Review

Per problem, decide: correct and warn, skip and warn, or stop.
logging.warning messages name the record and the action taken.
Raise when the whole input is wrong, or when bad records exceed an agreed budget.
Next module: writing tests, so bugs like these are caught before the program runs on real data.

Practise this