Dirigindo em Produção na neblina
O Teams toca, você atende e de repente você está em uma WarRoom do sistema crítico do seu Produto.
Você vai atrás dos logs da aplicação, na esperança de achar alguma resposta, e se depara com alguma coisa parecida com isso:
Application has just started at port 5000.
É como dirigir na neblina não é? Por isso hoje vou te dar algumas dicas, que não dependem de nenhuma tecnologia específica, de como se guiar através dessa densa falta de visibilidade das aplicações em produção.
Tudo junto e misturado
O primeiro desafio que vamos abordar é a dispersão dos logs quando trabalhamos com sistemas distribuídos, onde temos diversas instâncias (pods, VMs, serverless) da sua aplicação/rotina sendo executadas simultaneamante. Precisamos de acesso fácil ao log de todas as instâncias, e existem diversas ferramentas e stacks para auxiliar nesse processo de centralizar os logs, aqui no Pan recentemente passamos a utilizar o famoso ELK Elasticsearch + Logstash (atualmente Elastic Agent) e Kibana.
A depender da ferramenta poderá existir um formato preferencial, para o ELK o JSON funciona muito bem, permitindo buscas, agregações e visualizações.
O que sua aplicação te conta quando está em Produção?
Temos um lugar para salvar nossos logs, então surge a dúvida o que devemos logar (gravar)? Algumas dicas do que logar:
- Request e response das APIs com URL, body, headers, status code e tempo de resposta
- Request e response das integrações com URL, body, headers, status code e tempo de resposta
- Processamento assíncronos de mensageria ou jobs, é interessante logar entrada, duração, quantidade de trabalhado realizado, erros, etc.
Ao escrever mensagens de logs customizadas é importante que as mensagens de logs tenham contexto, assim como temos o famoso farol de milha ou farol de neblina para iluminar nosso caminho sem nos ofuscar:
Linha de log sem contexto
Consultar usuario no banco de dados
Linha de log com contexto
Consultar usuario 12345 na tabela tb_usuarios banco de dados db-usuarios
Outras informações úteis para suas linhas de log, especialmente em cenário de agregação de multiplas aplicações juntas:
- Identificação da instancia (pod-x1y2z3)
- Nome da aplicação (api-foo-bar)
- Timestamp (2023–04–04T23:00:21.197Z)
- Versão da aplicação (1.0.0)
- Erro com mensagem e origem (Connection refused at MyHttpIntegration.java)
Como não me perder no log?
Agora temos uma bela estrada com muitas faixas de log, de todo trabalho que nossa aplicação está fazendo, como se manter na pista certa? As faixas refletivas na pista te ajudam a não se desviar do caminho correto, como podemos ter faixas refletivas no nosso log?
Muito se fala de tracing com ferramentas como Jaeger e Zipkin, mas o trace-id utilizado por essas ferramentas pode ser muito útil no seu log :
2023-04-01 17:22:56.600 INFO [Service Foo,ef0fe81ff1f455ff,ef0fe81ff1f455ff] 14429 --- [nio-8081-exec-1] e.d.ApiFoo$FooRestController : Processando transacao 123xyz
2023-04-01 17:22:56.677 INFO [Service Foo,ef0fe81ff1f455ff,ef0fe81ff1f455ff] 14429 --- [nio-8081-exec-1] e.d.ApiFoo$FooRestController : Resposta BarService = Hello from /bar - 100ms 200 OK
2023-04-01 117:22:56.700 INFO [Service Bar,ef0fe81ff1f455ff,76b95441ff8d0300] 14466 --- [nio-8082-exec-1] e.d.ApiBar$SBarRestController : Processando transacao 123xyz
Se quiser ver um post falando mais sobre tracing e como aplicar isso na sua aplicação, comenta aqui embaixo “Como rastrear transações?” junto com a sua stack preferida 😉
Podemos facilmente relacionar as linhas que compõe as requisições e assim entender o caminho que ela percorreu.
Cuidado para não mostrar demais
Por último mas não menos importante, cuidado com informações sensíveis como dados de cliente, senhas, etc utilize mecanismos de ofuscação/substituição de valores para não ter problemas.
Seguindo essas dicas, hoje temos um log que parece um pouco com isso:
{"app-timestamp":"2023-01-27T13:07:17.174-03:00","app-instance":"pod-x1y2z3","app-service":"api--foo-bar","app-version":"1.0.0","app-severity":"INFO","app-trace":"c7da363c072eb216","app-span":"c7da363c072eb216","app-pid":"35498","app-thread":"main","app-class":"o.s.c.c.c.UsuarioRepository","app-msg":"Consultar usuario 12345 na tabela tb_usuarios banco de dados db-usuarios"}
{"app-timestamp":"2023-01-27T13:07:17.187-03:00","app-instance":"pod-x1y2z3","app-service":"api--foo-bar","app-version":"1.0.0","app-severity":"INFO","app-trace":"c7da363c072eb216","app-span":"c7da363c072eb216","app-pid":"35498","app-thread":"main","app-class":"o.s.c.c.c.UsuarioRepository","app-msg":"Usuário 12345 status: BLOQUEADO"}
A depender da ferramenta de agregação e visualização de log, que você estiver utilizando, é possível extrair métricas mas isso fica pra um próximo post.
Deu pra perceber que dirigir na neblina é mais fácil do que um incidente sem log né? Portanto avalie e planeje o log de suas aplicações, sempre se pergunte que informações faltaram no último incidente que você atendeu e complemente seu log.
Use logs e dissipe essa neblina.