Debugando Elixir descompilando bytecode BEAM
O Elixir faz um trabalho fantástico em cima da VM Erlang, aproveitando-se de características que geram sistemas de baixa latência, distribuídos e tolerantes a falhas.
Na SumUp fazemos uso extensivo de Elixir em nossos microsserviços e às vezes nos deparamos com alguns problemas, como em qualquer linguagem.
Quando testes de integração, métricas, debug hot-swap de código e todo o resto não fornece nenhuma pista, talvez seja a hora de adotar alguma outra abordagem.
O problema
O Oban é um framework para processamento robusto de jobs no Elixir e fazemos bastante uso dele.
Jobs no Oban podem falhar e quando isso ocorre, uma estratégia de desistência temporária (backoff) entra em cena. Por padrão, um job Oban implementa uma estratégia de backoff exponencial inicialmente fixada em 15 segundos com uma pequena margem. Caso se queira adotar uma estratégia própria, existe essa opção.
Certo dia fomos questionados a respeito do P99 dos tempos de conclusão para um determinado tipo de transação: estava totalmente fora do esperado.
Ao verificarmos o backoff do job responsável, absolutamente nada de útil foi revelado: estava configurado corretamente.
Pelo menos era o que achávamos.
Após um certo mergulho em logs e dados de transação, foi verificado que o backoff configurado não estava funcionando de maneira alguma. A boa notícia é que ele estava funcionando exatamente conforme o comportamento-padrão.
O código
Em Elixir é possível definir comportamentos (behaviours) para um módulo e esses comportamentos podem ser sobrescritos caso necessário. Esse é o caso para o backoff de um job do Oban.
Um comportamento de backoff no Oban é definido como:
E tem a seguinte implementação-padrão:
A definição de backoff() diz que deve existir uma função backoff() que recebe um Job e retorna um inteiro positivo.
Ao passo que a implementação-padrão apenas chama Worker.backoff(), que é o algoritmo-padrão exponencial de 15s.
Muito bem. Note a palavra-chave defoverridable bem no final do trecho de código acima: ela diz que os comportamentos (behaviours) do Worker podem ser sobrescritos conforme sua necessidade. Ou pelo menos esperávamos que fosse.
Dito isso podemos definir um módulo usando esse trecho de código e, sobrescrevendo conforme a necessidade, como:
Parece bom! Implementamos OurWorker usando Oban.Worker e sobrescrevendo a função backoff() para retentar a cada 10s.
Seria bom se funcionasse.
Por algum motivo, o comportamento de backoff ainda era o exponencial 15s.
Logs adicionados por meio de hot-swapping não revelaram absolutamente nada, chamar a função backoff() manualmente provou que a mesma funcionava. Então, o que poderia estar acontecendo?
Nesse ponto desistimos de formular hipóteses e partimos para explorar o código compilado a fim de obter alguma pista.
O debugging
Código-fonte Elixir é compilado para bytecode BEAM, que roda diretamente na VM Erlang.
O gol aqui era descobrir: por que a função backoff() não estava sendo sobrescrita como esperado?
Para responder a essa questão, um pequeno shell script foi executado em cima do arquivo BEAM gerado de OurWorker:
(Cortesia de: https://rocket-science.ru/hacking/2017/09/01/unveil_erlang_code_of_your_elixir_project)
O que acabou revelando que tínhamos duas funções backoff()!
Note que a primeira função backoff() chama exatamente Worker.backoff(), que é o comportamento-padrão de 15s.
Mistério resolvido!
Muita calma nessa hora.
Descobrimos o problema, mas resolvê-lo já era uma conversa completamente diferente.
A solução
Certamente a parte mais decepcionante deste artigo.
Uma vez descoberto o problema, a solução foi extremamente simples: apenas mover para cima no código a declaração use Oban.Worker:
Feito isso, descompilando novamente o código BEAM revelou (surpresa!) apenas uma função backoff() no bytecode gerado!
Conclusão
Descompilar código BEAM gerado a partir de Elixir não deveria ser uma tarefa parte do dia-a-dia de uma pessoa desenvolvedora. O código descompilado é bastante enigmático e difícil de ler e muitas vezes pode gerar até mais confusão.
De qualquer forma ele pode fornecer dicas valiosas, economizando muito tempo evitando deploys até que se encontre o problema.
Nesse caso específico, o mecanismo de use do Elixir é um tanto intrincado, fazendo uso de macros, o que pode ser confuso às vezes. Então, olhar pro código descompilado nos forneceu a compreensão imediata do que estava ocorrendo nas entranhas do código.
Tenha como uma ferramenta adicional no seu repertório como última alternativa e boas sessões de debugging!
Apêndice: o que causou o problema?
Falta de conhecimento necessário, provavelmente.
Esse é o processo de compilação, de acordo com o artigo de Saša Jurić:
(Fonte: https://www.theerlangelist.com/article/macros_1)
A cláusula use dispara uma expansão de macro, e o que não notamos foi que a declaração use OpenTelemetryDecorator colocada anteriormente causou a geração de uma função backoff() decorada. A função backoff() foi de fato sobrescrita, mas a função previamente decorada pelo OpenTelemetry tinha precedência maior.
Quer uma nova oportunidade de carreira com desafios globais? Confira nossas vagas em Engenharia e Produto e conheça mais sobre a SumUp.
