Cuando una función tarda “demasiado” y no sabes por qué, tienes dos caminos: adivinar o medir. El profiling es la herramienta que convierte esa intuición vaga en datos concretos: qué funciones se ejecutaron, cuántas veces, y cuánto tiempo consumieron en total y por llamada.
Python ofrece dos familias de herramientas para esto. cProfile es un profiler determinístico: intercepta cada llamada a función e instrumenta el tiempo. Captura todo, con una penalización de rendimiento pequeña pero real (~10-30%). py-spy es un profiler de muestreo: se adjunta a un proceso en ejecución, toma muestras periódicas del call stack sin modificar el intérprete, y construye una distribución estadística. No necesita tocar tu código ni reiniciar el proceso.
La distinción importa porque dicta cuándo usas cada uno. cProfile en desarrollo, donde puedes permitirte la instrumentación y quieres datos exactos. py-spy en producción, donde no puedes reiniciar el servicio, no quieres introducir overhead en una aplicación live, y muchas veces ni siquiera tienes acceso al código fuente del proceso.
Si usas cProfile para algo que ya está en producción, introduces overhead en un sistema bajo carga real. Si usas py-spy en desarrollo esperando conteos exactos de llamadas, te frustra que los números sean aproximados. La herramienta equivocada no solo da datos malos — puede degradar el sistema que intentas diagnosticar.
# profiling_demo.py
import cProfile
import pstats
import io
import time
import random
def sort_data(data: list[int]) -> list[int]:
return sorted(data)
def search_linear(data: list[int], target: int) -> int:
for i, v in enumerate(data):
if v == target:
return i
return -1
def process_chunk(size: int) -> dict:
data = [random.randint(0, size) for _ in range(size)]
sorted_data = sort_data(data)
target = random.choice(data)
idx = search_linear(sorted_data, target)
return {"size": size, "found_at": idx}
def run_pipeline(iterations: int = 50) -> None:
results = []
for _ in range(iterations):
chunk_size = random.randint(1_000, 5_000)
results.append(process_chunk(chunk_size))
return results
# ── 1. Profiling programático con cProfile ──────────────────────────────
def profile_with_cprofile() -> None:
profiler = cProfile.Profile()
profiler.enable()
run_pipeline()
profiler.disable()
# Volcamos las stats a un buffer en memoria para inspeccionarlas
stream = io.StringIO()
stats = pstats.Stats(profiler, stream=stream)
# cumulative: tiempo total acumulado en la función + sus llamadas
# útil para encontrar qué rama del call tree es la más costosa
stats.sort_stats("cumulative")
stats.print_stats(15) # top 15 funciones
print(stream.getvalue())
# ── 2. Guardar a disco para snakeviz ────────────────────────────────────
def save_profile_to_disk(output_path: str = "output.prof") -> None:
cProfile.run("run_pipeline()", filename=output_path)
print(f"Profile guardado en {output_path}")
print(f"Visualiza con: snakeviz {output_path}")
# ── 3. Análisis con pstats sobre archivo existente ──────────────────────
def analyze_from_file(path: str = "output.prof") -> None:
stats = pstats.Stats(path)
# strip_dirs() elimina rutas absolutas, hace la salida más legible
stats.strip_dirs()
print("=== Top 10 por tiempo acumulado ===")
stats.sort_stats("cumulative").print_stats(10)
print("\n=== Top 10 por tiempo propio (tottime) ===")
# tottime: tiempo en la función misma, sin contar llamadas a otras
# si tottime >> cumtime en una función, ahí vive el cuello de botella real
stats.sort_stats("tottime").print_stats(10)
if __name__ == "__main__":
print("--- Profiling en memoria ---")
profile_with_cprofile()
print("\n--- Guardando a disco ---")
save_profile_to_disk()
print("\n--- Análisis desde archivo ---")
analyze_from_file()
Desglose: qué decide cada herramienta
cProfile.Profile() como contexto manual te da control quirúrgico: puedes activar y desactivar el profiler alrededor de la sección exacta que te interesa. Si haces cProfile.run("run_pipeline()"), perfilas todo desde el arranque del script, incluyendo imports y setup — útil a veces, ruidoso otras.
La distinción entre cumulative y tottime es el hallazgo más valioso de pstats. tottime es el tiempo que la función gastó en sí misma; cumulative incluye todo lo que llamó. Una función con cumulative alto pero tottime bajo es solo un intermediario — no es el problema, sino la ruta hacia él. Una función con tottime alto es el problema.
pstats.strip_dirs() parece cosmético pero no lo es: cuando tienes múltiples versiones de un módulo o entornos virtuales, las rutas absolutas hacen que la misma función aparezca como entidades distintas en el reporte.
Para snakeviz, no necesitas cambiar nada en tu código:
pip install snakeviz python -m cProfile -o output.prof mi_script.py snakeviz output.prof
Abre un servidor local con un flamegraph interactivo donde puedes hacer clic en cualquier frame para ver su subárbol. Para scripts cortos con miles de llamadas, esto es mucho más rápido de leer que el output en texto.
py-spy opera en un paradigma completamente diferente. No modificas el código, no reinicias nada:
pip install py-spy # Ver top de funciones en tiempo real (como htop, pero para Python) py-spy top --pid 12345 # Grabar flamegraph de 30 segundos a SVG py-spy record -o profile.svg --duration 30 --pid 12345 # O adjuntarte mientras lanzas el proceso tú mismo py-spy record -o profile.svg -- python mi_script.py
El SVG resultante es un flamegraph interactivo: el eje X representa tiempo (o frecuencia de muestreo), la altura de cada frame su profundidad en el call stack. Los frames anchos en la base son los candidatos a optimizar.
En Linux, py-spy puede necesitar sudo o el capability SYS_PTRACE. En contenedores Docker, a veces necesitas --cap-add SYS_PTRACE en el docker run. Es el precio de adjuntarse a memoria de otro proceso sin su cooperación.
Errores que debes conocer
Error: Interpretar cumulative como el cuello de botella y optimizar la función intermedia en lugar del código que realmente consume CPU.
# ❌ Viendo esto en pstats y pensando que process_chunk() es el problema: # ncalls tottime cumtime function # 50 0.001 2.340 process_chunk # ✅ Revisar las llamadas DENTRO de process_chunk: # ncalls tottime cumtime function # 125000 1.890 1.890 search_linear ← aquí está el tiempo real
tottime alto en search_linear te dice que el algoritmo O(n) por cada elemento es el culpable, no el wrapper que lo llama.
Error: Usar cProfile sobre un proceso en producción con tráfico real, asumiendo que el overhead es despreciable.
# ❌ En un servidor Django/FastAPI en producción: profiler = cProfile.Profile() profiler.enable() # ... manejar requests reales ... profiler.disable() # ✅ Para producción, adjunta py-spy al proceso existente sin tocarlo: # py-spy record -o prod_profile.svg --pid $(pgrep -f gunicorn) --duration 60
cProfile serializa cada llamada a función con un lock global en el intérprete (el GIL). Bajo carga concurrente, esto puede incrementar la latencia de forma notable. py-spy lee la memoria del proceso sin interrumpirlo.
Error: Olvidar strip_dirs() al combinar stats de múltiples archivos con add().
# ❌ Las mismas funciones aparecen como entidades distintas por ruta:
stats = pstats.Stats("run1.prof", "run2.prof")
stats.sort_stats("cumulative").print_stats()
# ✅ Normalizar rutas antes de combinar:
stats = pstats.Stats("run1.prof", "run2.prof")
stats.strip_dirs() # colapsa duplicados con distinta ruta absoluta
stats.sort_stats("cumulative").print_stats()
Sin strip_dirs(), la misma función puede aparecer tres veces con tiempos fragmentados, haciéndote pensar que no es un problema cuando en realidad suma el tiempo dominante.
N° 164