Profiler du code Python

Mesurer d'abord, optimiser ensuite

Un backtest de quatre heures ou une fonction de valorisation appelée un million de fois par seconde donnent à chacun envie d'accélérer, et presque tout le monde se trompe sur l'endroit où passe le temps. La boucle qui paraît lourde peut ne rien coûter ; une ligne d'apparence innocente peut être toute l'exécution. Le profilage consiste à mesurer où un programme passe son temps, avant de rien changer. La règle est simple : n'optimisez pas une ligne que vous n'avez pas mesurée, et après un changement, mesurez de nouveau pour voir s'il a aidé.

# The simplest measurement: read a clock before and after
import time

def slow_sum(n):
    total = 0
    for i in range(n):
        total += i * i
    return total

start = time.perf_counter()
result = slow_sum(200_000)
elapsed = time.perf_counter() - start
print(result)                                        # 2666646666700000
print(elapsed > 0)                                   # True  a real duration; the exact value changes every run

Bruit, répétitions et minimum

Une seule mesure n'est pas fiable : le système d'exploitation, d'autres programmes, le cache du processeur et le démarrage de Python ajoutent du bruit, et ils ne font qu'ajouter du temps. Chronométrez donc une fonction plusieurs fois et prenez le minimum, l'exécution la moins perturbée ; timeit fait exactement cela. Utilisez time.perf_counter() (une horloge monotone haute résolution), pas time.time(). Mesurez avec des tailles d'entrée réalistes, car une fonction rapide sur dix lignes peut être lente sur dix millions, et échauffez d'abord pour que les coûts uniques (imports, caches) ne soient pas imputés au code mesuré.

# Repeat and take the minimum: the least disturbed run
import time

def work():
    return sum(i * i for i in range(50_000))

def best_of(func, repeats):
    best = None
    for _ in range(repeats):
        start = time.perf_counter()
        func()
        elapsed = time.perf_counter() - start
        if best is None or elapsed < best:
            best = elapsed
    return best

runs = [best_of(work, 1) for _ in range(5)]
print(best_of(work, 5) <= max(runs))                 # True  the minimum is never above the worst single run
print(min(runs) > 0)                                 # True

Où passe le temps : profileurs et loi d'Amdahl

Un chronomètre dit combien de temps, un profileur dit où. cProfile de la bibliothèque standard enregistre chaque appel de fonction et rapporte, pour chaque fonction, le nombre d'appels, le temps passé dans la fonction elle-même et le temps cumulé avec ce qu'elle appelle ; python -m cProfile -s cumtime script.py affiche les pires d'abord. La part de chaque fonction est alors simplement son temps sur le total. Le gain d'une correction est borné par la loi d'Amdahl : accélérer une fraction f de l'exécution d'un facteur s donne au total 1 / ((1 - f) + f / s). Rendre 60 % d'une exécution dix fois plus rapide ne donne que 2,2 fois au total, et même une moitié infiniment rapide plafonne le gain à 2. Attaquez d'abord le plus gros point chaud.

# Shares of the total and the payoff of fixing the biggest one (the timings are made-up numbers)
timings = {"load_prices": 6.0, "price_options": 3.0, "write_report": 1.0}
total = sum(timings.values())
for name, seconds in sorted(timings.items(), key=lambda item: -item[1]):
    print(f"{name:14s} {seconds / total:5.1%}")      # load_prices 60.0%, price_options 30.0%, write_report 10.0%

def amdahl_gain(fraction, speedup):
    return 1 / ((1 - fraction) + fraction / speedup)

print(round(amdahl_gain(0.6, 10), 2))                # 2.17  ten times faster on 60% of the run
print(round(amdahl_gain(0.1, 1000), 2))              # 1.11  a huge win on the smallest part barely helps

# cProfile records every call; the function that sleeps shows up as the hotspot
import cProfile
import time

def slow_part():
    time.sleep(0.02)

def fast_part():
    return sum(range(10))

def run_all():
    slow_part()
    for _ in range(100):
        fast_part()

profiler = cProfile.Profile()
profiler.runcall(run_all)
entries = {str(entry.code): entry for entry in profiler.getstats()}
slow = next(entry for name, entry in entries.items() if "slow_part" in name)
fast = next(entry for name, entry in entries.items() if "fast_part" in name)
print(fast.callcount, slow.callcount)                # 100 1   calls are counted exactly
print(slow.totaltime > fast.totaltime)               # True    one slow call outweighs 100 fast ones

• Mesurez avant de changer quoi que ce soit ; chronométrez avec perf_counter, répétez et gardez le minimum, avec des tailles d'entrée réalistes.
• Un profileur (cProfile) montre où passe le temps : appels, temps propre et temps cumulé par fonction ; chaque part est son temps sur le total.
• Loi d'Amdahl : accélérer une fraction f d'un facteur s donne 1 / ((1 - f) + f / s) ; corrigez d'abord le plus gros point chaud et remesurez après chaque changement.

À suivre : l'optimisation des boucles critiques, les changements qui accélèrent le code désigné par le profileur.

Lab : ce qui est noté

• Chronométrer un appel avec time_call25 pts
• Prendre le meilleur de plusieurs exécutions avec best_of25 pts
• Trouver où passe le temps avec hotspots25 pts
• Prévoir le gain avec amdahl_gain25 pts