Profiling async: el poll time, la contención y las herramientas

Perfilar código síncrono es, en esencia, cazar el punto caliente: dónde se va el porcentaje de CPU. En async esa pregunta sigue existiendo, pero deja de ser la principal, y confundirlas es el error que arruina el análisis. La métrica que gobierna el rendimiento async no es cuánta CPU consume una función, sino cuánto retiene el hilo trabajador antes de ceder: el poll time. Un poll que dura un milisegundo no solo cuesta ese milisegundo; se lo inyecta como latencia a todas las demás tareas que esperaban su turno en ese hilo. La salud de un sistema async no se mide por su uso de CPU —un servidor de E/S sano está casi siempre ocioso— sino por lo bien que sus tareas cooperan: poll cortos, cesión frecuente, ningún egoísta que acapare. A eso se suma un segundo enemigo silencioso, la contención de locks async, que serializa tareas sin gastar CPU visible. Perfilar async, por tanto, no es optimizar el cálculo: es proteger la cooperación, y para ello hay tres herramientas que se reparten planos distintos del problema.

El poll time es la latencia que repartes a los demás

Recupera la métrica reina de la lección de tokio-console. Cada vez que el executor sondea una tarea, esta corre hasta el siguiente .await y entonces cede. El tiempo de ese tramo es el poll time, y su importancia trasciende a la tarea que lo consume. Como un puñado de hilos trabajadores multiplexa miles de tareas de forma cooperativa, mientras un poll está en marcha ese hilo no puede atender a nadie más. Un poll de un milisegundo es un milisegundo de latencia añadido a la cola de todo lo que ese hilo tenía pendiente.

// Dos versiones que consumen la MISMA CPU total, pero se perfilan al reves.
async fn buena(items: &[Item]) {
    for item in items {
        procesar(item);              // trozo corto
        tokio::task::yield_now().await; // cede: poll time bajo, latencia repartida
    }
}

async fn mala(items: &[Item]) {
    for item in items {
        procesar(item);              // nunca cede: un unico poll larguisimo
    }                                // misma CPU, pero acapara el hilo de golpe
}

Aquí está la trampa que un perfilador de CPU clásico no ve: ambas funciones aparecen con idéntico consumo de CPU en un flamegraph, porque calculan lo mismo. Pero su efecto sobre la latencia del sistema es opuesto. La primera reparte su trabajo en poll cortos y deja respirar a las demás tareas; la segunda lo apelmaza en un poll monstruoso que las hace esperar. El porcentaje de CPU es ciego a esta diferencia; el poll time la mide con exactitud. Por eso tokio-console, y no un perfilador de CPU, es el primer instrumento que abres para un problema de latencia async.

La contención de locks async, el enemigo sin CPU

El segundo enemigo del rendimiento async no gasta CPU: la desperdicia en forma de espera. Si muchas tareas compiten por el mismo tokio::sync::Mutex, se serializan: por rápida que sea la sección crítica, solo una avanza a la vez y las demás hacen cola. El sistema parece ocioso —poca CPU, muchos hilos idle— y sin embargo la latencia se dispara, porque el cuello de botella no es el cálculo sino el turno.

La vista de recursos de tokio-console es donde esto se ve: cada Mutex o Semaphore muestra cuántas tareas esperan y cuánto llevan esperando. Una cola larga y persistente sobre un candado es la firma de la contención. Las curas son las del diseño concurrente, no las del microoptimizado:

Tres herramientas, tres planos del problema

No hay un perfilador único de async porque el problema tiene capas distintas, cada una con su instrumento. La destreza consiste en saber cuál abrir para qué pregunta.

samply merece una advertencia derivada de la primera lección del nivel: como muestrea las pilas del sistema operativo, verás los marcos de poll y del executor envolviendo tu código, y la pila lógica async aparecerá fragmentada por las suspensiones. Es perfecto para localizar un bucle de CPU concreto —el “dónde se quema”— pero no reconstruye el “quién llamó a quién” lógico; ese plano lo da tracing. Por eso las herramientas se complementan en vez de competir: usa una para cada pregunta.

# samply: perfila un binario y abre la interfaz de Firefox Profiler.
cargo build --release
samply record ./target/release/mi_servicio

flowchart TD
A[Latencia async alta] --> B[tokio-console busca poll time alto]
B --> C[Hay un poll largo]
C --> D[Es CPU pura dentro del poll]
C --> E[Es una llamada bloqueante]
C --> F[Es contencion de un lock]
D --> D2[samply localiza el punto caliente]
E --> E2[spawn_blocking saca el bloqueo del executor]
F --> F2[sharding RwLock o paso de mensajes]
B --> G[No hay poll largo pero hay cola]
G --> H[tracing mide que await domina la peticion]
style A fill:#f38ba8,color:#11111b
style B fill:#89b4fa,color:#11111b
style D2 fill:#fab387,color:#11111b
style H fill:#a6e3a1,color:#11111b

La metodología ata las tres: empieza siempre por tokio-console para encontrar el poll largo o la cola de un candado; si es un poll largo, decide con la naturaleza del código si es CPU —y entonces samply te da el punto caliente—, bloqueo —y entonces spawn_blocking— o contención —y entonces rediseñas el candado—; y usa tracing con tiempos para atribuir la latencia a la operación lógica cuando el problema no es un solo egoísta sino la suma de muchas esperas.