python-profiling
verified7ac20d1a-5a53-47f5-91f6-312ddbbc90eb
Profile Python to find real hotspots (cProfile/py-spy) and fix the actual bottleneck instead of guessing. Use when code is too slow and you don't know where time goes.
Metadata
Skill file
# Python Profiling
Use when Python code is too slow and you don't know where the time goes ā profile first, then fix the actual hotspot. Never optimize by guessing.
## Capturing a Profile
### cProfile + snakeviz (stdlib, visual)
```bash
# Profile a script
python -m cProfile -o profile.prof my_script.py
# Visualize in the browser
pip install snakeviz
snakeviz profile.prof
```
```python
# Profile a specific function in code
import cProfile
import pstats
profiler = cProfile.Profile()
profiler.enable()
result = expensive_function(data)
profiler.disable()
stats = pstats.Stats(profiler).sort_stats("cumulative")
stats.print_stats(20) # top 20 by cumulative time
```
### py-spy (sampling profiler, attach to running process)
```bash
pip install py-spy
# Top-style live view of a running process
py-spy top --pid 12345
# Record a flame graph (SVG)
py-spy record -o profile.svg --pid 12345
# Profile a script from the start
py-spy record -o profile.svg -- python my_script.py
```
## Reading the Numbers: Cumulative vs Self Time
```
ncalls tottime percall cumtime percall filename:lineno(function)
1 0.001 0.001 12.500 12.500 my_script.py:5(main)
1 0.000 0.000 11.300 11.300 my_script.py:20(process_all)
1000 0.200 0.000 11.200 0.011 db.py:40(fetch_record)
1 0.050 0.050 1.100 1.100 my_script.py:30(parse)
```
| Column | Meaning | Use |
|---|---|---|
| **tottime** (self time) | Time spent *inside* this function, excluding calls | Find the actual work |
| **cumtime** | Total time including all calls this function makes | Trace the call path |
| **ncalls** | Number of calls | Spot accidental loops (1000 calls where 1 expected) |
**Rule**: A function with high `cumtime` but low `tottime` is a *dispatcher* ā the real cost is in what it calls. A function with high `tottime` is the *actual hotspot*.
## Finding the Hotspot, Then the Fix
### Fix-by-Category Decision Table
| Profile Pattern | Cause | Fix |
|---|---|---|
| High `tottime` in a nested loop | Accidental O(nĀ²) | Replace with dict/set lookup or `collections.Counter` |
| High `tottime` in string building | `+=` in a loop (O(nĀ²) reallocation) | `''.join(parts)` |
| High `cumtime` in a DB/network call with high `ncalls` | N+1 queries | Batch into one query (see `n-plus-one-query-detection`) |
| Same expensive function called repeatedly with same args | Repeated work | Cache with `functools.lru_cache` |
| High `tottime` in I/O (file read, socket) | I/O bound | `asyncio`, threads, or parallel processes |
| High `tottime` in pure computation | Algorithmic | Use a better algorithm or `numpy` vectorization |
### Concrete Examples
```python
# O(nĀ²) ā membership test on a list inside a loop
seen = []
for item in items:
if item in seen: # O(n) each iteration ā O(nĀ²)
...
seen.append(item)
# O(n) ā use a set
seen = set()
for item in items:
if item in seen: # O(1)
...
seen.add(item)
```
```python
# Repeated expensive computation ā cache
from functools import lru_cache
@lru_cache(maxsize=128)
def expensive_lookup(key: str) -> dict:
return db.fetch(key) # only called once per unique key
```
## The Measure-First Rule
**Always profile before AND after** ā prove the speedup with numbers, not feelings.
```bash
# Before
time python my_script.py
# real 0m12.5s
# ... make the fix ...
# After
time python my_script.py
# real 0m2.1s ā 6x speedup, proven
```
```python
# Micro-benchmark a single function with timeit
python -m timeit -s "from mymod import process" "process(data)"
```
## Guardrails
- **Never** optimize code you haven't profiled ā you'll spend hours on a 0.1% path.
- **Never** micro-optimize at the cost of readability without a measured, significant win.
- **Always** profile a *representative* workload ā a tiny toy input will point you at the wrong hotspot.
- **Always** re-run the profile after the fix to confirm the hotspot actually moved.
## Pitfalls
- **Optimizing unmeasured code**: "This loop looks slow, let me rewrite it" ā while the real 80% is a DB query. Profile first, always.
- **Micro-optimizing a 0.1% path**: Shaving 10ms off a function called once at startup. Irrelevant to total runtime. Focus on the cumulative top.
- **Profiling a non-representative workload**: Profiling with 10 records when production processes 100,000 will hide the O(nĀ²) that only appears at scale.
- **Confusing cumulative and self time**: Rewriting the dispatcher (high cumtime) when the real cost is in a callee (high tottime). Read both columns.
- **Premature caching**: Adding `lru_cache` to everything introduces stale-data bugs. Cache only verified-expensive, frequently-repeated, deterministic calls.
## Verify / Checklist
- [ ] Profile captured with a representative, production-like workload
- [ ] Hotspot identified by reading *both* cumulative and self time (and ncalls)
- [ ] Root cause categorized (algorithmic / I/O / repeated work / O(nĀ²))
- [ ] Fix applied to the actual hotspot, not a guessed location
- [ ] Before/after timing measured (`time` or `timeit`) ā speedup quantified
- [ ] Profile re-run after the fix to confirm the hotspot moved
- [ ] No readability sacrificed without a measured, significant winAttached files
No attached files.