BlogInfraestructura

Cada clic tumbaba todo

Pasamos un archivo de 130 MB a una base de datos de verdad y cada clic bajó de 5 segundos a 0.6 ms

Nicolás Biondi

Una mesa pequeña doblándose bajo una caja enorme y agrietada, junto a un cubo pequeño y ordenado de luz cian.

Descartar cuatro avisos seguidos en un tablero interno tumbaba la página con un 502 Bad Gateway, el error que sale cuando el servidor dejó de responder. Revisábamos la tanda del día, botábamos los tres primeros y en el cuarto nos quedábamos mirando el error hasta que el proceso volviera solo. Tres clics de trabajo y uno de contemplación.

El 502 llegaba al cuarto clic

El tablero junta avisos que salen cada día en fuentes públicas y alguien los mueve entre estados: pendiente, en curso, cerrado o descartado. De cada tanda, la mayoría no tiene nada que ver con cámaras ni con fotografía, así que descartar es la operación más frecuente del sistema y era justo la que lo mataba.

El primer sospechoso fue la red, porque un 502 suele oler a proxy. Pero este 502 aparecía siempre al tercer o cuarto clic, y el registro del gestor de procesos mostraba un reinicio por memoria cada vez.

Un cuaderno que se reescribía entero

Todo vivía en un solo archivo JSON de 130 MB con decenas de miles de avisos. Cambiar el estado de una tarjeta leía los 130 MB a memoria, convertía ese texto en objetos, modificaba un campo de un registro, volvía a convertir todo a texto y escribía el archivo completo otra vez. Eso corría síncrono, así que solo la reescritura del archivo dejaba a Node bloqueado entre 3 y 5 segundos, sin atender nada más. Era como volver a copiar a mano el cuaderno de ingresos del taller cada vez que tachas una línea, cuando lo que necesitábamos era el archivador de fichas: sacas una, la corriges, la devuelves.

El pico de memoria por escritura llegaba a unos 800 MB, porque durante un instante conviven el texto leído, los objetos en memoria y el texto nuevo. Ese pico pasaba el techo del gestor de procesos, que reiniciaba el servicio, y de ahí salía el 502 en pantalla.

Meme Gru's Plan: Todo en un JSON / Borrar con un clic / Copiar 130 MB por clic / Copiar 130 MB por clic Todo en un JSON Borrar con un clic Copiar 130 MB por clic Copiar 130 MB por clic

Clic en descartar

Leer 130 MB

Modificar 1 registro

Convertir todo a texto

Escribir 130 MB

Pico ~800 MB RAM

Proceso reiniciado

502 en pantalla

Antes: un clic en descartar reescribía el archivo completo y terminaba en 502

Ninguna optimización dentro del JSON servía

Podíamos convertir el texto más rápido, escribir por partes o mandar la escritura a un hilo aparte. Ninguna de las tres toca el problema, que está en el modelo de almacenamiento: para cambiar una línea había que reescribir todas las demás, y el archivo crece cada día con los avisos nuevos. Guardar todo en un archivo de texto fue mi idea y aguantó meses, que es la forma más cara de equivocarse.

Columnas para filtrar, una columna de datos para el resto

Migramos a SQLite las tablas que el tablero usa a cada rato, en modo WAL (write-ahead log, que deja leer mientras otro proceso escribe). El esquema es híbrido a propósito: unas pocas columnas indexadas para lo que el tablero filtra y ordena, y el objeto completo guardado como JSON en una columna de datos. Cada aviso quedó como una ficha propia y agregar un campo nuevo sigue costando casi nada.

El proceso que trae los datos nuevos y el que atiende el tablero abren el mismo archivo, cada uno con su conexión. La estrategia de concurrencia es WAL más un busy timeout de 5 segundos: si el archivo está ocupado, el otro proceso espera en vez de fallar. No pusimos un bloqueo en la aplicación porque a este volumen de escrituras no hace falta.

Los archivos chicos de configuración siguen en JSON plano: se escriben poco y conviene abrirlos a mano. No migramos nada que no tuviera un problema medido.

Las altas y actualizaciones en lote entran ahora en una sola transacción, y la tanda bajó de unos 10 s a cerca de 1 s. Un reproceso que vuelve a puntuar todos los avisos contra las reglas del filtro, 30 segundos pegados a la CPU, salió del arranque: corre solo cuando esas reglas cambian, no cada vez que el servicio levanta.

0.6 ms y diez borrados en 11 ms

Un cambio de estado completo, medido del clic a la respuesta, bajó de entre 4,000 y 6,000 ms a 0.6 ms. Diez borrados seguidos, que antes tumbaban el proceso, toman 11 ms en total. Nadie volvió a avisarme que la página estaba muerta.

Dos procesos escribiendo el mismo archivo funciona a este volumen. Si algún día un tercer proceso escribe seguido, el busy timeout va a aparecer en los registros y tocará repensar el reparto.

Mover decenas de miles de avisos en producción da miedo, así que ahora escribo el script de migración, el respaldo con fecha y el plan de rollback antes de tocar el almacenamiento. Y cuando algo está lento pregunto primero si está guardado de la forma equivocada. El cuarto clic hoy es igual de aburrido que los tres primeros.

sqlite json performance postmortem