Gutes Performance-Tuning folgt der wissenschaftlichen Methode (messen, Hypothese bilden, optimieren, verifizieren). Profiling liefert uns die Messdaten, um Premature Optimization (Donald Knuth) zu vermeiden.
Wir betrachten Tools für Makro- und Mikroanalysen: von simplen Zeitmessungen über deterministisches Profiling bis hin zu statistischem Sampling.
Im Kapitel Datenstrukturen steht eine Intuition dafür, welche Operationen in Python teuer sind. Dieses Kapitel liefert die Werkzeuge, um sie zu überprüfen — und wer das einmal tut, stellt regelmäßig fest, dass die Intuition am konkreten Programm vorbeigeht.
Worum es geht. Herausfinden, wo ein Programm seine Zeit lässt, statt es zu erraten. Sechs Werkzeuge von der einfachen Zeitmessung bis zum Sampling am laufenden Prozess, alle am selben Monte-Carlo-Random-Walk vorgeführt.
Was Sie danach können. Mit %timeit zwei Implementierungen vergleichen; von der Funktion (cProfile) zur Zeile absteigen (line_profiler, scalene); einen laufenden Prozess von außen untersuchen (py-spy); Speicher statt Zeit messen (memray); und begründen, welches Werkzeug eine gegebene Frage beantwortet — und welches nicht.
Die Java-Entsprechung in einem Satz. cProfile entspricht dem instrumentierenden Modus eines Java-Profilers und py-spy dem Sampling-Modus etwa von async-profiler; der Grund, warum man beide braucht, ist derselbe wie dort: Instrumentierung verfälscht gerade viele kurze Aufrufe.
# Vorbereitung: Virtuelle Umgebung und Tools installieren
!uv venv --quiet
!uv sync --quiet
!uv pip install --quiet line-profiler memray py-spy scalene snakevizBeispiel: Monte-Carlo Random Walk¶
Wir simulieren Random Walks. Der Code enthält absichtlich ineffiziente Implementierungsdetails (z. B. random.choice statt random.getrandbits oder vektorisierten Operationen), um einen typischen CPU-Flaschenhals zu erzeugen.
%%writefile simulation.py
import random
import math
def random_walk(steps):
position = 0
for _ in range(steps):
# Absichtlich ineffizient: Listen-Allokation bei jedem Schleifendurchlauf
position += random.choice([-1, 1])
return position
def simulate_multiple_walks(runs, steps):
return [random_walk(steps) for _ in range(runs)]
def compute_statistics(data):
n = len(data)
mean = sum(data) / n
variance = sum((x - mean) ** 2 for x in data) / n
return mean, math.sqrt(variance)
def main():
data = simulate_multiple_walks(5000, 1000)
mean, std_dev = compute_statistics(data)
print(f"Mean: {mean:.2f}, StdDev: {std_dev:.2f}")
if __name__ == "__main__":
main()
Writing simulation.py
Einfache Messung mit timeit¶
Für einen schnellen Überblick reicht oft das eingebaute timeit-Modul. Es deaktiviert standardmäßig die Garbage Collection, um konsistentere Ergebnisse zu liefern. Man spricht von makroskopischer Messung weil die Gesamtlaufzeit eines Codeblocks gemessen wird (letztlich durch Erfassen der Systemzeit vor und nach dem Lauf). Es ist dabei üblich, mehrere Durchläufe eines Programms auszumessen und die Werte zu mitteln (meist mit einem harmonischen Mittel oder einfach dem Minimum - je nachdem, was man wissen möchte).
# Gesamtlaufzeit messen (1 Durchlauf)
!uv run python -m timeit -n 1 -r 1 "import simulation; simulation.main()"Mean: 0.16, StdDev: 31.25
1 loop, best of 1: 951 msec per loop
Messen im Notebook: die Zellmagics %time und %timeit¶
Der Aufruf über python -m timeit oben ist der Weg von der Kommandozeile. Im Notebook (und in jeder IPython-Sitzung) geht es direkter: %time misst einen Durchlauf, %timeit wiederholt ihn oft genug für eine belastbare Aussage. Beide gibt es als Zeilen-Magic (%, misst den Rest der Zeile) und als Zell-Magic (%%, misst die ganze Zelle).
import simulation
%time ergebnis = simulation.simulate_multiple_walks(500, 1000)
%time ergebnis = simulation.simulate_multiple_walks(500, 1000)CPU times: user 128 ms, sys: 0 ns, total: 128 ms
Wall time: 128 ms
CPU times: user 127 ms, sys: 0 ns, total: 127 ms
Wall time: 127 ms%time zeigt CPU-Zeit (user + sys) und Wall Time getrennt. Weichen beide stark voneinander ab, wartet das Programm — auf Platte, Netz oder einen anderen Thread — statt zu rechnen. Ein einzelner Durchlauf schwankt allerdings erheblich; verlässt man sich darauf, misst man oft den Zustand des CPU-Caches oder einen zufällig dazwischengeratenen anderen Prozess.
%timeit nimmt einem diese Sorge ab: Es bestimmt selbst eine sinnvolle Anzahl von Durchläufen, wiederholt die Messung mehrfach und berichtet Mittelwert und Streuung.
%timeit simulation.random_walk(10_000)
%timeit -n 100 -r 3 simulation.compute_statistics(list(range(5_000)))2.45 ms ± 18.6 μs per loop (mean ± std. dev. of 7 runs, 100 loops each)
433 μs ± 12.7 μs per loop (mean ± std. dev. of 3 runs, 100 loops each)Mit -n legt man die Schleifendurchläufe pro Messung fest, mit -r die Anzahl der Messungen. Wichtig ist die Streuung: Liegt sie in derselben Größenordnung wie der Unterschied zwischen zwei Varianten, die man vergleichen will, hat man nichts gezeigt.
Zwei Fallen lauern hier. Erstens misst %timeit den Code mehrfach — bei einer Funktion mit Nebenwirkungen (Datei schreiben, Liste leeren, Zähler erhöhen) misst man ab dem zweiten Durchlauf etwas anderes. Zweitens schaltet timeit die Garbage Collection ab, um die Streuung zu senken; bei Code, der viele Objekte erzeugt, fällt die reale Laufzeit dadurch günstiger aus als im Betrieb.
Zeilenweise Messung mit line_profiler¶
timeit sagt uns, dass random_walk langsam ist. Welche Zeile die Zeit verbraucht, sagt es nicht, und cProfile (unten) auch nicht: Es rechnet pro Funktionsaufruf ab. Genau diese Lücke füllt line_profiler.
Das Werkzeug misst nicht alles, sondern nur die Funktionen, die man ihm mit @profile zeigt — das hält den Overhead beherrschbar. Der Dekorator wird dabei nicht importiert: kernprof legt ihn vor der Ausführung in die Builtins. Ein direkter Aufruf von python simulation_profiled.py scheitert deshalb mit NameError: name 'profile' is not defined.
%%writefile simulation_profiled.py
import random
import math
@profile
def random_walk(steps):
position = 0
for _ in range(steps):
position += random.choice([-1, 1])
return position
@profile
def compute_statistics(data):
n = len(data)
mean = sum(data) / n
variance = sum((x - mean) ** 2 for x in data) / n
return mean, math.sqrt(variance)
def main():
data = [random_walk(1000) for _ in range(300)]
mean, std_dev = compute_statistics(data)
print(f"Mean: {mean:.2f}, StdDev: {std_dev:.2f}")
if __name__ == "__main__":
main()
Writing simulation_profiled.py!uv run kernprof --line-by-line --view simulation_profiled.pyMean: 2.49, StdDev: 30.76
Wrote profile results to 'simulation_profiled.py.lprof'
Timer unit: 1e-06 s
Total time: 0.658208 s
File: simulation_profiled.py
Function: random_walk at line 4
Line # Hits Time Per Hit % Time Line Contents
==============================================================
4 @profile
5 def random_walk(steps):
6 300 86.4 0.3 0.0 position = 0
7 300300 53621.5 0.2 8.1 for _ in range(steps):
8 300000 604440.3 2.0 91.8 position += random.choice([-1, 1])
9 300 59.9 0.2 0.0 return position
Total time: 0.000104787 s
File: simulation_profiled.py
Function: compute_statistics at line 11
Line # Hits Time Per Hit % Time Line Contents
==============================================================
11 @profile
12 def compute_statistics(data):
13 1 0.8 0.8 0.7 n = len(data)
14 1 4.8 4.8 4.6 mean = sum(data) / n
15 1 97.0 97.0 92.6 variance = sum((x - mean) ** 2 for x in data) / n
16 1 2.1 2.1 2.0 return mean, math.sqrt(variance)
Damit ist die Diagnose eindeutig: Über 90% der Laufzeit von random_walk stecken in einer einzigen Zeile, nämlich random.choice([-1, 1]) — und zwar nicht, weil die Zufallszahl teuer wäre, sondern weil bei jedem der 300.000 Durchläufe eine neue zweielementige Liste angelegt wird. Die Spalte Hits zeigt das unmittelbar; Per Hit ist mit 2 Mikrosekunden unauffällig, die Masse macht den Unterschied. Bei compute_statistics liegt die Zeit erwartungsgemäß in der Zeile mit dem Generator-Ausdruck.
Die Messwerte stehen außerdem in simulation_profiled.py.lprof und lassen sich später ohne erneuten Lauf ansehen:
uv run python -m line_profiler simulation_profiled.py.lprofIm Notebook geht es auch ohne @profile im Quelltext — dann sagt man beim Aufruf, welche Funktion zeilenweise vermessen werden soll:
%load_ext line_profiler
%lprun -f simulation.random_walk simulation.random_walk(10_000)Eine Warnung zur Interpretation: line_profiler verlangsamt die vermessenen Funktionen um ein Vielfaches. Die absoluten Zeiten taugen deshalb nicht zum Vergleich mit einem ungemessenen Lauf, die Verhältnisse zwischen den Zeilen einer Funktion schon. Und pro Zeile wird zusammengefasst: Stehen mehrere Aufrufe in einer Zeile, sieht man nicht, welcher davon teuer war.
Welches der Werkzeuge in diesem Kapitel wofür taugt, fasst die Tabelle am Kapitelende zusammen.
Deterministisches Profiling mit cProfile¶
cProfile ist in der C-Implementierung von Python integriert. Es misst jeden einzelnen Funktionsaufruf (deterministisch). Der Overhead ist spürbar, liefert aber exakte Call-Counts.
Wir sortieren die Ausgabe direkt nach der kumulierten Zeit (cumtime).
!uv run python -m cProfile -s cumtime simulation.py 2> /dev/null | head -n 20Mean: 0.26, StdDev: 31.86
35009204 function calls (35009181 primitive calls) in 5.236 seconds
Ordered by: cumulative time
ncalls tottime percall cumtime percall filename:lineno(function)
3/1 0.000 0.000 5.236 5.236 {built-in method builtins.exec}
1 0.000 0.000 5.236 5.236 simulation.py:1(<module>)
1 0.000 0.000 5.236 5.236 simulation.py:20(main)
1 0.001 0.001 5.235 5.235 simulation.py:11(simulate_multiple_walks)
5000 0.688 0.000 5.234 0.001 simulation.py:4(random_walk)
5000000 1.543 0.000 4.546 0.000 random.py:345(choice)
5000000 1.616 0.000 2.491 0.000 random.py:245(_randbelow_with_getrandbits)
9998442 0.534 0.000 0.534 0.000 {method 'getrandbits' of '_random.Random' objects}
10000024 0.513 0.000 0.513 0.000 {built-in method builtins.len}
5000000 0.340 0.000 0.340 0.000 {method 'bit_length' of 'int' objects}
1 0.000 0.000 0.001 0.001 simulation.py:14(compute_statistics)
2 0.000 0.000 0.001 0.000 {built-in method builtins.sum}
5/1 0.000 0.000 0.001 0.001 <frozen importlib._bootstrap>:1349(_find_and_load)
5/1 0.000 0.000 0.001 0.001 <frozen importlib._bootstrap>:1304(_find_and_load_unlocked)
Visuelle Analyse mit SnakeViz¶
Text-Tabellen sind bei tiefen Call-Stacks unübersichtlich. Wir speichern die cProfile-Daten binär (-o) und nutzen snakeviz für eine interaktive Icicle-/Sunburst-Darstellung im Browser.
!uv run python -m cProfile -o simulation.prof simulation.pyMean: 0.73, StdDev: 32.13
Der folgende Befehl öffnet einen Webbrowser.
uv run snakeviz simulation.profSo sieht es aus:
Mikroanalyse auf Zeilenebene¶
line_profiler oben hat uns die Zeit pro Zeile gezeigt, aber nicht, wofür sie draufging. Genau hier setzt scalene an: Es schlüsselt pro Zeile auf, wie viel davon auf Python-Bytecode, auf C-Code in Bibliotheken und auf Speicherallokationen entfällt — und es braucht dafür keine @profile-Markierung im Quelltext.
# Scalene generiert eine übersichtliche CLI-Ausgabe oder ein HTML-Profil.
!uv run scalene run --cli --reduced-profile simulation.py
!uv run scalene view --cliMean: 0.12, StdDev: 31.80
Scalene: profile saved to scalene-profile.json
To view in browser: scalene view
To view in terminal: scalene view --cli
NOTE: The GPU is currently running in a mode that can reduce Scalene's accuracy when reporting GPU utilization.
If you have sudo privileges, you can run this command (Linux only) to enable per-process GPU accounting:
python3 -m scalene.set_nvidia_gpu_modes
/home/konrad/Sciebo/hhu/eipy-26/eipy-skript/part-tools/simulation.py: % of ti
100.00% (1.458s) out of 1.458s.
╷ ╷ ╷ ╷ ╷ ╷ ╷ ╷ ╷
│Time │––––… │–––––– │––––… │Await │Memory │–––––– │––––––––––– │Co
Line │Python │nati… │system │GPU │% │Python │peak │timeline/% │(M
╺━━━━━━┿━━━━━━━┿━━━━━━┿━━━━━━━┿━━━━━━┿━━━━━━━┿━━━━━━━┿━━━━━━━┿━━━━━━━━━━━━━━━┿━━
1 │ │ │ │ │ │ │ │ │
2 │ │ │ │ │ │ │ │ │
3 │ │ │ │ │ │ │ │ │
4 │ │ │ │ │ │ │ │ │
5 │ │ │ │ │ │ │ │ │
6 │ │ │ │ │ │ │ │ │
7 │ │ │ │ │ │ │ │ │
8 │ 13% │ 8… │ 2% │ 6% │ │ │ │ │
9 │ │ │ │ │ │ │ │ │
10 │ │ │ │ │ │ │ │ │
11 │ │ │ │ │ │ │ │ │
12 │ │ │ │ │ │ │ │ │
13 │ │ │ │ │ │ │ │ │
14 │ │ │ │ │ │ │ │ │
15 │ │ │ │ │ │ │ │ │
16 │ │ │ │ │ │ │ │ │
17 │ │ │ │ │ │ │ │ │
18 │ │ │ │ │ │ │ │ │
19 │ │ │ │ │ │ │ │ │
20 │ │ │ │ │ │ │ │ │
21 │ │ │ │ │ │ │ │ │
22 │ │ │ │ │ │ │ │ │
23 │ │ │ │ │ │ │ │ │
24 │ │ │ │ │ │ │ │ │
25 │ │ │ │ │ │ │ │ │
26 │ │ │ │ │ │ │ │ │
╵ ╵ ╵ ╵ ╵ ╵ ╵ ╵ ╵
Function summaries:
random_walk (line 4): 13% Python, 84% native
Etwas ansprechender ist die interaktive grafische Oberfläche:
uv run scalene viewNicht-intrusives Sampling: Py-Spy¶
cProfile verändert durch den Overhead das Laufzeitverhalten. Sampling-Profiler wie py-spy pausieren den Python-Prozess stattdessen extrem kurz (z.B. 100 Mal pro Sekunde) und lesen den C-Stack aus.
Vorteile: Nahezu Zero-Overhead, kann an bereits laufende Prozesse (via PID) angehängt werden und generiert direkt Flame Graphs.
# Py-spy benötigt oft Root-Rechte, um Speicher fremder Prozesse zu lesen (sudo).
# Im User-Space (wie hier) generieren wir einen Flamegraph direkt beim Starten:
!uv run py-spy record -o flamegraph.svg -- python simulation.pypy-spy> Sampling process 100 times a second. Press Control-C to exit.
Mean: 0.42, StdDev: 31.55
py-spy> Stopped sampling because process exited
py-spy> Wrote flamegraph data to 'flamegraph.svg'. Samples: 98 Errors: 0
Memory Profiling mit Memray¶
Während Tools wie Scalene CPU und Speicher kombiniert analysieren, ist memray ein hochspezialisierter C-basierter Memory-Profiler.
Er fängt jede Speicherallokation ab – sowohl im reinen Python-Code als auch in C-Erweiterungen (wie NumPy). Das Tool modifiziert den Quellcode nicht und eignet sich hervorragend, um Memory Leaks oder temporäre Allokations-Spitzen exakt zu lokalisieren.
Im generierten Flamegraph lässt sich nicht nur die Gesamtmenge des allokierten Speichers ablesen, sondern auch visuell zwischen Python-Allokationen und nativen C-Allokationen unterscheiden.
!uvx memray run -o simulation.bin simulation.py
!uvx memray flamegraph simulation.binWriting profile results into simulation.bin
Memray WARNING: Correcting symbol for malloc from 0x4247d0 to 0x72ac068ad670
Memray WARNING: Correcting symbol for free from 0x424520 to 0x72ac068add50
Mean: 0.72, StdDev: 31.70
[memray] Successfully generated profile results.
You can now generate reports from the stored allocation records.
Some example commands to generate reports:
/home/konrad/.cache/uv/archive-v0/wXZ7NNq1jZwFohZOnNcWO/bin/python -m memray flamegraph simulation.bin
File already exists, will not overwrite: memray-flamegraph-simulation.html
memray flamegraph schreibt seinen Report als eigenständige HTML-Datei neben das Notebook,
hier part-tools/memray-flamegraph-simulation.html. Öffnen Sie sie im Browser: Dort ist der
Flamegraph interaktiv — Suchfeld, Zoom per Klick auf einen Frame, Umschalten zwischen Flames
und Icicles, dazu eine zweite Ansicht „Memory Graph" mit dem zeitlichen Verlauf des belegten
Speichers.
Welches Werkzeug wann?¶
Alle Werkzeuge dieses Kapitels im Überblick. Sie messen verschiedene Dinge, und die häufigste Fehlerquelle ist, die Ergebnisse zweier Werkzeuge miteinander zu vergleichen.
| Werkzeug | misst | Granularität | Overhead | typischer Einsatz |
|---|---|---|---|---|
time/timeit (%time, %timeit) | Wall- und CPU-Zeit eines Ausdrucks | ganzer Codeblock | vernachlässigbar (aber GC aus) | A/B-Vergleich zweier Implementierungen |
cProfile | Aufrufe und Zeit pro Funktion, deterministisch | Funktion | spürbar; verfälscht viele kurze Aufrufe | “wo ungefähr steckt die Zeit?” als erster Schritt |
line_profiler | Zeit pro Zeile, nur in markierten Funktionen | Zeile | hoch in den markierten Funktionen | ein bekannter Hotspot soll aufgeschlüsselt werden |
scalene | CPU (Python vs. C) und Speicher pro Zeile | Zeile | moderat (Sampling) | wenn unklar ist, ob Rechnen oder Allozieren das Problem ist |
py-spy | Stacks per Sampling, von außen | Funktion/Stack | sehr gering | laufender Prozess, Produktion, fremder Code |
memray | Allokationen, nicht Zeit | Zeile/Stack | moderat | Speicherverbrauch und Lecks |
Die übliche Reihenfolge ist damit: mit timeit prüfen, dass es überhaupt ein Problem gibt und wie groß es ist; mit cProfile (oder py-spy am laufenden Prozess) die verantwortliche Funktion finden; mit line_profiler oder scalene die Zeile; danach ändern — und mit timeit nachmessen, ob die Änderung wirklich etwas gebracht hat. Nur der letzte Schritt beantwortet die Frage, wegen der man angefangen hat.
Ausblick: Continuous Profiling und eBPF¶
Während py-spy hervorragend für die lokale Analyse oder punktuelles Debugging einzelner Prozesse geeignet ist, erfordern verteilte Cloud-Systeme eine kontinuierliche Überwachung.
Moderne Tools wie Parca oder Prodfiler nutzen eBPF (Extended Berkeley Packet Filter). Anstatt den Python-Prozess aus dem User-Space zu pollen, klinken sie sich direkt auf Kernel-Ebene in die Ausführung ein.
Vorteil: Nahezu Zero-Overhead (oft < 1%), da keine Context-Switches nötig sind.
Ergebnis: Aggregierte Flame Graphs in Echtzeit, die aufzeigen, wo ein gesamtes Cluster CPU-Zeit verbringt.
Und seit Python 3.15 steht ein Sampling-Profiler in der Standardbibliothek. PEP 799 (Status Final, Python 3.15) räumt die Profiler in ein gemeinsames Paket profiling ein und ordnet sie nach Methode statt nach Alter:
profiling.samplingist der neue statistische Profiler — intern trägt er den Codenamen Tachyon. Er arbeitet mit periodischem Stack-Sampling, kann sich an einen laufenden Prozess hängen, kennt Threads undasyncio-Tasks als eigene Einheiten und läuft auch im Freethreading-Build. Das ist alsopy-spyals Bordwerkzeug.profiling.tracingist die bisherige deterministische Implementierung;cProfilebleibt als Alias erhalten, sodass vorhandener Code weiterläuft.Das alte, in Python geschriebene Modul
profilewird abgekündigt: Warnungen ab 3.15, mehr Warnungen in 3.16, Entfernung in 3.17.
Für die Tabelle oben heißt das: Die Zeilen zu cProfile und py-spy beschreiben ab 3.15 zwei Teile eines Standardmoduls. Die externen Werkzeuge verlieren damit nicht ihren Sinn — scalene misst zusätzlich Speicher und trennt Python- von C-Zeit, memray verfolgt Allokationen —, aber der Einstieg braucht keine Installation mehr.
Zusammenfassung und Kontrollfragen¶
Profiling folgt der wissenschaftlichen Methode — messen, Hypothese bilden, ändern, nachmessen; der letzte Schritt wird am häufigsten weggelassen.
Die Reihenfolge ist festgelegt:
timeitklärt, ob es überhaupt ein Problem gibt,cProfileoderpy-spydie verantwortliche Funktion,line_profileroderscalenedie Zeile.Die Werkzeuge messen verschiedene Dinge; die Ergebnisse zweier Werkzeuge miteinander zu vergleichen ist die häufigste Fehlerquelle dieses Kapitels.
Overhead ist kein Randdetail: Instrumentierendes Profiling verfälscht viele kurze Aufrufe, Sampling nicht — und nur Letzteres lässt sich an einem Prozess in Produktion einsetzen.
Die Intuition liegt regelmäßig daneben. Im Beispiel dieses Kapitels stecken über 90 % der Laufzeit in einer Zeile, und zwar nicht wegen der Zufallszahl, sondern wegen der zweielementigen Liste, die bei jedem der 300.000 Aufrufe neu entsteht.
Kontrollfragen
Sie wollen wissen, welche Funktion die Zeit verbraucht, und danach, welche Zeile in dieser Funktion. Welche zwei Werkzeuge nehmen Sie in welcher Reihenfolge — und warum nicht gleich das zweite?
Ein Dienst in Produktion ist langsam; ein Neustart mit Profiler ist nicht möglich. Welches Werkzeug bleibt übrig, und welche zwei Eigenschaften machen es dafür geeignet?
Der Hotspot im Beispiel liegt in
random.choice([-1, 1]). Warum ist nicht die Zufallszahl das Problem, und an welcher Spalte derkernprof-Ausgabe lesen Sie das ab?
# Aufräumen
!rm -f scalene-profile.html scalene-profile.json simulation.bin simulation.prof simulation.py simulation_profiled.py simulation_profiled.py.lprof