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
- The report of the call stack at the moment an exception was raised, from the outermost frame to the frame that failed.
- A marked location where the interpreter pauses so a debugger can inspect state before execution continues.
- Inspecting the state of a program after it has already raised an unhandled exception.
- A severity label such as DEBUG, INFO or WARNING that decides whether a record is emitted.
- The logging object that sends a formatted record to a destination such as the console, a file or a queue.
- A profiler that records every function call and return, which gives exact counts but adds overhead.
- A profiler that reads the call stack at intervals and estimates where time is spent, with low overhead.
- A visualization of nested call frames where the width of a bar represents the time or memory attributed to that frame.
- Memory that stays reachable and therefore cannot be reclaimed, often because a cache or registry keeps growing.
- A repeatable measurement of a small piece of code under controlled conditions, used to compare implementations.
- Connecting a debugger or profiler to an already running process by its process id.
- The highest amount of traced memory in use during a measurement window, not just the amount at the end.
Traceback
Breakpoint
Post-mortem debugging
Log level
Handler
Deterministic profiler
Sampling profiler
Flame graph
Memory leak
Benchmark
Remote attach
Peak memory
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.
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.
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.
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.
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.csvThe 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.
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.
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.
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.
try:
charge(order)
except PaymentError:
logger.exception("charge failed for order %s", order.id)
raiseFor 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.
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.
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.
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.
def apply_discount(price: float, percent: float) -> float:
discount = price * percent / 100
breakpoint()
return price - discount$ 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) cThe 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.
PYTHONBREAKPOINT=0 python -m billing.worker
PYTHONBREAKPOINT=ipdb.set_trace python -m billing.workerThe 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.
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.
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.
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.
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.
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.
PYTHONFAULTHANDLER=1 python -m billing.worker
python -X faulthandler -m billing.worker
kill -USR1 1234The 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.
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.
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.
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.
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.
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.
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.
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.
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.
python -m cProfile -o profile.out -s cumulative billing.py
python -m snakeviz profile.outSaving 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.
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.
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 12345The 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.
py-spy record -o profile.svg --pid 12345
py-spy top --pid 12345
py-spy dump --pid 12345 --localsScalene 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".
scalene run worker.py
scalene view --htmlDescription
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.
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.
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.
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.
memray run -o output.bin worker.py
memray flamegraph output.bin
memray attach 12345
memray run --native worker.pyA 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.
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.
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.
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.
The matching exercise connects a symptom to the first tool.
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.
Drag answers from here:
The fill in the blank exercise checks the commands that expose a hung or failing process.
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:
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
timeitrun with the default number of loops. - Measuring a snippet whose result is discarded and then optimized away.
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.
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.
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.
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
profilingpackage from PEP 799.profiling.tracingis the deterministic profiler,profiling.samplingis the Tachyon sampling profiler, andcProfileremains a backward-compatible alias. The oldprofilemodule is deprecated and will be removed in Python 3.17. - Tachyon supports wall-clock, CPU, GIL and exception modes, with output as a
pstatstable, 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 PIDand the PEP 768 interface behindsys.remote_exec. The interface defines a safe execution point for debugger code in a running interpreter. faulthandlergaineddump_c_stackin Python 3.14 and themax_threadsargument in Python 3.15. The module remains the fastest way to get a stack from a deadlocked or crashing process.timeitcolorizes command line output by default in Python 3.15 and adds--target-timefor 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.monitoringsince 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 throughsys.breakpointhook, so a test suite or an IDE can replace the debugger without editing the source.faulthandleris implemented in C, which is why it can still write a stack when the interpreter is deadlocked or a C extension has crashed.tracemallocrecords the traceback of each allocation, so a snapshot diff points at the line that allocated the memory, not just at the object type.- A
cProfilefile is plain data. The same.proffile can be read bypstatsin 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
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?
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?
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?
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?
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?
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?
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?
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?
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?
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?
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.
pdbis for inspection at a breakpoint or after a failure, andPYTHONBREAKPOINT=0makes an accidental breakpoint harmless.faulthandlerand external samplers recover evidence from hung or crashing processes that never raise a Python exception.timeitcompares small implementations,cProfileranks cost inside a program, and sampling profilers observe production with low overhead.tracemallocsnapshot 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.