Cada cinco a siete minutos, como un reloj, el reverse proxy de sh0 se congelaba. La API Admin de Caddy dejaba de responder. El monitor de salud detectaba el fallo, mataba el proceso, lo reiniciaba, re-aplicaba todas las rutas, y todo funcionaba de nuevo -- durante exactamente cinco a siete minutos. Luego se congelaba otra vez.
Los logs contaban una historia de auto-reparacion implacable:
ERROR sh0_proxy::manager: Caddy process is alive but admin API is unresponsive -- killing and restarting
INFO sh0_proxy::manager: Caddy restarted -- re-applying 12 routes
...
ERROR sh0_proxy::manager: Caddy process is alive but admin API is unresponsive -- killing and restarting
INFO sh0_proxy::manager: Caddy restarted -- re-applying 12 routesEl monitor de salud que habiamos construido (Articulo 5) estaba haciendo su trabajo admirablemente -- no hubo downtime visible para los usuarios. Pero el patron era desesperante. Caddy no se estaba cayendo. El proceso estaba vivo. Simplemente estaba... congelado. Cada vez.
Esta es la historia de un bug que ha existido desde los primeros dias de Unix, escondido a plena vista en nuestro moderno codebase Rust.
El sintoma
El fallo era perfectamente consistente:
- Proceso de Caddy vivo (PID presente, no zombie)
- API Admin sin respuesta (timeout HTTP en
localhost:2019) - Trafico HTTPS a todas las apps hospedadas congelado (Caddy maneja toda la terminacion TLS)
- Intervalo entre congelaciones: 5-7 minutos, variando ligeramente
- Despues de matar y reiniciar: recuperacion inmediata, rutas re-aplicadas en menos de un segundo
El intervalo variable fue la primera pista de que algo se estaba llenando. Un intervalo fijo sugeriria un temporizador o disparador tipo cron. Un intervalo que varia lentamente sugiere un buffer o cola alcanzando su capacidad, donde la tasa de llenado depende de la actividad.
La investigacion
Empezamos con los sospechosos obvios.
Memoria? No. El RSS de Caddy era estable en unos 30MB. Sin crecimiento entre reinicios.
Descriptores de archivo? No. lsof mostraba una cantidad normal de sockets y archivos abiertos.
Bug de Caddy? Improbable. Caddy es software probado en batalla sirviendo millones de sitios. Un bug que congela todo el proceso cada cinco minutos no sobreviviria un solo ciclo de release.
Nuestra configuracion? Inspeccionamos la configuracion JSON que enviabamos a Caddy. Valida. Limpia. La misma configuracion funcionaba perfectamente cuando se cargaba desde un archivo con caddy run --config caddy.json.
Esa ultima observacion fue el avance. El mismo binario de Caddy, con la misma configuracion, funcionaba bien cuando se ejecutaba de forma independiente pero se congelaba cuando se ejecutaba como proceso hijo de sh0. La diferencia era como lo creabamos.
Miramos el codigo de creacion en process.rs:
rustlet child = Command::new(&self.caddy_path)
.args(["run", "--config", "-"])
.stdin(Stdio::null())
.stdout(Stdio::null())
.stderr(Stdio::piped()) // <-- linea 53
.spawn()?;Tres flujos de I/O estandar. Stdin: null (Caddy no necesita entrada interactiva). Stdout: null (no necesitamos su salida estandar). Stderr: piped.
Piped. Hacia donde?
La causa raiz
La respuesta es: a ninguna parte. Habiamos conectado el stderr de Caddy a nuestro proceso pero nunca leiamos del pipe. Habiamos escrito .stderr(Stdio::piped()) con la intencion de capturar la salida de errores, pero nunca creamos una tarea para consumirla.
Esto es lo que sucede cuando conectas la salida de un proceso hijo y no la lees:
- El proceso hijo escribe en stderr (Caddy registra cada peticion, cada handshake TLS, cada actualizacion de ruta)
- Los datos van a un buffer de pipe del kernel
- En macOS, este buffer es de aproximadamente 16 KB (65 KB en Linux)
- Cuando el buffer esta lleno, la siguiente llamada
write()del hijo se bloquea - La escritura ocurre en el hilo principal de Caddy (o un hilo que mantiene un lock critico)
- Caddy ahora esta congelado -- no puede procesar peticiones HTTP, no puede responder a la API Admin, no puede hacer nada hasta que el buffer del pipe tenga espacio
Esto no es un bug de Caddy. No es un bug de Rust. Es una propiedad fundamental de los pipes Unix que ha existido desde los anos 70. Un pipe es un buffer de tamano fijo. Cuando esta lleno, el escritor se bloquea hasta que el lector consume datos. Si no hay lector, el escritor se bloquea para siempre.
El intervalo de 5-7 minutos se mapea perfectamente al tiempo necesario para que la salida de log de Caddy llene 16 KB. Con trafico moderado (una docena de apps hospedadas, health checks periodicos, renovaciones TLS), Caddy produce unos cientos de bytes de salida de log por segundo. A esa tasa, 16.384 bytes se llenan en aproximadamente 5-7 minutos.
Por que no Stdio::null()?
La pregunta natural: por que conectamos stderr en primer lugar en vez de enviarlo a null como stdout?
Porque queriamos la salida de errores de Caddy para depuracion. Cuando Caddy falla al vincular un puerto, rechaza una configuracion o encuentra un error TLS, esa informacion aparece en stderr. Descartarla con Stdio::null() haria que depurar problemas del proxy fuera casi imposible.
El error no fue conectar stderr. El error fue conectarlo sin leerlo.
La correccion
La correccion son cinco lineas de codigo, anadidas inmediatamente despues de crear el proceso hijo:
rust// Drenar stderr en una tarea en segundo plano para prevenir el deadlock del buffer de pipe
if let Some(stderr) = child.stderr.take() {
let reader = tokio::io::BufReader::new(stderr);
let mut lines = reader.lines();
tokio::spawn(async move {
while let Ok(Some(line)) = lines.next_line().await {
tracing::debug!(target: "caddy", "{}", line);
}
});
}Una tarea tokio en segundo plano lee stderr linea por linea y reenviar cada linea al logger de tracing a nivel debug. El buffer del pipe nunca se llena porque se drena continuamente. La salida de log de Caddy se preserva (visible al ejecutar con RUST_LOG=caddy=debug) pero no obstruye el pipe.
Tambien bajamos el nivel del mensaje de reinicio del monitor de salud de error! a warn!:
rust// Antes
tracing::error!("Caddy process is alive but admin API is unresponsive -- killing and restarting");
// Despues
tracing::warn!("Caddy process is alive but admin API is unresponsive -- killing and restarting");El reinicio es comportamiento de auto-reparacion, no un fallo critico. El nivel warn es apropiado: algo inesperado ocurrio, pero el sistema lo manejo automaticamente.
Confirmando la correccion
Despues de desplegar la correccion, dejamos el servidor funcionar por mas de 15 minutos. Luego una hora. Luego toda la noche. El ciclo de reinicios habia desaparecido. Caddy se ejecuto continuamente, la API Admin permanecio responsiva, y el monitor de salud no reporto nada mas que verificaciones limpias.
La logica de reinicio que habiamos construido en el Articulo 5 permanecio en su lugar como red de seguridad. Simplemente dejo de activarse. Un sistema que se reiniciaba cada cinco minutos ahora se ejecutaba indefinidamente sin intervencion.
Un bug clasico en un codebase moderno
Este bug esta documentado en cada libro de texto de programacion Unix. La especificacion POSIX para pipe(2) declara explicitamente que las escrituras a un pipe lleno se bloquearan. La documentacion de Python advierte sobre ello. La documentacion de std::process de Rust lo menciona. Y aun asi nos atrapo, a dos constructores experimentados (uno humano, uno IA), porque el sintoma -- un servidor HTTP sin respuesta -- no se parecia en nada a su causa -- un buffer de pipe lleno.
La indireccion es lo que hace este bug insidioso. La causa (un buffer de 16 KB lleno en un pipe del kernel) y el efecto (la API Admin de Caddy no respondiendo a peticiones HTTP) estan separados por multiples capas de abstraccion. Tienes que razonar a traves de la cadena: pipe lleno lleva a una escritura bloqueada, que lleva a un hilo bloqueado, que lleva a un proceso en deadlock, que lleva a endpoints HTTP sin respuesta.
Varios factores hicieron este bug particularmente dificil de diagnosticar:
El proceso no estaba muerto. El monitoreo tradicional de procesos (esta vivo el PID? es zombie?) reportaba todo como saludable. El proceso estaba vivo, simplemente no podia avanzar.
El intervalo era variable. Si hubiera sido exactamente 5 minutos cada vez, podriamos haber buscado un temporizador. La variacion de 5-7 minutos apuntaba hacia un disparador dependiente de la capacidad, pero inicialmente buscamos en las caches internas de Caddy en lugar del buffer de pipe a nivel de SO.
La solucion temporal enmascaraba la causa. Nuestro monitor de salud (matar, reiniciar, re-aplicar rutas) mantenia la plataforma funcionando. La urgencia por encontrar la causa raiz era menor porque los usuarios no se veian afectados. Esta es la espada de doble filo de la infraestructura auto-reparable: te compra tiempo, pero tambien te deja vivir con bugs mas tiempo del que deberias.
macOS versus Linux. En Linux, el buffer de pipe por defecto es de 65 KB, por lo que el mismo bug se manifestaria con un intervalo mas largo -- quizas 20-30 minutos. Estabamos desarrollando en macOS donde el buffer de 16 KB hacia el ciclo mas rapido y notable. Si hubieramos estado en Linux, esto podria haber sido confundido con un problema intermitente de red.
Reglas para la gestion de procesos hijo
Esta experiencia cristalizo tres reglas que ahora seguimos para cada proceso hijo en sh0:
Regla 1: Cada flujo conectado debe tener un lector. Si conectas stdout o stderr, crea una tarea para consumirlo. Siempre. Incluso si piensas que el proceso hijo no producira mucha salida. "No mucho" eventualmente se convierte en "suficiente para llenar el buffer".
Regla 2: Preferir drenaje asincrono sobre lecturas sincronas. Un read() bloqueante en un runtime tokio puede dejar sin recursos al ejecutor. Usa tokio::io::BufReader y lines() para integrar el I/O del proceso hijo con el runtime asincrono.
Regla 3: Registrar la salida del proceso hijo, no descartarla. Enviar stderr a Stdio::null() previene el deadlock pero destruye informacion de diagnostico. Drenar a un logger a nivel debug te da ambos: sin deadlock, y la capacidad de ver la salida cuando la necesites.
La leccion mas amplia
El bug de 16 KB es un recordatorio de que la programacion de sistemas esta llena de contratos implicitos. Un pipe Unix tiene un contrato: el lector debe mantener el ritmo del escritor, o el escritor se bloqueara. Este contrato es invisible en la API -- .stderr(Stdio::piped()) compila y se ejecuta sin queja. La violacion solo se manifiesta bajo carga, despues de minutos de salida acumulada, en un sintoma que parece completamente no relacionado con la causa.
Cada capa de abstraccion que usamos -- runtimes asincronos, servidores HTTP, gestores de procesos, runtimes de contenedores -- tiene contratos como estos. Los bugs mas peligrosos no son los que hacen que tu programa se caiga. Son los que hacen que deje de avanzar mientras parece perfectamente saludable desde afuera.
Lo que viene despues
Con el deadlock de pipe corregido y Caddy funcionando establemente, dirigimos nuestra atencion al otro lado de la ecuacion del proxy: los certificados SSL. El siguiente articulo cubre como sh0 maneja HTTPS automatico via ACME, soporta subidas de certificados personalizados para despliegues empresariales, y cifra las claves privadas en reposo con AES-256-GCM.
Esta es la Parte 7 de la serie "Como construimos sh0.dev". sh0 es una plataforma PaaS construida enteramente por un CEO en Abidjan y un CTO de IA, sin ningun ingeniero humano.