Usai pierde el 81% de su rendimiento en un soak de 72 horas: era la aplicación

El runtime Usai (v0.0.15, aún en alpha) sirvió 73.627.701 peticiones en un soak de 72 horas sin registrar un solo 5xx ni un 503. Y aun así terminó la prueba con un 81% menos de throughput que al empezar. Una segunda ejecución de 24 horas, idéntica salvo porque el harness iba borrando los datos que generaba la carga, no mostró degradación ninguna. El problema no estaba en el runtime: estaba en una tabla de la aplicación que nadie podaba.

El montaje era un despliegue con forma de producción sobre una sola VM de 16 vCPU Xeon: Caddy delante de la imagen publicada del runtime, PostgreSQL 18 detrás y la aplicación de ejemplo examples/invoicing del repositorio. Ocho clientes en bucle cerrado repetían el mismo ciclo —listar facturas, traer una, crear otra—, y alrededor del 10% de las peticiones eran escrituras. Un muestreador tomaba memoria, CPU, descriptores abiertos y el estado del runtime cada minuto.

La línea que caía

Por los criterios de corrección fijados de antemano, el soak pasó. La mediana de latencia apenas se movió, de 4,6 a 5,3 ms. La cola lenta sí: el p99 pasó de 84 a 810 ms, y el throughput se despeñó de 794 peticiones por segundo en las primeras seis horas a 154 en las últimas.

Mientras eso pasaba, todo lo que el runtime posee se mantenía plano. CPU por petición dentro del mundo de la aplicación: de 1,56 a 1,59 ms. CPU de todo el proceso: de 2,80 a 3,04 ms. Operaciones SQL: de 2,52 a 2,59. Memoria cargada al contenedor: de 51,5 a 53,5 MiB. Descriptores abiertos: de 29 a 30. En tres días el runtime creó 73.627.744 mundos de ejecución, no detectó trabajo desligado, no puso en cuarentena ninguna conexión y no escribió una sola línea WARN ni ERROR.

Aquí es donde el asunto se pone interesante, porque había dos explicaciones y las dos encajaban. La primera: la carga escribió unos 7,4 millones de facturas con sus líneas en una tabla sin podar. Más filas es más índice, más WAL, más checkpoint y más autovacuum, así que el cliente espera más a PostgreSQL y cierra menos peticiones por segundo. Con CPU por petición plana, cuadra. La segunda: una fuga fuera de la CPU que se recorre una vez por petición dejaría exactamente la misma curva. Elegir la cómoda habría sido una conjetura disfrazada de hallazgo.

El control que zanjó la duda

Repitieron el soak 24 horas con el mismo despliegue, los mismos clientes y la misma carga. El único cambio: cada minuto se borraban las facturas más allá de las 20.000 más recientes. Si la culpa era del dato, la degradación desaparecería; si era del runtime, seguiría ahí. Desapareció: 1.416 peticiones por segundo en la primera hora y 1.480 en la última, cerca del doble que las horas iniciales del soak largo. Sobre 124.471.717 peticiones exitosas: cero 5xx, cero 503, cuatro 4xx, latencia media de 4,39 ms y memoria entre 53,2 y 55,2 MiB.

La ejecución de control tampoco fue perfecta y los autores lo publican: 344 timeouts repartidos en 91 segundos, ninguno generado por el servidor. Doce cayeron en la hora 1, cuando otro proceso del mismo host construía una imagen Docker. El resto, entre las horas 16 y 18, cuando otro trabajo bajó la cuota de CPU del contenedor de un 415% a un 65% durante unos minutos y los clientes en bucle cerrado llegaron a su propio timeout de 10 segundos. Fuera de esas dos ventanas, 22 horas y 114 millones de peticiones sin un solo segundo con errores.

Queda un detalle de instrumentación que merece la pena: a mitad de la prueba la página de estado del proceso marcaba 89 MiB y docker stats decía 53. Las dos eran correctas. Y conviene recordar el alcance: Usai es alpha, todo corrió en una máquina, y el propio autor deja claro que esto no dice nada sobre comportamiento bajo saturación, otros hosts u otras aplicaciones. Lo que sí enseña es una lección de método: cuando el throughput se cae y la CPU por petición no, quedan al menos dos historias posibles, y solo un control aísla cuál es.