cProfile and py-spy answer "which function is slow?". Often that is enough; the function has an obvious expensive call and the fix is clear. Sometimes it is not. The hot function is forty lines of loops, comprehensions and small method calls, none of which are separate functions the profiler could attribute time to, and the question becomes "which of these lines?". Guessing is unreliable: the line that looks expensive is frequently fine, and the one that looks trivial runs a million times.
line_profiler times every line of the functions you select. Its report shows, for each line, how many times it ran, the total time spent on it, the time per hit and the percentage of the function's time. It is deliberately narrow — you choose the functions — and deliberately heavy, because timing every line costs overhead. Used as the second step after a sampling profiler, it turns a vague hotspot into a specific line to change.
Prerequisites
line_profiler >= 4.1, Python 3.8 or later.- A hot function identified with CPU profiling with cProfile and py-spy.
Solution
# pricing.py
@profile # injected by kernprof; remove before committing
def apply_rules(order, rules):
total = 0
for line in order.lines:
price = line.unit_price
for rule in rules:
if rule.matches(line):
price = rule.apply(price)
total += price * line.quantity
discounts = [r for r in rules if r.kind == "order"]
for d in discounts:
total = d.apply(total)
return round(total, 2)
kernprof -lv bench_pricing.py
Line # Hits Time Per Hit % Time Line Contents
==============================================================
4 500 0.1 0.0 0.0 total = 0
5 25500 4.9 0.0 0.9 for line in order.lines:
6 25000 4.1 0.0 0.8 price = line.unit_price
7 5025000 812.3 0.0 15.6 for rule in rules:
8 5000000 4102.6 0.0 78.9 if rule.matches(line):
9 12000 14.8 0.0 0.3 price = rule.apply(price)
10 25000 11.3 0.0 0.2 total += price * line.quantity
# Calling it from a test, no kernprof needed.
from line_profiler import LineProfiler
def test_profile_apply_rules(big_order, all_rules, capsys):
lp = LineProfiler()
lp.add_function(apply_rules)
lp.runcall(apply_rules, big_order, all_rules)
lp.print_stats(output_unit=1e-3)
Why this works
kernprof -l injects a profile decorator into builtins and runs the script. The decorator registers each decorated function with a LineProfiler, which uses CPython's tracing hooks to record a timestamp at every line event inside those functions only. Time between consecutive line events is attributed to the earlier line, so each line's "Time" is how long it took to execute including any calls it made. -v prints the report on exit; without it the results are saved to a .lprof file for python -m line_profiler.
The two most useful columns are Hits and % Time, read together. A line with high % Time and low Hits is slow per call — a database query, a regex compile, a large copy. A line with high % Time and very high Hits is cheap per call but called too often — the loop-within-a-loop in the example. The fixes differ: the first needs a faster operation, the second needs fewer calls, and Hits tells you which you are looking at before you start optimising.
Reading the numbers honestly
line_profiler's absolute times are inflated. Each line event costs a timer call and some bookkeeping, and for a line that takes 50 nanoseconds on its own, that overhead can double or triple the measurement. The effect is largest on cheap lines executed many times, which means it exaggerates exactly the hot loops you are looking at.
The percentages are more trustworthy than the absolute times, but still biased towards lines with many hits. Confirm any improvement by timing the whole function without the profiler — timeit, pytest-benchmark, or simply the benchmark script — before and after the change. A change that makes the line_profiler report look better but does not improve real runtime was optimising the profiler's overhead.
Acting on the report: the rule-matching fix
The report above makes the fix almost mechanical. Five million calls to rule.matches for 25,000 order lines means every one of 200 rules was checked against every line, although only 12,000 checks — about one in four hundred — actually matched. The work is dominated by rejecting rules that could never apply.
The standard fix is an index. Most pricing rules match on a single attribute — a SKU, a category, a customer tier — so build a dictionary from that attribute to the rules that mention it, once, before the loop. For each line, look up only the candidate rules and check those. Rules that match on something more complex stay in a small "always check" list.
by_category = defaultdict(list)
general = []
for r in rules:
(by_category[r.category] if r.category else general).append(r)
for line in order.lines:
for rule in chain(by_category.get(line.category, ()), general):
...
Re-running kernprof after the change shows the matches line dropping from five million hits to a few tens of thousands, and its share of the function time falling below a third. More importantly, the benchmark without the profiler attached shows the function running about fifteen times faster on the large test order. The profiler's absolute numbers overstated the original cost, as expected, but the direction and rough scale of the improvement were right.
The indexing step itself deserves a place in the report too. If the rules change rarely, build the index once when rules are loaded rather than on every call; line_profiler on the new version will show whether index construction has become the new hot line, which happens surprisingly often when the optimisation is applied inside the function being optimised.
Profiling more than one function at once
The decorator approach profiles one function at a time, but the slow line is sometimes in a helper the hot function calls. Rather than moving @profile around and re-running, register several functions together. With the API, call add_function for each; with kernprof, decorate each one. The report then has one section per function, each with its own totals, and the call from the outer function's line to the inner function appears as time on that outer line — which, read against the inner function's total, shows how much of the call is the helper's own work and how much is argument preparation or result handling.
For methods on classes, add_function(Class.method) works as long as the method is accessed through the class, not an instance. For code that uses many small helpers from one module, LineProfiler.add_module(module) registers every function defined in it — heavy, but convenient for a quick survey of a small module before narrowing again.
Keep the set small. Every registered function pays the line-tracing overhead on every call, and profiling a dozen helpers in a tight loop can slow the program by an order of magnitude and distort the relative timings beyond usefulness. Two or three functions — the hot one and its most suspicious callees — is almost always enough to find the line that matters.
Edge cases and failure modes
NameError: name 'profile' is not defined. The decorator only exists under kernprof. Remove it before running normally, or define a no-op fallback in development code.- Nothing reported for a function. It was never called under the profiler, or the decorated object is not the one being called — a method replaced by a wrapper, or a function imported before decoration.
- Generators and async functions. line_profiler supports both, but time spent suspended is not counted; awaiting slow I/O shows as a fast line.
- Comprehensions. A list comprehension is one line with one hit per evaluation; the per-element work is invisible. Expand it into a loop temporarily if you need the detail.
- C extensions. Time inside a C function is attributed to the calling line as a whole. line_profiler cannot see inside NumPy calls.
Frequently Asked Questions
When should I use line_profiler instead of cProfile? After cProfile or py-spy has identified a hot function. cProfile tells you which functions take time; line_profiler tells you which lines inside one function do. Profiling every line of a program with line_profiler is slow and noisy.
Why is line_profiler's total time higher than the real runtime? Timing every line adds overhead to each line's execution, which is especially large for cheap lines executed millions of times. Treat the absolute times as inflated and focus on the relative percentages.
Can I use line_profiler on code called from pytest?
Yes. Create a LineProfiler in a fixture or test, add the function with add_function, run the code through the profiler's wrapper, and print_stats at the end. The kernprof command-line tool is not needed.
Related
- CPU Profiling with cProfile and py-spy — finding the hot function.
- Interpreting cProfile Cumulative vs Total Time — reading function-level reports.
- Benchmarking with pytest-benchmark — verifying improvements.
- Reading py-spy Flame Graphs — the sampling view.
← Back to CPU Profiling with cProfile and py-spy