Performance Profiling
Python · Advanced · Run with python3
Explanation
`cProfile` is CPython's built-in deterministic profiler — it records every function call, call count, and cumulative time. Run with `python -m cProfile -s cumulative script.py`. `pstats` filters and formats results. `line_profiler` (third-party) profiles per-line within a function (decorate with `@profile`, run with `kernprof -l`). `tracemalloc` tracks memory allocations (built-in). For production: `py-spy` is a sampling profiler that attaches to a running process without modifying code.
Real-World Scenario
A report generation script takes 45 seconds. `cProfile` reveals 80% of time is in `str.format()` called 10 million times inside a nested loop. Moving the format call outside the inner loop cuts runtime to 8 seconds — the profile told exactly where to look. ```python import cProfile import pstats import io import timeit def slow_sum(n: int) -> int: """Intentionally slow version using string conversion.""" total = 0 for i in range(n): total += int(str(i)) # Silly but profiling shows it return total def fast_sum(n: int) -> int: return sum(range(n)) # Profile slow_sum pr = cProfile.Profile() pr.enable() result = slow_sum(50_000) pr.disable() buf = io.StringIO() ps = pstats.Stats(pr, stream=buf).sort_stats("cumulative") ps.print_stats(5) # Top 5 functions print(buf.getvalue()) # Quick benchmark slow_t = timeit.timeit("slow_sum(1000)", globals={"slow_sum": slow_sum}, number=100) fast_t = timeit.timeit("fast_sum(1000)", globals={"fast_sum": fast_sum}, number=100) print(f"slow: {slow_t:.3f}s fast: {fast_t:.3f}s speedup: {slow_t/fast_t:.1f}x") ```
Quick Snippet
import cProfile
import pstats
import io
import timeit
def slow_sum(n: int) -> int:
"""Intentionally slow version using string conversion."""
total = 0
for i in range(n):
total += int(str(i)) # Silly but profiling shows it
return total
def fast_sum(n: int) -> int:
return sum(range(n))
# Profile slow_sum
pr = cProfile.Profile()
pr.enable()
result = slow_sum(50_000)
pr.disable()
buf = io.StringIO()
ps = pstats.Stats(pr, stream=buf).sort_stats("cumulative")
ps.print_stats(5) # Top 5 functions
print(buf.getvalue())
# Quick benchmark
slow_t = timeit.timeit("slow_sum(1000)", globals={"slow_sum": slow_sum}, number=100)
fast_t = timeit.timeit("fast_sum(1000)", globals={"fast_sum": fast_sum}, number=100)
print(f"slow: {slow_t:.3f}s fast: {fast_t:.3f}s speedup: {slow_t/fast_t:.1f}x")Full Example
# Compile: python3 profiling.py
# Output:
# Speedup printed between slow and fast implementations
import cProfile
import pstats
import io
import timeit
def slow_sum(n: int) -> int:
total = 0
for i in range(n):
total += int(str(i))
return total
def fast_sum(n: int) -> int:
return sum(range(n))
pr = cProfile.Profile()
pr.enable()
slow_sum(5_000)
pr.disable()
buf = io.StringIO()
ps = pstats.Stats(pr, stream=buf).sort_stats("cumulative")
ps.print_stats(3)
output = buf.getvalue()
# Print just the first few lines
for line in output.splitlines()[:8]:
if line.strip():
print(line)
slow_t = timeit.timeit("slow_sum(500)", globals={"slow_sum": slow_sum}, number=200)
fast_t = timeit.timeit("fast_sum(500)", globals={"fast_sum": fast_sum}, number=200)
print(f"\nslow_sum: {slow_t:.3f}s")
print(f"fast_sum: {fast_t:.3f}s")
print(f"speedup: {slow_t/fast_t:.1f}x")
python3 profiling.py