- A memória do Dyno
web de um app Rails em produção com 10 anos de vida disparou durante deploys, e como o serviço sustentava 400–500 req/s continuamente e processava milhares de req/s nos picos, era necessária uma mitigação rápida
- Na Heroku, reiniciaram Dynos próximos do limite de memória e reverteram mudanças recentes de código e métricas dos últimos 3 dias, mas o vazamento de memória continuou
- Enquanto Sidekiq e Delayed::Job estavam normais, apenas alguns workers do Puma cresciam, sugerindo relação com um tipo específico de tráfego
- Ao rastrear o heap com
rbtrace, ObjectSpace, heapy, sheap e reap, descobriram que uma thread de processamento de requisições do Puma mantinha 32.067 objetos e 1.9GiB de memória por meio do array @children de ActiveSupport::Notifications::Event
- Parâmetros de query manipulados causavam
URI::InvalidURIError durante a limpeza de URL do Bugsnag; a resposta de curto prazo foi atualizar o Bugsnag, e a de longo prazo, atualizar o Rails
Um vazamento começou em um app Rails em produção
- O alvo era um app Rails com 10 anos de vida, um serviço de produção que gerava receita de verdade
- A carga contínua normal era de 400–500 req/s, com picos que chegavam a milhares de requisições por segundo
- Durante um fluxo normal de deploy, começou um pico de memória, acionando alertas no pager
- Como rodava na Heroku, o estado era acompanhado com base nos números de memória por Dyno
A mitigação da falha começou com reinicialização de Dynos
- O comportamento não parecia simples inchaço de memória (bloat), mas sim um vazamento, e a solução temporária era reiniciar processos
- Em geral, vários deploys diários já reiniciavam as instâncias
web, mas os Dynos que se aproximavam do limite de memória eram reiniciados manualmente
Mesmo revertendo mudanças suspeitas, o vazamento continuava
- Fizeram uma auditoria retroativa das mudanças de código dos 3 dias anteriores a partir de pouco antes do primeiro grande pico
- Havia três mudanças com potencial relação
- uma mudança que causava vazamento em modo
development por causa do recarregamento de código do Rails
- uma mudança em que chamadas ao Redis durante a filtragem de certas requisições ficavam mais frequentes do que o pretendido
- uma mudança em estilo N+1 que gerava mais chamadas ao banco e carregamento de instâncias
ActiveRecord
- Corrigiram as duas primeiras, fizeram rollback da terceira e implantaram uma a uma, mas o vazamento persistiu
- Também reverteram mudanças em ferramentas para coletar métricas da linguagem Ruby e uso do pool do Puma, mas o crescimento de memória não parou
O padrão do vazamento apontava para um tráfego específico
- O vazamento ocorria apenas em Dynos
web; Dynos de Sidekiq e Delayed::Job pareciam normais
- Nem todos os Dynos
web vazavam o tempo todo
- por algumas horas, mostravam uso de memória relativamente estável, como processos web de longa duração
- depois, em algum momento, um, alguns ou todos os Dynos começavam a vazar
- O Puma rodava em modo cluster e cada Dyno usava 12 worker process para 8 vCPUs
- Mesmo dentro de um Dyno, às vezes só parte dos 12 workers consumia quase toda a memória
- Os traces do OpenTelemetry tinham amostragem pesada, dificultando ligar certos tipos de requisição a Dynos específicos, e correlacionar com logs sem amostragem também não era simples com as ferramentas disponíveis
Procedimento para coletar heap dumps
- Usaram
rbtrace para se conectar a um processo Ruby em execução
- Como o
rbtrace precisa estar carregado no processo, ele foi incluído no Gemfile, com o carregamento controlado por variável de ambiente
gem "rbtrace", require: String(ENV.fetch("FEATURE_ENABLE_MEMORY_DUMPS", false)) == "true"
- Na Heroku, abriram um túnel SSH para o Dyno com vazamento usando
heroku ps:exec e ordenaram os processos Ruby por RSS com ps
ps -eo pid,ppid,comm,rss,vsz --sort -rss | grep ruby
- Em Dynos
web, os processos com o mesmo PPID eram workers do Puma, e o PID do worker com maior uso de memória virava o alvo
- O rastreamento de alocação de memória foi ativado com
ObjectSpace.trace_object_allocations_start, o que pode afetar desempenho, memória e CPU
DUMP_PID=<pid>
rbtrace --pid="${DUMP_PID}" --eval="Thread.new{require 'objspace';ObjectSpace.trace_object_allocations_start}.join"
- O heap dump era gerado em
/tmp com ObjectSpace.dump_all, e em processos com vazamento rodando havia horas o arquivo JSON chegava a 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"
- Na Heroku, os dumps eram copiados localmente com
heroku ps:copy, e para ver retained memory no heapy era preciso coletar pelo menos uns três dumps
- Depois do trabalho, desativavam o rastreamento de alocação e apagavam os dumps ou reiniciavam o Dyno
A análise do heap revelou uma Thread segurando 1.9GiB
- Só o relatório de retained memory do
heapy e o diff do sheap não bastavam para encontrar o ponto de partida
- Geraram um flame graph com
reap, que analisa e visualiza o grafo de referências de heap dumps do Ruby
- O flame graph mostra, da perspectiva do root do GC do Ruby, as referências até os objetos mais abaixo; quanto mais memória um objeto retém, mais larga aparece sua célula
- No terceiro heap dump, uma
Thread segurava 1.9GiB de memória
- Na prática, era um
Array mais abaixo que referenciava 32.067 objetos e retinha 1.9GiB
Seguindo o caminho de referência com sheap
- Usaram a versão mais recente da branch
main do sheap para comparar o segundo e o terceiro dump
- Como os dumps chegavam perto de 6GiB, o parsing demorava
- Pelo resultado de
find_path, a Thread problemática não era uma thread de background de telemetria ou métricas, e sim uma Puma thread processando requisições
ActiveSupport::SubscriberQueueRegistry em Rails 6.1 funciona como um Hash por thread que guarda listas de ActiveSupport::Subscriber por nome de evento- Esse registry referenciava um
Hash, e um dos Array dentro dele estava segurando ActiveSupport::Notifications::Event
- Esse
Event, por sua vez, referenciava mais de 32.067 objetos Event filhos por meio do array @children
- O nome do primeiro
Event filho era redirect_to.action_controller, e dentro dele havia um objeto ActionDispatch::Request
A requisição anômala virou a pista para reprodução
- O
ActionDispatch::Request no heap tinha uma rota real e um ID válido de recurso público, mas os parâmetros de query estavam manipulados
- O caminho da requisição incluía
password=[FILTERED], mostrando que a limpeza de dados sensíveis havia entrado em ação
- Ao fazer a mesma requisição na app de produção em uma janela anônima do navegador, ocorreu um 500 server error
- Os logs registravam
URI::InvalidURIError, e também foi possível ver qual Dyno recebeu a requisição
- Esse Dyno, naquele momento, mostrava uso de memória normal, mas ao pausar os deploys por um tempo e observar, a tendência de vazamento apareceu
- Localmente, inseriram depuração com
binding.pry e puts na gem activesupport para reproduzir o mesmo cenário e o backtrace
A causa real era a combinação de mudanças em Rails e Bugsnag
- O backtrace do erro apontava para a gem
uri da biblioteca padrão do Ruby, usada em Bugsnag.cleaner.clean_url
- Esse código ficava no processo de limpeza da URL do breadcrumb do Rails dentro de um bloco de
ActiveSupport::Notifications.subscribe
- O problema era a combinação de dois fatores
- em Rails 6.1,
ActiveSupport::Subscriber rastreia eventos com Event#children e um Array compartilhado
- uma mudança no Bugsnag passou a usar
URI para limpar URLs de breadcrumbs do Rails, e isso podia gerar exceção com URI inválida
- Quando
URI levantava erro em uma URI inválida, o bloco subscribe do Bugsnag disparava uma exceção durante o processamento de ActiveSupport::Notifications::Event
- Por causa dessa exceção, o
Event pai não era removido com pop de Subscriber#event_stack, e o Event pai restante causava o vazamento de memória
- O
Event pai continuava referenciando Event filhos pelo array #children, retendo cada vez mais memória
- A correção no Rails 7.1 feita por John Hawthorn remove o conceito de
Event#children e o Array compartilhado para rastreamento de eventos, eliminando as duas causas do vazamento
A solução foi atualizar o Bugsnag e o Rails
- Nas versões mais recentes do Rails, esse problema não ocorre mais por causa da correção de John Hawthorn
- Na época, a app ainda estava em Rails 6.1, então não podia se beneficiar imediatamente da correção no Rails
- O Bugsnag já havia corrigido
Bugsnag.cleaner.clean_url para não levantar exceção com URI inválida
- A solução de curto prazo foi atualizar para uma versão da gem Bugsnag que incluísse essa correção
- A solução de longo prazo foi atualizar a versão do Rails
- A mudança que coincidiu com o primeiro pico de memória foi a atualização do Bugsnag de
v6.26.0 para v6.26.1, feita para corrigir um aviso de depreciação de outra dependência
1 comentários
Opiniões no Hacker News
Não entendo por que o gerenciamento manual de memória causa tanto medo. Com RAII e regras claras de propriedade, gerenciamento de memória é uma tarefa simples de engenharia.
Na verdade, frameworks que impõem contagem de referências ou ponteiros compartilhados parecem mais difíceis, porque a propriedade fica nebulosa.
Se você criou, você libera; se passou adiante, não se preocupa mais. Recursos do SO, como handles e sockets, também são gerenciados manualmente sem um gerenciador automático de recursos; então não vejo motivo para complicar o design com gerenciamento automático de memória.
Depois de anos desenvolvendo, passei a ver que a maioria dos desenvolvedores não tem folga suficiente na memória de trabalho para raciocinar simultaneamente também sobre gerenciamento de memória. Mesmo conhecendo o método de forma mecânica, quando se faz malabarismo com coisas demais na cabeça, algo acaba escapando.
Por outro lado, há uma minoria que acerta o gerenciamento manual de memória quase sem esforço, vez após vez. Para essas pessoas, isso é realmente fácil, então elas têm dificuldade de perceber por que é difícil para os outros. Para alguém assim, o gerenciamento automático de memória pode parecer ter benefícios pouco claros e apenas grandes desvantagens.
Em termos aproximados, esses bugs não foram substituídos por outros; eles simplesmente desapareceram. Isso também não exige mais trabalho do programador; pelo contrário, reduz o trabalho em comparação com o gerenciamento manual de memória.
Claro que garbage collection não vence sempre, e há desvantagens reais. Mas, para a maioria dos programas, coletores de lixo modernos são bons o suficiente para que essas desvantagens não importem muito.
Bugs de lógica têm problemas parecidos, e até em linguagens como Java vazamentos de memória podem ocorrer raramente, mas linguagens com segurança de memória são uma melhoria. É parecido com TypeScript ser melhor que JavaScript. Se existe automação capaz de reduzir erros de memória de 1% para 0,01%, não entendo por que a prevenção de vazamentos e comportamento indefinido deveria continuar sendo uma preocupação manual.
Você pode usar uma linguagem com garbage collection, fácil mas com overhead, como Java, ou uma linguagem que impõe propriedade sem overhead, mas com curva de aprendizado, como Rust. Bugs de lógica também dão dor de cabeça, mas bugs de memória são especialmente famosos porque às vezes não dão uma mensagem de erro clara, ou mesmo quando ocorrem o programa não para.
Como observação lateral, verificação formal também é uma forma de eliminar, na prática, uma classe de bugs. Hoje ela aparece principalmente em sistemas em que a corretude é o mais importante, porque, ao contrário do gerenciamento de memória, suas desvantagens são grandes demais. O código fica extremamente verboso e exigente, e impõe certas estruturas. Mas acredito que, se a verificação formal melhorar, isso também se tornará mais mainstream.
“Eu não sou um programador de verdade. Eu junto um monte de coisas até parecer que funciona e sigo em frente. Programadores de verdade diriam: ‘Funciona, mas está vazando memória por todo lado. Não deveríamos consertar isso?’ Eu simplesmente reiniciaria o Apache a cada 10 requisições.” — Rasmus Lerdorf, PHP Non-Designer
https://en.wikiquote.org/wiki/Rasmus_Lerdorf
Um lugar onde trabalhei antigamente merecia ganhar o prêmio de maneira mais idiota de perder 5 milhões de dólares por vazamento de memória.
Havia um vazamento de memória no driver de impressora do Solaris nos anos 90[1]. Na época, eu trabalhava como contratado para um grande banco e, naquele período, como o status legal do fax em confirmações de contrato ainda não tinha sido suficientemente testado nos tribunais, os bancos registravam as transações por fax. O sistema que enviava os faxes também enviava o documento para uma determinada impressora, imprimindo a confirmação da transação; então alguém pegava essa confirmação e a lia por telefone para a contraparte, para que ficasse registrada na gravação da chamada[2] e fosse confirmada legalmente.
Um dia, por causa do vazamento de memória, o driver da impressora morreu e uma confirmação não foi impressa, então o responsável não conseguiu lê-la por telefone. O mercado se moveu muito, e a contraparte tratou a transação como DK[3]. Por mais que os executivos do banco fizessem escândalo, não adiantou: registraram a perda de 5 milhões de dólares nos livros e criaram uma política de nunca mais negociar com aquele banco[4]. O trabalho de impressão de fax foi transferido para Windows NT.
[1] Segundo o excelente livro “Expert C Programming”, esse problema foi corrigido no fim porque Scott McNealy, então CEO da Sun Microsystems, apesar de ser CEO recebeu uma workstation de baixo desempenho, sofria com o problema com frequência e reclamou o suficiente para que os desenvolvedores finalmente o corrigissem https://progforperf.github.io/Expert_C_Programming.pdf
[2] Chamadas da área de securities de bancos quase sempre são gravadas por motivos jurídicos e de compliance.
[3] DK é abreviação de “Don’t know”. Quando a contraparte diz que “não conhece” a transação, ela está contestando o fato de que o contrato foi firmado.
[4] A contraparte poderia negociar em outro lugar e pagar comissão a outro banco, então provavelmente quem saiu perdendo mais fomos nós.
O Citi também enfrentou um processo por ter quitado um empréstimo cedo demais. No setor financeiro, acho que qualquer um vai se agarrar com força ao contrato escrito quando isso lhe for favorável.
Em C, encontrar vazamentos é muito fácil graças ao Valgrind
Corrigir é mais difícil, mas, se o design estiver certo, geralmente é fácil. Em geral, a menos que seja uma função que aloca para o chamador, você aloca e libera dentro da mesma função. Se for uma função que aloca para o chamador, então a própria chamada é considerada uma alocação do lado do chamador
Ao fazer análise estática da base de código, os caminhos de tratamento de erro eram a causa mais comum do problema
Assim como há escopo de bloco, escopo de função, escopo de arquivo e escopo global, também há vários níveis de escopo em modelos que abstraem o domínio do problema ou a solução. Só que nunca vi isso ser ensinado
Quando algum escopo adquire um recurso em
$SCOPE::foo()e não o libera em$SCOPE::cleanup(), é bem fácil encontrar visualmente. A capacidade de modelar o domínio do problema e a solução proposta antes de sair codando é útilIsso me lembra uma história que ouvi sobre o Yahoo. Havia um vazamento de memória no servidor de anúncios, e ele ficava sem memória depois de cerca de 10000 requisições
A solução foi reiniciar o servidor depois de 8000 requisições. Esse método funcionou por 1 ou 2 anos, mas depois ele começou a ficar sem memória mesmo após 8000 requisições
A solução seguinte foi reiniciar o servidor depois de 6000 requisições
Para esse método funcionar, a reinicialização teria que ser incrivelmente rápida
Quando eu era desenvolvedor Rails, jogar mais hardware nesse tipo de problema era visto como uma troca aceitável em nome da produtividade. O clima era: se você se importa com esse tipo de problema, use ferramentas mais rigorosas
Pessoalmente, por causa da minha tendência perfeccionista, tenho dificuldade em aceitar essa abordagem, mas é difícil negar que ela funciona na prática
Já usei tanto linguagens com coleta de lixo quanto sem. Em geral, gerenciamento manual é mais difícil de escrever, e gerenciamento automático é mais difícil de diagnosticar
Eu gostaria de usar uma linguagem que permitisse os dois. Ao escrever código exploratório, gerenciamento automático de memória é conveniente; para certos tipos de código, gerenciamento manual de memória é vantajoso
É frustrante não encontrar um meio-termo entre proibição e obrigação
@[manualfree], e também no projeto inteiro comv -gc nonehttps://vlang.io
“Muitos textos já foram escritos sobre várias ferramentas para perfilar vazamentos, entender heap dumps e causas comuns de vazamento”
Eca, vazamentos e heap dumps. Parece que alguém precisa de uma dieta mais saudável