- La memoria del Dyno
web de una app de Rails en producción de 10 años se disparó durante un despliegue, y como era un servicio con una carga sostenida de 400–500 req/s y picos de miles de req/s, hacía falta una mitigación rápida
- En Heroku se reiniciaron los Dynos cerca del límite de memoria y se revirtieron los cambios de código y métricas de los últimos 3 días, pero la fuga de memoria continuó
- Mientras Sidekiq y Delayed::Job se veían normales, apareció un patrón en el que solo crecían algunos workers de Puma, lo que hizo sospechar una relación con cierto tipo de tráfico
- Al rastrear el heap con
rbtrace, ObjectSpace, heapy, sheap y reap, se encontró que un thread de manejo de solicitudes de Puma retenía 32,067 objetos y 1.9GiB de memoria a través del arreglo @children de ActiveSupport::Notifications::Event
- Parámetros de consulta manipulados provocaban
URI::InvalidURIError durante el proceso de limpieza de URL de Bugsnag; la respuesta de corto plazo fue actualizar Bugsnag y la de largo plazo, actualizar Rails
Empezó una fuga en una app de Rails en operación
- El objetivo era una app de Rails de 10 años, un servicio en producción que generaba ingresos reales
- La carga sostenida habitual era de 400–500 req/s, y en los picos subía a miles de solicitudes por segundo
- Durante un flujo normal de despliegue empezó un pico de memoria y se activó una alerta del pager
- Como corría en Heroku, el estado se observaba con base en las métricas de memoria por Dyno
La mitigación del incidente empezó reiniciando Dynos
- El fenómeno no parecía simple hinchamiento de memoria (bloat), sino una fuga, y la solución temporal era reiniciar el proceso
- Aunque los despliegues diarios normalmente reiniciaban varias veces las instancias
web, los Dynos que se acercaban al límite de memoria se reiniciaron manualmente
La fuga seguía incluso al revertir cambios sospechosos
- Se auditaron los cambios de código de 3 días remontándose desde justo antes del primer gran pico
- Había tres cambios que parecían potencialmente relacionados
- Un cambio que causaba fuga de memoria en modo
development por la recarga de código de Rails
- Un cambio que hacía más llamadas a Redis de las previstas durante cierto filtrado de solicitudes
- Un cambio tipo N+1 que provocaba más llamadas a base de datos y carga de instancias de
ActiveRecord
- Se corrigieron los dos primeros cambios, se revirtió el tercero y se desplegaron uno por uno, pero la fuga continuó
- También se revirtieron cambios de herramientas para recolectar métricas del lenguaje Ruby y del uso del pool de Puma, pero el aumento de memoria no se detuvo
El patrón de la fuga apuntaba a un tráfico específico
- La fuga ocurría solo en los Dynos
web; los Dynos de Sidekiq y Delayed::Job se veían normales
- No todos los Dynos
web tenían fuga todo el tiempo
- Durante horas mostraban un uso de memoria relativamente estable, como procesos web de larga ejecución
- Luego, en algún momento, uno, algunos o todos los Dynos empezaban a fugar memoria
- Puma corría en modo clúster y cada Dyno usaba 12 procesos worker para 8 vCPU
- Incluso dentro de un Dyno, a veces solo algunos de los 12 workers consumían casi toda la memoria
- OpenTelemetry Traces tenía un muestreo muy agresivo, así que era difícil vincular tipos específicos de solicitudes con Dynos específicos, y tampoco era fácil correlacionarlo en la herramienta con logs no muestreados
Procedimiento para recolectar heap dumps
- Se usó
rbtrace para adjuntarse a un proceso Ruby en ejecución
- Como
rbtrace debe estar cargado en el proceso, se incluyó en el Gemfile y se controló su carga mediante una variable de entorno
gem "rbtrace", require: String(ENV.fetch("FEATURE_ENABLE_MEMORY_DUMPS", false)) == "true"
- En Heroku se abrió un túnel SSH al Dyno con fuga usando
heroku ps:exec, y con ps se ordenaron los procesos Ruby por RSS
ps -eo pid,ppid,comm,rss,vsz --sort -rss | grep ruby
- En un Dyno
web, los procesos con el mismo PPID eran workers de Puma, y se tomó como objetivo el PID del worker que más memoria usaba
- El rastreo de asignaciones de memoria se activó con
ObjectSpace.trace_object_allocations_start, lo que puede afectar rendimiento, memoria y CPU
DUMP_PID=<pid>
rbtrace --pid="${DUMP_PID}" --eval="Thread.new{require 'objspace';ObjectSpace.trace_object_allocations_start}.join"
- El heap dump se generó en
/tmp con ObjectSpace.dump_all, y en procesos con fuga que llevaban horas ejecutándose el archivo JSON crecía hasta 5–6GiB
rbtrace --pid="${DUMP_PID}" --eval="Thread.new{require 'objspace'; GC.start(); io=File.open('/tmp/heap-${DUMP_PID}.json', 'w'); ObjectSpace.dump_all(output: io); io.close}.join" --timeout=600
gzip "/tmp/heap-${DUMP_PID}.json"
- En Heroku, el dump se trajo a local con
heroku ps:copy, y para ver memoria retenida con heapy se recolectaron al menos unos tres dumps
- Después del trabajo, se desactivó el rastreo de asignaciones y se borraron los dumps o se reinició el Dyno
El análisis del heap reveló un Thread que retenía 1.9GiB
- Solo con el reporte de memoria retenida de
heapy y el diff de sheap era difícil encontrar el punto de inicio
- Se generó un flame graph con
reap, que analiza y visualiza el grafo de referencias de los heap dumps de Ruby
- El flame graph muestra, desde la raíz según el GC de Ruby, las referencias hacia los objetos inferiores, y cuanto más memoria retiene un objeto, más ancha aparece su celda
- En el tercer heap dump, un
Thread estaba reteniendo 1.9GiB de memoria
- En realidad, un
Array más abajo estaba referenciando 32,067 objetos y reteniendo 1.9GiB
Siguiendo la ruta de referencia con sheap
- Se compararon el segundo y el tercer dump usando la rama
main más reciente de sheap
- Como los dumps se acercaban a 6GiB, el parseo tomaba tiempo
- Según
find_path, el Thread problemático no era un thread en segundo plano de telemetría o métricas, sino un thread de Puma que procesaba solicitudes
ActiveSupport::SubscriberQueueRegistry funciona en Rails 6.1 como un Hash por thread que almacena listas de ActiveSupport::Subscriber por nombre de evento- Ese registry referenciaba un
Hash, y uno de los Array dentro de él retenía ActiveSupport::Notifications::Event
- Ese
Event, a su vez, referenciaba más de 32,067 objetos Event hijo a través del arreglo @children
- El nombre del primer
Event hijo era redirect_to.action_controller, y dentro incluía un objeto ActionDispatch::Request
Una solicitud anómala dio la pista para reproducirlo
- El
ActionDispatch::Request dentro del heap tenía una ruta real y un ID de recurso público válido, pero los parámetros de consulta estaban manipulados
- La ruta de la solicitud incluía
password=[FILTERED], lo que mostraba que había intervenido el proceso de saneamiento de información sensible
- Al solicitar en una ventana privada del navegador la app de producción con esa misma ruta y parámetros, se produjo un 500 server error
- En los logs quedó registrado
URI::InvalidURIError, y también se pudo identificar el Dyno que recibió la solicitud
- Ese Dyno mostraba un uso de memoria normal en ese momento, pero al pausar brevemente los despliegues y observarlo, apareció la tendencia de fuga
- En local, se reprodujo la misma situación y el backtrace añadiendo depuración con
binding.pry y puts en el gem activesupport
La causa real fue la combinación de cambios en Rails y Bugsnag
- El backtrace del error apuntaba al gem
uri de la biblioteca estándar de Ruby, que se usaba en Bugsnag.cleaner.clean_url de Bugsnag
- Ese código estaba dentro de un bloque de
ActiveSupport::Notifications.subscribe durante la limpieza de la URL del breadcrumb de Rails
- El problema fue la combinación de dos cosas
ActiveSupport::Subscriber de Rails 6.1 rastrea eventos con Event#children y un Array compartido- Un cambio en Bugsnag usaba
URI para limpiar la URL del breadcrumb de Rails, y podía lanzar una excepción con URIs inválidas
- Cuando
URI levantaba un error por una URI inválida, el bloque subscribe de Bugsnag lanzaba una excepción durante el procesamiento de ActiveSupport::Notifications::Event
- Por esa excepción, el
Event padre no se removía con pop de Subscriber#event_stack, y ese Event padre quedaba retenido, provocando la fuga de memoria
- El
Event padre seguía referenciando eventos hijo mediante el arreglo #children, reteniendo cada vez más memoria
- La corrección de Rails 7.1 de John Hawthorn eliminó tanto el concepto de
Event#children como el Array compartido para rastrear eventos, quitando así ambas causas de fuga
La solución fue actualizar Bugsnag y Rails
- En las versiones recientes de Rails, este problema ya no ocurre gracias a la corrección de John Hawthorn
- En ese momento la app seguía en Rails 6.1, así que no podía beneficiarse de inmediato de la corrección en Rails
- Bugsnag ya había corregido que
Bugsnag.cleaner.clean_url no lanzara excepciones con URIs inválidas
- La solución de corto plazo fue actualizar a una versión del gem Bugsnag que incluyera esa corrección
- La solución de largo plazo fue actualizar la versión de Rails
- El cambio que coincidió con el momento del primer pico de memoria fue la actualización de Bugsnag de
v6.26.0 a v6.26.1, cuyo objetivo era corregir una advertencia de deprecación en otra dependencia
1 comentarios
Opiniones de Hacker News
No entiendo por qué la gestión manual de memoria causa tanto miedo. Con RAII y reglas claras de propiedad, la gestión de memoria es una tarea de ingeniería sencilla.
De hecho, los frameworks que obligan a usar conteo de referencias o punteros compartidos me parecen más difíciles, porque la propiedad se vuelve difusa.
Si lo creaste tú, lo liberas tú; si lo transferiste, ya no te preocupas por eso. También gestionamos manualmente recursos del SO como handles y sockets sin un gestor automático de recursos, así que no veo por qué habría que complicar el diseño con gestión automática de memoria.
Tras años desarrollando, he llegado a pensar que la mayoría de los desarrolladores no tienen suficiente margen en la memoria de trabajo para razonar al mismo tiempo sobre la gestión de memoria. Aunque conozcas el método mecánicamente, si haces malabares con demasiadas cosas en la cabeza, algo se te escapa.
En cambio, también hay una minoría que casi siempre acierta con la gestión manual de memoria sin mucho esfuerzo. Para ellos realmente es fácil, así que no les resulta evidente por qué a otros les cuesta. Para esas personas, la gestión automática de memoria puede parecerles con beneficios poco claros y con desventajas muy grandes.
Dicho a grandes rasgos, esos bugs no fueron reemplazados por otros: simplemente desaparecieron. Tampoco exigen más trabajo al programador; al contrario, reducen lo que hay que hacer frente a la gestión manual de memoria.
Claro que la recolección de basura no gana siempre y tiene desventajas reales. Pero en la mayoría de los programas, los recolectores de basura modernos son lo bastante buenos como para que esas desventajas no sean un gran problema.
Los bugs lógicos tienen problemas parecidos, y en lenguajes como Java también pueden darse fugas de memoria ocasionalmente, pero los lenguajes con seguridad de memoria son una mejora. Es parecido a que TypeScript sea mejor que JavaScript. Si existe automatización capaz de reducir los errores de memoria de 1% a 0.01%, no entiendo por qué la prevención de fugas y comportamiento indefinido debería seguir siendo una preocupación manual.
Puedes usar un lenguaje con recolección de basura, fácil pero con overhead, como Java, o un lenguaje que impone propiedad, con curva de aprendizaje pero sin overhead, como Rust. Los bugs lógicos también son un dolor de cabeza, pero los bugs de memoria son especialmente famosos porque a veces no dan mensajes de error claros o incluso, aunque ocurran, el programa no se detiene.
Como nota al margen, la verificación formal también es una forma de eliminar en la práctica una clase de bugs. Hoy se ve sobre todo en sistemas donde la corrección es lo más importante, porque, a diferencia de la gestión de memoria, sus desventajas son demasiado grandes. El código se vuelve extremadamente verboso y exigente, e impone ciertas estructuras. Pero creo que, si la verificación formal mejora, también se volverá más mainstream.
“No soy un programador de verdad. Armo cosas para que parezcan funcionar y sigo adelante. Los programadores de verdad dirían: ‘Funciona, pero hay fugas de memoria por todos lados. ¿No deberíamos arreglarlo?’. Yo simplemente reiniciaría Apache cada 10 requests”. — Rasmus Lerdorf, PHP Non-Designer
https://en.wikiquote.org/wiki/Rasmus_Lerdorf
Un lugar donde trabajé antes habría merecido el premio a la forma más tonta de perder 5 millones de dólares por una fuga de memoria.
En los 90, el driver de impresora de Solaris tenía una fuga de memoria[1]. En esa época trabajaba como contratista para un banco grande, y por entonces el estatus legal de los faxes en confirmaciones de contratos no había sido suficientemente probado en tribunales, así que los bancos registraban las operaciones por fax. El sistema que enviaba los faxes también mandaba el documento a una impresora específica para imprimir la confirmación de la operación, y alguien tomaba esa confirmación y se la leía por teléfono a la contraparte, para que quedara en la grabación de la llamada[2] y así confirmarla legalmente.
Un día, por una fuga de memoria, el driver de impresora murió y una confirmación no se imprimió, así que la persona a cargo no pudo leerla por teléfono. El mercado se movió mucho y la contraparte trató esa operación como DK[3]. Por más escándalo que hicieran los ejecutivos del banco, no sirvió de nada: registramos la pérdida de 5 millones de dólares en los libros y luego se creó una política de no volver a operar con ese banco[4]. El trabajo de la impresora de faxes se migró a Windows NT.
[1] Según el excelente libro “Expert C Programming”, este problema lo sufría con frecuencia Scott McNealy, entonces CEO de Sun Microsystems, porque aunque era CEO le habían dado una workstation de bajo rendimiento; después de quejarse lo suficiente, los desarrolladores finalmente lo arreglaron https://progforperf.github.io/Expert_C_Programming.pdf
[2] Las llamadas del área de valores de los bancos casi siempre se graban por razones legales y de compliance.
[3] DK es abreviatura de “Don’t know”. Si la contraparte dice que “no conoce” la operación, está disputando que el contrato se haya celebrado.
[4] La contraparte podía operar en otro lado y pagar comisiones a otro banco, así que probablemente nosotros salimos perdiendo más.
Citi también enfrentó una demanda por pagar un préstamo demasiado pronto. En finanzas, creo que cualquiera se pondrá firme con un contrato escrito si eso le favorece.
En C, encontrar fugas es muy fácil gracias a Valgrind
Arreglarlas es más difícil, pero si el diseño es correcto, normalmente es sencillo. Por lo general, se asigna y se libera dentro de la misma función, salvo que sea una función que asigna memoria para el llamador. Si es una función que asigna para el llamador, entonces esa llamada en sí se considera una asignación del lado del llamador.
Al hacer análisis estático de la base de código, las rutas de manejo de errores resultaron ser la causa más común del problema.
Así como existen el alcance de bloque, de función, de archivo y global, también hay varios niveles de alcance en los modelos que abstraen el dominio del problema o la solución. Sin embargo, nunca he visto que esto se enseñe.
Cuando algún alcance adquiere un recurso en
$SCOPE::foo()y no lo libera en$SCOPE::cleanup(), suele ser bastante fácil detectarlo a simple vista. La capacidad de modelar el dominio del problema y la solución propuesta antes de ponerse a programar es útil.Me viene a la mente una historia que escuché sobre Yahoo. Su servidor de anuncios tenía una fuga de memoria y se quedaba sin memoria después de unas 10000 solicitudes
La solución fue reiniciar el servidor después de 8000 solicitudes. Ese método funcionó durante 1 o 2 años, pero luego empezó a quedarse sin memoria incluso después de 8000 solicitudes.
La siguiente solución fue reiniciar el servidor después de 6000 solicitudes.
Para que ese método funcionara, el reinicio tenía que ser increíblemente rápido.
Cuando era desarrollador de Rails, meterle más hardware a este tipo de problemas se consideraba un compromiso razonable en favor de la productividad. La mentalidad era que, si te importaban estos problemas, podías usar herramientas más estrictas
Personalmente, por mi tendencia perfeccionista, me cuesta aceptar ese enfoque, pero es difícil negar que en la práctica funciona.
He usado tanto lenguajes con recolección de basura como lenguajes sin ella. Por lo general, la gestión manual es más difícil de escribir, y la gestión automática es más difícil de depurar
Quisiera usar un lenguaje que permita ambas cosas. Al escribir código exploratorio, la gestión automática de memoria es cómoda, y para ciertos tipos de código la gestión manual de memoria resulta ventajosa.
Me frustra no encontrar un punto medio entre prohibir y obligar.
@[manualfree], y también en todo el proyecto conv -gc nonehttps://vlang.io
“Se ha escrito mucho sobre varias herramientas para perfilar fugas, entender volcados de heap y causas comunes de fugas”
Uf, fugas y volcados de heap. Parece que alguien necesita una dieta más saludable.