Usando logs como ferramenta de visualização de comportamento.
Um dos tópicos centrais de quando trabalhamos com microserviço é a observabilidade. O desacoplamento e diversidade de aplicações quase que obrigatoriamente nos obrigam a centralizar os logs em alguma ferramenta.
É possível com poucos logs produzir gráficos que ajudam a inferir se o fluxo de uma aplicação está funcionando ou não.
Isso pode ser aplicado para maioria dos pipelines utilizando brokers de mensagens (rabbit/kafka), em que 1 mensagem deve ser processada sequencialmente por N microserviços e você quer saber por quais microserviços seu dado passou, por exemplo.
Analogia do ponto de ônibus
Imagine uma cidade que possui transporte coletivo de ônibus, vamos supor que a regra de negócio começou com algo parecido com isso:
- Uma linha de ônibus pode ser criada através de um
HTTP POST - A partir do momento que a linha é criada, ela é executada conforme a escala de horários
- Essa linha possui uma rota com vários pontos.
- O pagamento é feito no desembarque.
- Quando o ônibus chega no último ponto da rota sabemos que foi concluída.
É possível ao longo dos dias analisando fluxos assim em timeseries construir um conhecimento de como está executando e confrontar essa visão com o que o negócio realmente espera.
Além disso, passa a ficar mais fácil responder questões como
- Esse ônibus (
job) está rodando todo dia no mesmo horário? - Podemos ter ônibus duplicados?
- Como saber quais pontos uma pessoa passou?
Agora vamos assumir se seguintes ideias
- Cada ponto é um
microserviçoindependente - Essa mensagem (ônibus) sempre tem que chegar no final
- Cada “dinheiro” em cima do ônibus representa um dado do
payload/objeto(da mensagem) associado a rota do ônibus naquele dia - Pode ser que naquele dia não tinha pessoas nas ruas e o ônibus fez a rota vazio, a mensagem chegou no final do pipeline, mas seu
payloadera algo que representasse “nulo”. - Essas rotas podem ser flexíveis e aumentar de tamanho — i.e. mais
microserviçosadicionados ao longo do tempo
Conectando com o log timeseries
Partindo do princípio que rodamos um ambiente kubernetes e escolhemos o graylog como ferramenta centralizadora dos outputs dos nossos microserviços.
ℹ️ O Graylog é uma ferramenta que você pode instalar no seu ambiente para fazer toda a ingestão de logs em uma base centralizada e permitir a criação de consultas e dashboards dentro de uma interface web ou via api.
Vamos adicionar em todos os microserviços a seguinte linha de log no momento em que o pagamento é realizado.
logger.info(f“Pagamento realizado em: {nome_da_linha=} {nome_do_ponto=} {id_de_quem_pagou=}")
O pagamento aqui representa o checkpoint/marcador de saída de cada microserviço, como se o serviço dissesse: “peguei a mensagem e fiz tudo que precisava e to mandando pra frente”
Com esses logs sendo coletados podemos analisar em gráficos timeseries, no exemplo aqui vou utilizar agrafana para visualizar o graylog.
ℹ️ Grafana é uma ferramenta que permite a gestão de dashboards alimentados pelas mais diversas fontes. A interface dele é bem flexivel e permite adicionarmos parametros e customizarmos diferentes base de dados em um mesmo grafico.
A técnica dos marcadores
Podemos utilizar os logs da nossa aplicação exatamente como sensores.
Imagine que a ação de solicitar para o ônibus parar no próximo ponto seja um evento e esse evento é consumido pelo “processador de parada do ônibus” que executa sequencialmente as rotinas:
- Puxar a corda / Apertar o botão
- Realizar o pagamento
- Passar pela catraca
- Ônibus parar e abrir a porta
- Pisar na calçada
- Fechar a porta do ônibus
A técnica dos marcadores consiste em produzir um log de início e um de final. Visualizar esses logs com timeseries é o que permite inferirmos resultado baseado no comportamento e também responder perguntas do tipo:
- A mensagem chegou no
microserviçoe saiu com sucesso? - A mensagem chegou no
microserviço, porém ele teve problema para processar? - A mensagem nunca chegou no
microserviço?
Vamos supor que esse fluxo acima represente cada ponto de parada do ônibus do fluxo anterior.
Supondo que o marcador de saída foi aquele que colocamos la em cima e retrazendo aqui:
logger.info(f“Pagamento realizado em: {nome_da_linha=} {nome_do_ponto=} {id_de_quem_pagou=}")Nossa intenção aqui com a grafana é fazer uma conversão direta no timeseries de como os eventos acontecem e como eles são representados no gráfico através da contagem.
No exemplo aqui vamos fazer as seguintes considerações
- O log do onibus parar no ponto sempre é gerado
- Se não houve pagamento, então inferimos que ninguém desceu
- Na linha as pessoas entram no ponto inicial, depois disso ninguém mais entra só sai.
- Quando o
id_de_quem_pagouénuloninguém desceu.
Para responder isso no gráfico podemos fazer uma query de text-serch adicionado o argumento AND NOT message:"id_de_quem_pagou=None" para não fazer contagem quando não tiver o id, isto faz com que o gráfico acima fique com contagem 0 no ponto 1, inferindo que o evento não ocorreu.
pod_name:"bus-stop-ponto-X" message:"Pagamento realizado" AND NOT message:"id_de_quem_pagou=None" 
Log com filtros
No exemplo acima, como só temos 1 execução, é possível entender o ciclo completo, mas e quando nosso log é publicado em paralelo com os logs de outras linhas de ônibus?
Geralmente as ferramentas de dashboards para análises gráficas nos permitem criar uma variável para ser aplicado nos gráficos, com isso só adaptarmos a query como no exemplo abaixo adicionando o parâmetro do AND message:"$nomeDaLinha"
pod_name:"bus-stop-ponto-X" message:"Pagamento realizado" AND NOT message:"id_de_quem_pagou=None" AND message:"$nomeDaLinha"
Agrupamentos
Vamos fazer um exercicio aqui, imagine que estamos analisando uma linha de onibus e identificamos a seguinte visão no Ponto 2
E se tiver várias formas de pagamento? Para isso assumimos as seguintes características sobre aquela informação do id_de_quem_pagou que colocamos nos logs:
- O
id_de_quem_pagouno cartão sempre começa com 1 - O
id_de_quem_pagouno dinheiro é sempre nulo
Se quisermos entender quem pagou no dinheiro ou cartão através da linha de ônibus é possível combinarmos várias consultas distintas e agrupá-las no mesmo gráfico.
Com isso é possível chegar em graficos que permitam diferenciarmos os tipos de dados que estão passando, podemos entender cada linha de onibus como uma “transação”. Onde eventos acontecem a cada parada no ponto, que por sua vez são iterações diretas com os passageiros.
ℹ️ Os agrupamentos tem uma natureza muito dinamica e estão muito relacionado com o comportamento de cada aplicação/regra de negócio, a ideia aqui é transmitir as possibilidades que podem ser exploradas, lembrando que boa parte do assunto observabilidade é experimentação e observação ativa do time.
O que mais você precisa saber!
Sempre que possível tente trazer as análises para o time
Temos sempre uma oportunidade ótima de trazer conhecimento para o time trazendo análise de log como evidência de suas entregas, compartilhe as queries/links/dashs que você montou com ele e utilize os dados para explicar o porquê de algo ter ocorrido (bem ou mal)
É uma boa forma de fortalecer a cultura orientada a dados dentro dos times que atuamos.
Quantos dias de persistência de log?
Já tive experiências que 14 dias eram insuficientes porque o comportamento era semanal (uma determinada ação só acontecia uma vez por semana), então quando eu queria analisar uma amostra isolada eu só tinha 2 exemplos.
Porém, se o mesmo comportamento roda todo dia, lá é possível extrair algumas conclusões com poucos dias de persistência, 3~4 dias. Vai depender muito do comportamento de cada aplicação.
Logs como evidências para deploys que alteram apenas o comportamento.
Muitas vezes para validar um deploypodemos checar em alguma database, ou nós mesmos irmos lá e realizar a operação, porém isso fica um pouco mais complicado quando falamos de refatorações, integrações entre microserviços, questões de qualidade (canary, blue/green) onde nosso software apenas mudou o comportamento, porém não os seus dados.
Nesse cenário acima, as abordagens com logs são sempre muito bem-vindas.
Logs vs Métricas vs Traces
Os logs vão conseguir ajudar a responder algumas questões booleanas, contagens e alguns filtros bem específicos.
As métricas vão conseguir te dar operações matemáticas ao longo do tempo, em geral, as ferramentas sempre possibilitam aplicar função estatística com métricas tipo: min/max/avg/sum
Os traces vão permitir calcular o tempo que uma operação durou e também permitir correlacionar toda essa informação em contexto diferentes (para se aprofundar: distributed tracing)
Unicidade do log
Se tiver muitos logs duplicados, em libs ou até mesmo aplicações diferentes que possuem sentidos diferentes será muito difícil analisar os logs, pois vão ficar misturados.
Trabalhar com containers, kubernetes ajuda bastante já que as ferramentas mais modernas já integram boa parte dos metadados do container e muitas vezes é possível atingir ótimos filtros usando o nome do container ou deploy para montar uma visão.
Mesmo assim, se tudo estiver duplicado e rodando na mesma app, podemos inserir/criar tags específicas da nossa aplicação para trazer essas visões quando publicamos o log.
