Debugging and Profiling
Intermediate⏱80 minutesπŸ“–28 min readLesson 10 of 10

Debugging and Profiling

Turn a failure into evidence: read tracebacks, log with context, debug with pdb, capture hung processes, and measure performance with timeit, cProfile and sampling profilers

The nightly invoice job finished in four minutes for a year. On a Tuesday it took forty. The first engineer added timing prints, ran the job twice and saw nothing obvious. The second engineer opened the traceback from a failed retry, found that one supplier file had changed its column order, and fixed the parser in ten minutes. The difference was not skill. It was evidence.

Debugging is the work of turning a vague failure into a specific claim about one line of code. Profiling is the same work applied to time and memory. Both reward a short, repeatable loop: reproduce, reduce, inspect, change one thing, and verify. Both punish a loop that changes three things at once and calls the result an improvement.

This lesson covers tracebacks, logging, pdb, faulthandler, timeit, cProfile, sampling profilers and tracemalloc. It ends with three case studies and a playbook for choosing the first tool when the symptom is still unclear.

Key terms

Traceback
The report of the call stack at the moment an exception was raised, from the outermost frame to the frame that failed.
Breakpoint
A marked location where the interpreter pauses so a debugger can inspect state before execution continues.
Post-mortem debugging
Inspecting the state of a program after it has already raised an unhandled exception.
Log level
A severity label such as DEBUG, INFO or WARNING that decides whether a record is emitted.
Handler
The logging object that sends a formatted record to a destination such as the console, a file or a queue.
Deterministic profiler
A profiler that records every function call and return, which gives exact counts but adds overhead.
Sampling profiler
A profiler that reads the call stack at intervals and estimates where time is spent, with low overhead.
Flame graph
A visualization of nested call frames where the width of a bar represents the time or memory attributed to that frame.
Memory leak
Memory that stays reachable and therefore cannot be reclaimed, often because a cache or registry keeps growing.
Benchmark
A repeatable measurement of a small piece of code under controlled conditions, used to compare implementations.
Remote attach
Connecting a debugger or profiler to an already running process by its process id.
Peak memory
The highest amount of traced memory in use during a measurement window, not just the amount at the end.

1. The Debugging Loop

A useful debugging session has a shape. Reproduce the failure with a command that can be run again. Reduce the input until the failure is small enough to hold in one screen. Inspect the state with a traceback, a log record or a debugger. Change one thing. Verify the change against the same reproduction, then add a regression test so the failure cannot return quietly.

100%
Description

A debugging loop with five stages. Start by reproducing the failure, then reduce it to the smallest input, inspect the state with a traceback or debugger, change one thing, and verify the fix with a regression test. If the fix does not hold, the loop returns to inspection.

The loop is deliberately boring. Excitement in a debugging session usually means the engineer is guessing. A guess is fine as a hypothesis, but it becomes evidence only when a command can confirm or reject it. The loop also protects the fix: a change that is verified against the original reproduction is much less likely to be a coincidence.

Reduction deserves its own habit. If a request fails, try the same request with one field. If a file fails, try the first ten lines. If a loop fails at item 900, try item 900 alone. A reduced case runs faster, produces a shorter traceback and often makes the wrong assumption visible without a debugger.

πŸ’‘Tip

Write the reproduction as a command before changing any code. A shell command, a failing test or a five line script is enough. If the failure cannot be reproduced, the first task is to improve observability, not to edit the function that looks suspicious.

2. Tracebacks as Evidence

A traceback is a stack, not a verdict. Python prints the outermost call first and the frame that raised last, so the last few lines usually identify the operation that failed. The exception type names the category, and the message names the specific value. Read the whole chain before editing, because the first exception is often the cause and the last one is only the symptom.

python
def total_amount(lines: list[dict]) -> float: return sum(line["amount"] for line in lines) def load_invoice(path): try: lines = read_lines(path) except OSError as error: raise RuntimeError(f"cannot read invoice {path}") from error if not lines: raise ValueError(f"invoice {path} has no lines") return total_amount(lines)

The from error clause records an explicit cause. Python prints the original OSError, then a line that says it was the direct cause of the RuntimeError. Without the clause, an exception raised inside an except block is linked as context and printed with a different message. Both forms preserve the chain, but from states that the new error was deliberate.

plaintext
Traceback (most recent call last): File "billing.py", line 12, in load_invoice lines = read_lines(path) FileNotFoundError: [Errno 2] No such file or directory: 'invoice.csv' The above exception was the direct cause of the following exception: Traceback (most recent call last): File "billing.py", line 18, in <module> load_invoice("invoice.csv") RuntimeError: cannot read invoice invoice.csv

The chain is data, not just text. error.__cause__ holds the explicit cause, error.__context__ holds the implicit one, and error.__suppress_context__ records whether from None hid the context. A handler can walk those attributes, but printing the formatted chain is usually enough.

traceback.TracebackException turns an exception into a stable object that can be formatted later. That is useful when a log handler needs a compact record, or when an error reporter wants to serialize the frames without keeping the live exception alive.

python
import logging import traceback logger = logging.getLogger(__name__) try: load_invoice("invoice.csv") except Exception as error: logger.error("invoice import failed\n%s", "".join( traceback.TracebackException.from_exception(error).format() ))

An ExceptionGroup adds one more layer. It carries several exceptions that failed together, and the traceback prints each member under a numbered branch. The group is the right shape for a batch job that should report every bad row instead of stopping at the first one. Iterate over group.exceptions and log each member with its own exc_info so the report stays searchable.

ℹ️Note

An exception message is for humans; the exception type and attributes are for code. Catch the narrowest type that you can handle, and never catch Exception only to log it and continue as if the operation succeeded. A swallowed error turns a loud failure into a silent wrong answer.

3. Logging Instead of print

print writes to standard output with no level, no timestamp and no way to turn it off. The logging module adds a severity, a source name, a destination and a configuration layer. The five standard levels are DEBUG, INFO, WARNING, ERROR and CRITICAL, in increasing severity. The root logger starts at WARNING, so debug and info records are dropped until a handler and a level are configured.

python
import logging logger = logging.getLogger("billing.worker") handler = logging.StreamHandler() handler.setFormatter( logging.Formatter("%(asctime)s %(levelname)s %(name)s %(message)s") ) logger.addHandler(handler) logger.setLevel(logging.INFO) logger.propagate = False logger.info("processed %d orders", 12) logger.debug("cache hit for %s", "sku-7")

A logger is named and hierarchical, so billing.worker sits below billing. Records travel up the hierarchy to the handlers of ancestor loggers unless propagate is false. That design lets an application configure one root handler and let every module logger use it. It also explains the classic duplicate line: a handler on the child plus a handler on the root means the same record is handled twice.

Passing values as arguments, as in logger.info("processed %d orders", 12), keeps the message template separate from the data. The % placeholders are filled inside the logging call, and the record is only emitted when the level allows it. Building the string first with an f-string or concatenation does the work even when the record is discarded, which matters in a hot path.

logger.exception is the shortcut for an error record with the current traceback attached. It is equivalent to logger.error(..., exc_info=True) and belongs inside an except block. The output includes the message and the full chain, so the log line stays short while the diagnosis stays complete.

python
try: charge(order) except PaymentError: logger.exception("charge failed for order %s", order.id) raise

For real services, configure logging in one place with a dictionary. The dictConfig function accepts formatters, handlers and logger levels, and it can rotate files by size or time. A rotating file handler keeps the last few files, which prevents an unattended service from filling the disk.

python
import logging.config logging.config.dictConfig({ "version": 1, "disable_existing_loggers": False, "formatters": { "standard": { "format": "%(asctime)s %(levelname)s %(name)s %(message)s" } }, "handlers": { "console": { "class": "logging.StreamHandler", "formatter": "standard", "level": "INFO", }, "file": { "class": "logging.handlers.RotatingFileHandler", "formatter": "standard", "filename": "app.log", "maxBytes": 1_000_000, "backupCount": 5, "level": "WARNING", }, }, "root": {"handlers": ["console", "file"], "level": "INFO"}, })

basicConfig is the quick path for a script, but it does nothing if the root logger already has handlers, unless force=True is passed. That behavior is a common source of "my logging configuration is ignored" reports, because an imported library configured the root first.

Context turns a log line into a record. The extra argument attaches fields that a formatter can print, and a JSON formatter can send them to a log aggregator without parsing prose. Include identifiers, durations and outcome, not secrets, tokens, full card numbers or personal data. A log file is a copy of production data and inherits its retention and access rules.

python
logger.info( "order processed", extra={"order_id": order.id, "customer_id": order.customer_id, "duration_ms": elapsed_ms}, )

For latency sensitive code, a QueueHandler places records on a queue and a QueueListener formats and writes them on another thread. The request path pays for the enqueue, not for disk I/O. The trade-off is that a process crash can lose records still waiting in the queue, so queue logging pairs well with an immediate error path that flushes on shutdown.

⚠️Warning

Do not log inside a tight loop at DEBUG and leave the level enabled in production. Logging is cheap compared with a network call, but a million formatted records per minute are not. Use sampling, counters or a periodic summary for high volume events.

4. pdb and the Breakpoint

A debugger pauses a program and lets you inspect the live state. The built in module is pdb, and the built in function breakpoint() is the portable way to enter it. Calling breakpoint() is equivalent to import pdb; pdb.set_trace() with one important difference: the behavior can be changed without editing the source, because the call goes through sys.breakpointhook.

python
def apply_discount(price: float, percent: float) -> float: discount = price * percent / 100 breakpoint() return price - discount
plaintext
$ python billing.py > /srv/billing.py(3)apply_discount() -> return price - discount (Pdb) p price 100.0 (Pdb) p discount 20.0 (Pdb) n --Return-- > /srv/billing.py(3)apply_discount()->80.0 (Pdb) c

The environment variable PYTHONBREAKPOINT controls the hook. Setting it to 0 makes every breakpoint() call return immediately, which is the safe default for production. Setting it to a dotted path such as ipdb.set_trace selects a different debugger without touching the code. If the import fails, Python reports a warning and ignores the breakpoint.

bash
PYTHONBREAKPOINT=0 python -m billing.worker PYTHONBREAKPOINT=ipdb.set_trace python -m billing.worker

The command set is small. n runs the current line and stops at the next line in the same frame. s steps into a call. r runs until the current function returns. c continues to the next breakpoint or to exit. l lists source, p prints an expression, pp pretty prints it, w prints the stack and q quits.

Command
Effect
n
Next line, stepping over calls
s
Step into the call on this line
r
Run until the current function returns
c
Continue to the next breakpoint
l
List source around the current line
p expr
Evaluate and print an expression
pp expr
Pretty print a value
w
Print the call stack
b file:line
Set a breakpoint
b file:line, condition
Break only when the condition is true
cl
Clear a breakpoint
!statement
Execute a statement in the current frame
interact
Start an interactive interpreter in the frame
q
Quit the debugger

Conditional breakpoints are the antidote to a loop that fails only at item 900. Set b process.py:42, item_id == 900, continue, and stop exactly once. The condition is evaluated in the frame where the breakpoint sits, so it can read local variables and call simple predicates.

Post-mortem debugging starts after the failure. python -m pdb script.py automatically enters the debugger when the program exits abnormally, which means the stack and locals are still available without a breakpoint in advance. Inside a handler, pdb.post_mortem() uses the exception that is being handled, and since Python 3.13 it also accepts an exception object directly.

python
import pdb try: load_invoice("invoice.csv") except Exception as error: pdb.post_mortem(error)

Python 3.14 added the ability to attach to a running process: python -m pdb -p 1234 connects to the process with that id. The safe mechanism behind it is PEP 768, which defines an execution point where another process can inject code without changing the interpreter's normal path. The public function is sys.remote_exec(pid, script_path), and it should be treated as a privileged operation because it runs arbitrary code in the target process.

100%
Description

A sequence diagram of one pdb session. The developer starts the script, Python reaches a breakpoint, pdb shows a prompt, the developer inspects a variable, steps over one line and continues, and the program finishes.

The video below is a practical tour of the same commands in a terminal. It is useful for seeing the prompt, the source listing and the step commands in motion, which is easier to absorb than a table.

Real PythonWatch on YouTube
Description

A short screencast that starts a Python script under pdb, sets a breakpoint, inspects variables, steps through lines and continues execution. It shows the terminal prompt and the source listing at each stop.

Attaching to a process that is blocked in a system call or waiting for I/O only works once the next bytecode instruction runs or the process receives a signal. That limitation is part of the pdb documentation, and it is why a hung process often needs faulthandler or an external sampler instead of an interactive debugger.

πŸ“ŒImportant

Never leave a live breakpoint() in a request handler on a shared environment. A single unguarded call can freeze every worker that reaches it. Keep the call behind a debug flag, and set PYTHONBREAKPOINT=0 in production so an accidental breakpoint becomes a no-op.

5. When the Process Hangs

A deadlock or a crash in a C extension can leave no Python traceback at all. faulthandler fills that gap. It installs signal handlers for SIGSEGV, SIGFPE, SIGABRT, SIGBUS and SIGILL, and it can dump every thread stack after a timeout or on demand. It is implemented in C, so it can still write a dump when the interpreter is deadlocked.

python
import faulthandler faulthandler.enable() faulthandler.dump_traceback_later(30, repeat=True, exit=True)

The exit=True argument terminates the process after the dump, which lets a supervisor restart a worker that will never recover. repeat=True writes a fresh dump every 30 seconds, which is useful when the first dump is not enough to identify the stuck operation. The handler can also be enabled at startup with PYTHONFAULTHANDLER=1 or python -X faulthandler, without importing the module.

bash
PYTHONFAULTHANDLER=1 python -m billing.worker python -X faulthandler -m billing.worker kill -USR1 1234

The kill path requires faulthandler.register(signal.SIGUSR1) first. A registered signal gives operators an on-demand stack dump without restarting the service, which is often the difference between a five minute diagnosis and a five hour one.

The dump is intentionally minimal. It prints ASCII only, limits each string to 500 characters, omits source lines, and caps the output at 100 frames per thread and 100 threads by default. Python 3.14 added dump_c_stack for the C stack, and Python 3.15 added the max_threads argument to control the thread cap.

100%
Description

A state diagram of a hung process triage. A worker stops responding, the engineer dumps all thread stacks, then classifies the wait as a lock wait, an I/O wait or a C extension call. Each path leads to a review of the relevant resource.

A stack dump answers "what is every thread doing right now". The next question is "what is it waiting for". A thread parked in lock.acquire names the lock object, and the thread that holds it appears in another stack. A thread parked in a socket read names the peer and the timeout. A thread inside a C function needs a native stack, which faulthandler.dump_c_stack or py-spy dump can provide.

py-spy is an external sampler that reads the target process from outside. It needs no import, no restart and no change to the code, and it can dump stacks with local variables or record a flame graph over time. The trade-off is that it samples, so very short functions can be missed.

⚠️Warning

A fault handler writes to a file descriptor and uses only signal safe functions. Do not call arbitrary Python from a signal handler, and make sure the dump destination is writable before the incident. A dump that fails because the disk is full is worse than no dump at all.

6. Measuring Small Pieces with timeit

Optimization starts with a measurement, and timeit is the standard tool for small, isolated snippets. It runs a statement many times, takes the total elapsed time and divides by the loop count. The repeat argument runs the whole measurement several times, and the documentation recommends using the best time because it is least affected by other activity on the machine.

python
import timeit setup = "data = list(range(1_000))" statements = { "loop": "total = 0\nfor x in data:\n total += x * x", "generator": "sum(x * x for x in data)", "list": "sum([x * x for x in data])", } for name, statement in statements.items(): samples = timeit.repeat(statement, setup=setup, number=1_000, repeat=5) print(name, f"{min(samples) / 1_000 * 1e6:.2f} us per call")

On CPython 3.14.4 with a 1,000 item list, the explicit loop measured about 20.49 microseconds per call, the generator expression about 30.97 and the list comprehension about 34.67. The ordering is the useful part: the generator avoids materializing a list but adds per item generator overhead, while the explicit loop avoids both the generator protocol and the temporary list. The numbers are specific to that interpreter and machine, so treat them as a shape rather than a constant.

Time per call for three ways to sum squares
Description

Bar chart of time per call for a list of one thousand integers on CPython 3.14.4. An explicit loop takes about 20.5 microseconds, a generator expression inside sum takes about 31 microseconds, and a list comprehension inside sum takes about 34.7 microseconds.

The command line is convenient for a quick check. -n sets the number of loops, -r sets the number of repeats and -s runs setup code once. Python 3.15 colorizes the output by default and adds --target-time, which keeps increasing the loop count until the run lasts at least the requested number of seconds.

bash
python -m timeit -s "data = list(range(1000))" "sum(x*x for x in data)" python -m timeit -n 1000 -r 5 "sum(range(100))" python -m timeit --target-time 1.0 "sum(range(100))"

Benchmarks lie in predictable ways. A statement whose result is never used can be optimized away, a setup that runs inside the loop measures the wrong thing, and a single run on a busy laptop measures the laptop. Keep the result, use the same setup for every candidate, repeat the measurement, and report the interpreter version and the input size with the number. timeit measures a snippet; it does not explain why the snippet is slow.

πŸ’‘Tip

Compare two implementations by running them in the same process, with the same input, in alternating order. A 5 percent difference between runs on different days is usually noise; a 40 percent difference that survives a repeat is worth a change.

7. Deterministic Profiling with cProfile

timeit answers "which snippet is faster". A profiler answers "where does the program spend its time". The standard deterministic profiler records every call and return, so it produces exact call counts and a complete caller tree. That completeness costs overhead, which is why profilers are for finding hotspots, not for publishing benchmark numbers.

python
import cProfile import pstats from pstats import SortKey profile = cProfile.Profile() profile.enable() result = handle_request(payload) profile.disable() stats = pstats.Stats(profile) stats.strip_dirs().sort_stats(SortKey.CUMULATIVE).print_stats(15)

The pstats table has six important columns. ncalls is the number of calls, shown as total divided by primitive for recursive functions. tottime is the time spent in the function itself, excluding calls it made. cumtime includes the whole subtree. percall divides each of those by the call count, and the last column names the file, line and function.

plaintext
35401 function calls (21 primitive calls) in 0.008 seconds Ordered by: cumulative time ncalls tottime percall cumtime percall filename:lineno(function) 35400/20 0.008 0.000 0.008 0.000 fib_demo.py:4(fib)

The 35400/20 row means 35,400 total calls and 20 primitive calls. The function was entered 20 times from outside, and the remaining calls came from its own recursion. A high cumtime with a low tottime means the function is mostly waiting on its callees. A high tottime means the function itself contains the expensive work. Optimize the row with the high self time, then re-profile to see whether the cost moved.

Sort order changes the question. SortKey.CUMULATIVE finds the subtree that dominates the total, while SortKey.TIME finds functions that burn time in their own body. SortKey.CALLS finds chatty functions whose per call cost is small but whose count is enormous. The print_callers and print_callees methods show the edges around a row when the tree is not obvious.

bash
python -m cProfile -o profile.out -s cumulative billing.py python -m snakeviz profile.out

Saving to a file separates collection from analysis. SnakeViz reads the same profile data and renders an interactive sunburst and table in a browser, which is easier to explore than a long terminal listing. The profile file is portable, so a colleague can open it without reproducing the workload.

Python 3.15 moved the deterministic implementation into the new profiling package. profiling.tracing is the new name, and cProfile remains a backward-compatible alias. The pure Python profile module is deprecated and scheduled for removal in 3.17. Existing import cProfile code keeps working, but new code should prefer the explicit module name.

⚠️Warning

A deterministic profiler adds overhead to Python calls but not to C calls, which can make pure Python code look worse than it is. Use the profile to find the hot path, then confirm the improvement with timeit or an external sampler. Never quote a profiler duration as the program's real runtime.

8. Sampling Profilers and Production

A sampling profiler does not instrument every call. It reads the call stack at intervals and estimates where the program spends its time. The estimate becomes more precise as the number of samples grows, and the overhead stays low enough for production. The trade-off is resolution: a function that finishes between two samples may never appear.

Python 3.15 adds profiling.sampling, a statistical profiler named Tachyon. It can run a script or attach to a running process by id, and it supports wall-clock, CPU, GIL and exception modes. Output formats include a pstats table, an interactive flame graph, a line-level heatmap, Firefox Profiler data and a live terminal view. The --native option includes time spent in C extensions, and -a samples all threads.

bash
python -m profiling.sampling run script.py python -m profiling.sampling run --flamegraph -o profile.html script.py python -m profiling.sampling attach 12345 python -m profiling.sampling dump 12345

The run command starts the target and profiles it from startup. attach connects to a live process, collects samples for a duration and detaches without a restart. dump reads the stack once and exits, which is the fastest way to answer "what is this process doing right now" for a hung worker.

Before 3.15, the same job belonged to external tools. py-spy records a flame graph, shows a live top-like view and dumps stacks from a process it does not own. It supports --locals for local variables and --native for C frames, and attaching usually needs elevated permissions because the sampler reads another process's memory.

bash
py-spy record -o profile.svg --pid 12345 py-spy top --pid 12345 py-spy dump --pid 12345 --locals

Scalene takes a different angle. It reports CPU, GPU and memory use at line level, separates Python time from native time, and can copy the profile to a standalone HTML file. That combination is useful when the question is "which line allocates and which line burns CPU", rather than "which function is on the stack most often".

bash
scalene run worker.py scalene view --html
100%
Description

A timeline of debugging and profiling support in Python. Python 3.3 added faulthandler, 3.4 added tracemalloc, 3.12 added sys.monitoring, 3.14 added remote pdb attach and sys.remote_exec, and 3.15 added the profiling package with the Tachyon sampling profiler.

Sampling is the default for a first look at a production system because it is safe to attach and cheap to run. Deterministic tracing remains the right tool when exact counts matter, such as proving that a cache reduced the number of database calls. The two are complementary: sample to find the region, trace to count the calls inside it.

ℹ️Note

A flame graph is a call tree, not a timeline. The width of a bar is the share of samples in that subtree, and the x position has no chronological meaning. Read it from the bottom up to find the broad bar, then follow the narrow children that explain it.

9. Memory: tracemalloc and memray

A memory leak in Python is rarely a missing free. It is usually an object that stays reachable because a cache, a registry or a closure still holds it. The first measurement is the traced memory over time, and the second is the allocation site that grew. tracemalloc records the traceback of each Python allocation and can compare two snapshots.

python
import tracemalloc tracemalloc.start() snapshot_before = tracemalloc.take_snapshot() cache = {f"sku-{i}": i for i in range(100_000)} snapshot_after = tracemalloc.take_snapshot() current, peak = tracemalloc.get_traced_memory() print(f"current={current / 1024**2:.1f} MiB peak={peak / 1024**2:.1f} MiB") for stat in snapshot_after.compare_to(snapshot_before, "lineno")[:3]: print(stat)

On CPython 3.14.4 this prints a current value of 11.5 MiB and a peak of 12.3 MiB. The top difference is the line that built the dictionary, with about 199,745 traced blocks and an average of 60 bytes. The count is larger than the number of keys because the dictionary, its keys and its values are separate allocations. The exact numbers depend on the interpreter and platform, but the method transfers.

take_snapshot copies the current traces, and compare_to subtracts an older snapshot from a newer one. Sorting by "lineno" groups allocations by the line that created them, and sorting by "traceback" groups them by the full stack. A tracemalloc.Filter removes noise such as import machinery or test frameworks, which makes the top of the report readable.

python
import tracemalloc snapshot = tracemalloc.take_snapshot().filter_traces(( tracemalloc.Filter(False, "<frozen importlib._bootstrap>"), tracemalloc.Filter(False, tracemalloc.__file__), )) for stat in snapshot.statistics("traceback")[:5]: print(stat)

Tracing has overhead, so enable it for a bounded window. The nframe argument controls how many frames each trace stores; one frame is enough for line level statistics, and more frames are needed for a full stack. get_traced_memory returns the current and peak values, and reset_peak starts a new peak window without discarding the traces.

sys.getsizeof is a different measurement. It returns the shallow size of one object and does not include the objects it refers to, so summing it over a dictionary's keys and values is error prone. Use tracemalloc when the question is "how much memory did this line allocate", and use getsizeof when the question is "how large is this one object".

For C extensions, native allocations and long running services, memray goes further. It records Python and native allocations, produces flame graphs and summary tables, and can attach to an already running process. The --native flag includes allocations made outside the Python allocator, which is where a leak in a C library hides.

bash
memray run -o output.bin worker.py memray flamegraph output.bin memray attach 12345 memray run --native worker.py

A memory investigation has a simple order. Confirm that the process grows across a full workload, not just at startup. Take a baseline after warm up. Run the workload again. Compare the snapshots and read the top allocation sites. Fix the retention, then repeat the same workload and confirm that the growth is gone. A garbage collection cycle that makes the number drop is a clue, not a fix, because the next cycle will bring the memory back.

⚠️Warning

Do not call gc.collect() and declare the leak fixed because the resident set fell. If an object is still reachable, the memory will return on the next allocation. Find the owner that keeps the reference, and remove or bound it.

10. Choosing a Tool and Avoiding Traps

The first tool depends on the symptom, not on the tool that is most familiar. The table below is a starting point for the first five minutes.

Symptom
First tool
Next step
An exception with a long chain
Read the traceback and __cause__
Reproduce the smallest failing input
A wrong value in production
Structured logs with request context
Add a regression test around the input
A single slow function
timeit with repeat and min
Change one implementation and remeasure
A slow request path
Sampling profiler or cProfile
Confirm the hotspot with a focused benchmark
A hung worker
faulthandler dump or py-spy dump
Inspect the lock or I/O wait in the stacks
Memory that grows over time
tracemalloc snapshot diff
Inspect the retaining owner, then bound it
A crash inside a C extension
faulthandler with the C stack
Reproduce with the native library version pinned

The quadrant below places the common tools by overhead and by how much of the program they explain. The useful first move is usually the low cost, broad view corner: a sampling profiler or a stack dump. The high cost, narrow view corner is for a specific question that a broader tool has already localized.

100%
Description

A quadrant chart of debugging tools by overhead and insight. Print statements sit at low overhead and narrow insight, logging at low overhead and medium insight, pdb at high overhead and narrow insight, cProfile at high overhead and broad insight, and a sampling profiler at low overhead and broad insight.

The drag and drop exercise puts the investigation order in one sequence.

Ordering Question
How to answer

Ordering exercise with 7 items. Move them into the correct order, then check your answer.

Order the steps of a disciplined performance investigation.

Define the metric and the target
Reproduce the slow path with a realistic workload
Measure a baseline with timeit or a profiler
Find the dominant cost and form one hypothesis
Change one thing and measure again
Keep the change only if the metric improves
Add a regression test or a benchmark

The matching exercise connects a symptom to the first tool.

Matching Question
How to answer

Matching exercise with 6 pairs. Match each item on the left with its answer on the right.

Match each symptom to the first tool to reach for.

A traceback that ends in another exception
Drop here
A process that stopped responding
Drop here
One function that is slower than expected
Drop here
A whole request path that is slow
Drop here
Memory that grows without bound
Drop here
A silent wrong value in production
Drop here

Drag answers from here:

Read the exception chain and the explicit cause
A faulthandler dump or an external stack dump
timeit with repeat and the best time
A sampling profiler or cProfile
A tracemalloc snapshot diff or memray
Structured logging with request context

The fill in the blank exercise checks the commands that expose a hung or failing process.

Fill in the Blanks
How to answer

Fill-in-the-blank exercise with 3 blanks. Type the missing words, then check your answer.

Complete the commands that expose a hung or failing process.

Start the interpreter with blank to install the fault handler, call blank to dump every thread after a timeout, and set blank to 0 to turn breakpoint calls into no-ops in production.

Word Bank, drag words into the blanks above:

-X faulthandler
faulthandler.dump_traceback_later
PYTHONBREAKPOINT
-X tracemalloc
faulthandler.enable
PYTHONFAULTHANDLER

The recurring traps are about evidence and scope.

  • Optimizing before measuring, then keeping a change because it feels faster.
  • Profiling a debug build, a test fixture or a single request and treating it as the production workload.
  • Comparing two runs on different machines, interpreter versions or input sizes.
  • Changing three things at once, then attributing the result to the wrong one.
  • Reading only the average latency and missing the tail that users experience.
  • Leaving breakpoint() or verbose DEBUG logging enabled in production.
  • Logging secrets, tokens or personal data while chasing a bug.
  • Fixing a leak by forcing garbage collection instead of finding the owner.
  • Trusting a single timeit run with the default number of loops.
  • Measuring a snippet whose result is discarded and then optimized away.
πŸ“ŒImportant

A short review before closing an investigation: can the failure be reproduced, is the evidence from the same environment, did one change explain the result, and will a test or benchmark catch the regression next time?

Real-World Case Studies

The three cases below are composite scenarios built from common production patterns. The tools and commands are real; the names are illustrative.

Case 1: The checkout endpoint that doubled in latency

An endpoint that assembled an order summary grew from 120 ms to 260 ms after a feature flag added a customer profile call. The team could not reproduce it locally because the test fixture returned a cached profile. The first fix was observability: a structured log line with the profile lookup duration. The log showed a p99 of 90 ms for the lookup alone, which was almost the entire regression.

A deterministic profile confirmed the shape. The request handler spent most of its cumulative time below load_profile, and most of the time below load_profile sat in the JSON decoder rather than in the network call. The profile also showed the handler called load_profile five times per request, once for each line item, because the profile was fetched inside a loop.

python
import cProfile import pstats from pstats import SortKey def handle_request(order): lines = [] for item in order.items: profile = load_profile(order.customer_id) lines.append(render_line(item, profile)) return {"lines": lines, "total": sum(line["total"] for line in lines)} profile = cProfile.Profile() profile.enable() summary = handle_request(order) profile.disable() pstats.Stats(profile).strip_dirs().sort_stats( SortKey.CUMULATIVE ).print_stats(10)

The fix was a per request cache, not a global one. The profile call moved out of the loop, and a timeit benchmark of render_line showed that the JSON decode was still the largest per item cost. The team then cached the decoded profile for the duration of the request and measured again: the endpoint returned to about 130 ms. The regression test asserts that load_profile is called once for an order with five items.

The lesson is not "cache everything". It is that a profiler ranks cost by subtree, and a per request cache is a bounded change with a measurable result. A global cache would have fixed the latency too, and it would have introduced a stale data bug that no benchmark would catch.

Case 2: The cache that never forgot

A batch job processed about two million rows per night and grew by roughly 40 MiB per hour. The job finished, so the leak did not page anyone, but the container was killed every third night. Restarting hid the symptom. The team took a tracemalloc snapshot after warm up and another after one hour of the same workload.

python
import tracemalloc tracemalloc.start() run_warmup() before = tracemalloc.take_snapshot() run_workload(hours=1) after = tracemalloc.take_snapshot() for stat in after.compare_to(before, "lineno")[:5]: print(stat)

The top difference pointed at a module level dictionary that mapped a row key to a parsed object. The dictionary was intended as a cache, but it had no size limit and no eviction. The fix replaced it with a bounded cache and a metric for the hit rate. The next snapshot showed flat growth across the same workload.

The important detail is the baseline after warm up. A snapshot taken at process start includes imports, model loading and connection pools, which are one time costs. Comparing two snapshots from the same phase isolates the growth that matters. The second detail is the key: the leaked value was reachable from a module global, so the garbage collector could never reclaim it.

Case 3: The worker that stopped answering

A queue worker stopped processing jobs at 02:10 and resumed after a restart at 02:40. There was no exception in the log, which pointed at a deadlock rather than a crash. The team had already enabled the fault handler at startup, so the first diagnostic was a stack dump on demand.

python
import faulthandler import signal faulthandler.enable() faulthandler.register(signal.SIGUSR1) faulthandler.dump_traceback_later(120, repeat=True, exit=True)

The dump showed the main thread waiting on a lock held by a worker thread, and the worker thread waiting on a database connection from a pool that the main thread had already checked out. The lock order was inconsistent between two code paths. The fix was to acquire the connection before the lock in both paths, and to add a timeout to the checkout so the next incident fails fast.

A second tool confirmed the diagnosis without a restart. py-spy dump showed the same two stacks from outside the process, including the local variables at the waiting frames. That mattered because the first dump was from a staging reproduction, and the production process could not be stopped.

The lesson is to make the diagnosis possible before the incident. The fault handler, the signal registration and the timeout were all small changes made on a quiet afternoon. Without them, the only evidence would have been a gap in the log and a restart.

2026 Updates (as of November 2026)

  • Python 3.15.2 is the current stable release in the 3.15 line, and the examples target 3.11 or newer unless a feature is marked with a later version.
  • Python 3.15 adds the profiling package from PEP 799. profiling.tracing is the deterministic profiler, profiling.sampling is the Tachyon sampling profiler, and cProfile remains a backward-compatible alias. The old profile module is deprecated and will be removed in Python 3.17.
  • Tachyon supports wall-clock, CPU, GIL and exception modes, with output as a pstats table, a flame graph, a heatmap, Firefox Profiler data or a live terminal view. It can attach to a running process by id, which makes it a first choice for production profiling.
  • Python 3.14 added remote attach for pdb with python -m pdb -p PID and the PEP 768 interface behind sys.remote_exec. The interface defines a safe execution point for debugger code in a running interpreter.
  • faulthandler gained dump_c_stack in Python 3.14 and the max_threads argument in Python 3.15. The module remains the fastest way to get a stack from a deadlocked or crashing process.
  • timeit colorizes command line output by default in Python 3.15 and adds --target-time for a minimum measurement duration.
  • The external toolchain is current at py-spy 0.4.3, scalene 2.4.0 and memray 1.20.0. py-spy and memray can attach to a process that is already running, and scalene can start with profiling off and be switched on from another terminal.
  • sys.monitoring since Python 3.12 gives tools a low overhead event system for coverage, tracing and profiling, which is why modern tools can observe more code with less distortion.

The direction is clear: debugging and profiling are moving out of the process. Remote attach, external sampling and native stack capture all avoid the old choice between a restart and a guess. The skill that remains is the same one from the opening story: decide what evidence would settle the question, then collect exactly that.

πŸ“š Did you know?

  • breakpoint() is a built in since Python 3.7, and it routes through sys.breakpointhook, so a test suite or an IDE can replace the debugger without editing the source.
  • faulthandler is implemented in C, which is why it can still write a stack when the interpreter is deadlocked or a C extension has crashed.
  • tracemalloc records the traceback of each allocation, so a snapshot diff points at the line that allocated the memory, not just at the object type.
  • A cProfile file is plain data. The same .prof file can be read by pstats in a terminal, by SnakeViz in a browser, or by a custom report.
  • Diagram widths in a flame graph are shares of samples, not seconds. Two profiles with different durations can look identical because the shape is normalized.

Practice Questions

Practice Question
How to answer

Multiple-choice question with 4 options. Select one option, then choose Check Answer.

An exception report shows the line 'The above exception was the direct cause of the following exception' between two tracebacks. What produced that link?

Practice Question
How to answer

Multiple-choice question with 4 options. Select one option, then choose Check Answer.

A service logs one record per request at INFO. Which call keeps the message template and the data separate inside the logging call?

Practice Question
How to answer

Multiple-choice question with 4 options. Select one option, then choose Check Answer.

A module attaches a console handler to its own logger and leaves propagate at its default. The root logger also has a console handler. Each record appears twice. What is the smallest correct fix?

Practice Question
How to answer

Multiple-choice question with 4 options. Select one option, then choose Check Answer.

In pdb, the current line calls validate(order). The developer wants to stop on the first line inside validate. Which command does that?

Practice Question
How to answer

Multiple-choice question with 4 options. Select one option, then choose Check Answer.

A deployment sets PYTHONBREAKPOINT=0. A breakpoint call in the code is reached. What happens?

Practice Question
How to answer

Multiple-choice question with 4 options. Select one option, then choose Check Answer.

A worker hangs while holding a lock. The team wants a dump of every thread stack after 30 seconds, then process exit so the supervisor restarts it. Which call fits?

Practice Question
How to answer

Multiple-choice question with 4 options. Select one option, then choose Check Answer.

Five timeit.repeat runs return 0.41, 0.39, 0.52, 0.40 and 0.44 seconds for the same statement. Which summary is the usual choice for comparing implementations?

Practice Question
How to answer

Multiple-choice question with 4 options. Select one option, then choose Check Answer.

In cProfile output a function shows high cumulative time but low self time. What does that pattern suggest?

Practice Question
How to answer

Multiple-choice question with 4 options. Select one option, then choose Check Answer.

A production service cannot be restarted, and its latency budget leaves no room for deterministic tracing. Which tool fits the first look?

Practice Question
How to answer

Multiple-choice question with 4 options. Select one option, then choose Check Answer.

A batch job grows by about 40 MiB per hour. Two tracemalloc snapshots are taken an hour apart. Which call shows the lines that grew?

βœ…Success

Key Takeaways

  • Debugging is a loop: reproduce, reduce, inspect, change one thing and verify with a regression test.
  • A traceback is evidence about a call stack; read the whole chain and use the explicit cause before editing.
  • Structured logging with levels, named loggers and context replaces print statements and survives production.
  • pdb is for inspection at a breakpoint or after a failure, and PYTHONBREAKPOINT=0 makes an accidental breakpoint harmless.
  • faulthandler and external samplers recover evidence from hung or crashing processes that never raise a Python exception.
  • timeit compares small implementations, cProfile ranks cost inside a program, and sampling profilers observe production with low overhead.
  • tracemalloc snapshot diffs name the line that allocates and keeps the memory, which is the real cause of most Python leaks.
  • Choose the tool from the symptom, keep one change per measurement and record the environment with every number.

References

Every factual claim links to its source, with the access date printed so the source can be rechecked.

  1. Python Software Foundation Β· Accessed 2026-11-07

  2. Python Software Foundation Β· Accessed 2026-11-07

  3. Python Software Foundation Β· Accessed 2026-11-07

  4. Python Software Foundation Β· Accessed 2026-11-07

  5. Python Software Foundation Β· Accessed 2026-11-07

  6. [6]pdb, The Python DebuggerDocumentation

    Python Software Foundation Β· Accessed 2026-11-07

  7. Python Software Foundation Β· Accessed 2026-11-07

  8. Python Software Foundation Β· Accessed 2026-11-07

  9. YouTube Β· Real Python Β· Accessed 2026-11-07

  10. Python Software Foundation Β· Accessed 2026-11-07

  11. Python Software Foundation Β· Accessed 2026-11-07

  12. GitHub Β· Accessed 2026-11-07

  13. Python Software Foundation Β· Accessed 2026-11-07

  14. Python Software Foundation Β· Accessed 2026-11-07

  15. Python Software Foundation Β· Accessed 2026-11-07

  16. Python Package Index Β· Accessed 2026-11-07

  17. Python Software Foundation Β· Accessed 2026-11-07

  18. [18]What's New In Python 3.15Documentation

    Python Software Foundation Β· Accessed 2026-11-07

  19. GitHub Β· Accessed 2026-11-07

  20. Python Software Foundation Β· Accessed 2026-11-07

  21. GitHub Β· Accessed 2026-11-07

  22. [22]Python 3.15 documentationDocumentation

    Python Software Foundation Β· Accessed 2026-11-07

  23. [23]py-spy 0.4.3 on PyPIRepository

    Python Package Index Β· Accessed 2026-11-07

  24. [24]scalene 2.4.0 on PyPIRepository

    Python Package Index Β· Accessed 2026-11-07

  25. [25]memray 1.20.0 on PyPIRepository

    Python Package Index Β· Accessed 2026-11-07

Progress100%