Logs de Aplicações: Motivações e Melhores Práticas de Utilização

Introdução e objetivos

Este artigo trata o log do ponto de vista de depuração e acompanhamento do sistema no ambiente de desenvolvimento e produção e não de auditoria de sistemas.O objetivo principal da ferramenta de log e auxiliar no acompanhamento da execução do sistema com a finalidade de facilitar a busca de ocorrências de erros e na indicação de fatalidades.

Motivação para utilizar Log

A técnica de log consiste na geração de registros em uma saída(arquivo texto) para os desenvolvedores e analistas de suporte da aplicação obterem informações sobre um processamento importante ou a ocorrência de erro no ambiente de produção, o monitoramento do log torna essencial para o diagnóstico de um possível problema na aplicação.

Tentar descobrir um bug de uma aplicação em um ambiente de produção e como andar no escuro, não sabe onde se encontra e não sabe para onde ir.Apesar do sistema passar nos testes de homologação todas as possibilidades de testes não são esgotadas é possível que tenha algum bug na aplicação que esteja indo para o ambiente produção. Muitos problemas podem passar despercebidos ou não acontecer no ambiente desenvolvimento ou homologação, por isto o log é importante para verificar possíveis efeitos colaterais e fatalidades, na produção o código do sistema e colocado a prova e a todas as possibilidades são testadas, no caso da ocorrência de algum erro ou anormalidade do sistema, um log bem definido auxilia na contextualização do problema, registrando na saída de log, para uma posterior consulta, o estado e a localização do erro. Devemos colocar log na aplicação para ter informações necessárias e suficientes quando ocorrer um erro na aplicação, fazendo-se assim uma manutenção preventiva, fornecendo uma aplicação de qualidade para o usuário.

Os testes de unidade são valiosos para indicar o que pode estar acontecendo de errado com o sistema o que garante a qualidade e a confiança do código, mas não necessariamente onde o problema pode estar.O log fornece ao desenvolvedor contextos detalhados para falhas de aplicações deste modo, log e testes não devem ser confundidos, pois são complementares.

A técnica de log e mais eficaz e vantajosa em relação ao debug para diagnosticar problemas na aplicação, o debug foca em verificar o estado do programa em um dado instante, algumas vezes é necessário acompanhar o estado do programa e as estruturas de dados a todo momento com pequenas mensagens de diagnósticos como “Valor=” X , para verificar a ocorrência de um determinado problema o que leva o consumo de tempo excessivo para percorrer o código e encontrar a localização exata da ocorrência do erro e ainda depende de ferramentas específicas para debugar, e os 'breakpoints' não podem ser colocados no controle de versão para ser posteriormente localizado, para quando ocorrer um bug novamente.

Quando o log é utilizado com bom senso, ele se torna uma ferramenta essencial. Entretanto, quando usado sem critérios, ele se torna uma sobrecarga para aplicação com pouco valor agregado.

Arquitetura de um componente/lib de Log

Priority - Níveis de logging

Quando pensamos em um log, é possível compreendermos que ele possui informações de diferentes tipos (por exemplo, avisos de execução das rotinas, informações de depuração, indicação de erros críticos, etc). Estes tipos de informação podem ser encarados como níveis de logging. Estes níveis são decrescentes, ou seja, alterando-se o nível de logging para um nível mais baixo, ele irá conter as mesmas informações que estavam presentes anteriormente, adicionando-se as informações específicas que este nível grava.

Em geral as libs de log possuem os seguintes níveis:

• OFF: nenhuma mensagem é gravada;
• FATAL: erros fatais, os quais provavelmente abortaram a aplicação;
• ERROR: erros que permitam que as aplicações continuem sendo executadas;
• WARN: situações potencialmente prejudiciais;
• INFO: informações que descrevem as operações que o sistema está executando;
• DEBUG: informações de depuração;
• ALL: Qualquer informação sobre o sistema.

Destination - Local que o log vai ser enviado

O Destination é a parte de um sistema de log que é responsável por enviar as mensagens de log para algum destino ou meio. Ele responde à pergunta "onde você deseja armazenar essas coisas?"

O registro de log pode torna-se uma proposta mais complexa em ambientes distribuídos, você pode dividir em três preocupações principais:

• Gravação e formatação de mensagens. É aqui que você decide o que deve ir no log e como formatá-lo .
• Destination de log, a parte da operação que decide para onde as mensagens vão e como chegam lá.
• Análise de log. Isso pode variar de alguém simplesmente inspecionando os logs até pesquisa, inteligência e visualização sofisticadas .

Podemos ter diversos tipo de Destination de acordo com a necessidade :

Arquivo diários e contínuos: Inicia o registro em um novo arquivo, arquivando o antigo. Esse estilo destination é sofisticado o suficiente para permitir que você configure o que aciona os backups (tempo definido, determinado tamanho de arquivo, etc.) e se você compactar ou não os backups, entre outras coisas.

Console : Esse tipo de destination envia todas as saídas ao console para sua revisão à medida que você depura.

Banco de dados: Considerando que os logs são de fato, dados, armazenar os logs em um banco de dados é uma coisa perfeitamente razoável a se fazer. Esse tipo de destination envia todas as saídas para tabelas de banco de dados.

Assíncronos : destination assíncrono, que opera em um thread diferente de prioridade mais baixa e despacha mensagens para outros destination, como os de arquivo ou de banco de dados.

Email : Esse tipo de destination envia todas as saídas ao um e-mail para avisar que ocorreu o log.

Ferramenta e serviços que centralizam os logs: Esse tipo de destination envia todas as saídas para um sistema que consolida os logs para análise. Exemplos : Elastic Stack , Graylog , LOKI , DataDog Log.

É possível criar outros destination se a ferramenta de log permitir - como um destination para uma fila de mensagem assíncrona.

Dependendo da ferramenta de log é possível configurar diversos destinationpara um nível - Exemplo : Enviar as mensagens no nível ERROR para um destination que realiza a abertura de um ticket no sistema de_ *gestão de bugs *_e enviar um e-mail com a mensagem de log.

Layout - Formatação de mensagens

Layout é o conteúdo de uma entrada de log de um tipo de dados em outro. As estruturas de log fornecem Layouts Texto simples, HTML, XML, JSON, serializado e outros logs.

O padrão Layout json, gera entradas de log de texto semelhantes a esta:

{
  "level": "INFO,WARN,DEBUG,ERROR",
  "ts": "2022-03-18T11:02:59.201-0300",
  "app": "service-send-email",
  "version": "2.0.1",
  "logger": "main.subpackage",
  "caller": "utils/function_str.go:12",
  "msg": "sum:",
  "fator": "01",
  "fator": "02"
}

formato TXT:

2006-02-08 22:20:02,165 192.168.0.1 server_app  Protocol problem: connection reset

Requisitos para os componente/lib de log

• Ser capaz de alternar para outra biblioteca de log sem modificar o código do sistema.
• Sem dependência direta de qualquer biblioteca de log.
• Definir uma instância global do logger para todo o aplicativo, para poder alterar a configuração do log em um só lugar e aplicá-la a todo a aplicação.
• Poder alterar o comportamento de log facilmente sem modificar o código, por exemplo : nível de log alterar de INFO para DEBUG.
• Ser capaz de alterar o nível de log dinamicamente quando o sistema estiver em execução.

Práticas recomendadas

Um ponto a ser considerado é o trabalho de se adicionar instruções de log a um sistema. É muito mais fácil e barato o desenvolvedor adicionar as mensagens de log durante o desenvolvimento do sistema, neste momento, o programador tem muito mais conhecimento sobre o que o sistema realiza, e a tarefa portanto se torna mais natural. Entretanto, o trabalho necessário para se adicionar mensagens de log em uma aplicação pronta é muito maior, pois há o trabalho do desenvolvedor de compreender novamente a lógica do sistema e onde faria sentido colocar instruções de log. Desta maneira, fica justificada a decisão de se criar instruções de log no momento de desenvolvimento.

Abaixo segue um conjunto de práticas para auxiliar no uso da ferramenta de logging:

Prática 0 - Utilizar a definição de um wrapper para lib dos logs

Definir uma interface e um “wrapper”para as libs de log, motivações:

• Evitar o acoplamento das libs com os micro serviços;
• Flexibilizar a adoção de uma nova lib com a alteração apenas da sua configuração inicial;
• Alterar as definições de configuração sem a necessidade de recompilação;
• Alterar as definições de configuração e implementação apenas em um código fonte;

Rascunho da interface:

//Logger  common interface for logging

type Logger interface {

    Errorf(format string, args ...interface{})_

         Fatalf(format string, args ...interface{})_

    Infof(format string, args ...interface{})_

    Warnf(format string, args ...interface{})_

    Debugf(format string, args ...interface{})_

}

Factory para cada implementação:

    factory.NewLoggerZap(ConfigLog)

    factory.NewLoggerZerolog(ConfigLog)

//Variável global:
 var Log Logger
 Log =  factory.NewLoggerZap(ConfigLog)

//obter o log sempre por uma função 
log := Log.GetLogger(“canal do logger”)

log.Info(“Hello Log”) 

Prática 1 - Configurar o formato

A maioria das ferramentas/frameworks de análise de logs conseguem se ajustar a um padrão. Fica a critério de quem desenvolve escolher qual esse padrão. As vantagens é que você consegue classificar e limitar sua busca. Além de extrair informação de valor sobre o fluxo de sua aplicação em produção. E assim construir gráficos e poder fazer análises até do negócio! Os padrões mais comuns incluem: Horário, Nível do Log, Nome da thread, nome do logger e a mensagem. Definição do formato do log:

{
  "level": "INFO,WARN,DEBUG,ERROR",
  "ts": "2022-03-18T11:02:59.201-0300",
  "app": "service-send-email",
  "version": "2.0.1",
  "logger": "main.subpackage",
  "caller": "utils/function_str.go:12",
  "msg": "sum:",
  "fator": "01",
  "fator": "02"
}

level - INFO,WARN,DEBUG,ERROR

ts - TIMESTAMP RFC 339 -https://datatracker.ietf.org/doc/html/rfc3339

logger- canal do log - ex: "calc.fiscal" - tudo referente a cálculo e logado para este canal

caller - onde esta localizado o log no código fonte: exemplo app/utils/str.go:12

app - qual o código fonte está executando o log;. executando "app" : "send-email"

version - versão da app que foi criada para a produçao - https://semver.org/lang/pt-BR/

msg - mensagem enviada para o log

stacktrace - rastreamento de log - identificar a origem da falha.

parâmetros de logger - "pid" : "12345" , "valor_total" : "123.50" , "conta" : "00222"

Logger := _logger.Get(_"calc.fiscal")

 Logger.Info( "somatório geral" , Logger.String("pid" , string(os.Getpid())) , Logger.String("valor_total" , soma.ValorTotalStr() ) )

obs: O formato/layout vai ser definido de acordo com a ferramenta de análise de log.

Prática 2 - Configuração do ambiente produção

Em ambiente de produção, o log deve estar configurado para ser executado no nível acima de INFO. Com a finalidade de diminuir o I/O e como consequência o aumento do desempenho.

Utilizar o 'destination' de modo assíncrono para gerar os logs sem comprometer o desempenho da aplicação. Um lembrete importante e muitas vezes esquecido e que o log ocupa espaço, mesmo com alguns níveis desligado a quantidade de log fica grande depois de uma semana, solicite ao suporte ou equipe do SRE que verifique o tamanho dos logs diariamente e defina uma política de backup, para apagar os arquivos de log desnecessário depois de executado o backup. Exemplo de uma política e fazer backup do log gerados da semana passada e apagar após o backup os logs do servidor.

A equipe do SRE pode verificar a necessidade de alertar ao time da aplicação, pois certo texto padrão foi encontrado. Desta maneira, é necessário ter claro este funcionamento dos agentes de coleta de logs, para possibilitar uma integração mais fácil com os logs. Para isto ocorrer, sempre que forem criadas mensagens de log, será necessário:

▪ Verificar se esta mensagem contém alguma informação importante para análise. Caso afirmativo, deve ser verificado se a mensagem possui somente uma linha.

▪ Definir o formato do log, quais atributos e informações aparecerão nele. Esta definição é importante pois estas informações e atributos serão depois coletados pelos agentes, e serão a base para o envio de alertas.

▪ Definir em qual categoria/canal de log este evento se encontra. Por exemplo, podemos imaginar que certo log se refere a eventos de negócios, e por isso alertas relacionados a este log devem ser enviados ao time da aplicação. Podemos imaginar categorias como: bancos de dados, negócios, erros de lógica de aplicação, falha na comunicação com outros sistemas externos.

Prática 3 - Não utilize println no console para logar a aplicação

O println causa perda de performance e não podem ser configurados para inibir a saída para observar somente os logs que interessa.Em ambiente de produção os processos de I/O com logs desnecessários torna a performance da aplicação lenta.

Prática 4 - Utilize os níveis de LOG corretamente

O desenvolvedor de qualquer aplicação deve se preocupar em logar informações relevantes para observação . O desenvolvedor deve estar atento ao contexto de cada nível ( DEBUG , INFO , WARN , ERROR , FATAL ) , para não colocar mensagens em nÍveis incorretos.De imediato, é facil observamos que mensagens do tipo DEBUG ou ERROR são muito comuns e fáceis de serem identificadas.Pense cuidadosamente no nível de log que vai ser colocado, utilize as seguintes dicas :

FATAL: erros fatais, os quais provavelmente abortaram a continuidade do funcionamento da aplicação;

ERROR: erros que permitam que as aplicações continuem sendo executadas, mas prejudiciais para execução da operação, exemplo: acesso negado parâmetros incorretos;

WARN: situações potencialmente prejudiciais a corretude da execução, mas que não atrapalhe o andamento da execução, gerar dados para investigação;

INFO: informações que descrevem as operações que o sistema está executando, e que o administrador ou o desenvolvedor está interessando em saber, no ambiente de produção;

DEBUG: informações de depuração para verificar os dados e o fluxo de execução. Não deve ser logado no ambiente em produção.

No golang a maioria das lib de log finaliza o sistema ( os.Exit(1) ) .
Obs: Evitar utilizar Log.Fatal

Calls os.Exit(1) after logging

log.Fatal("Bye.")

Prática 5 - Log somente informações necessárias e precisas

Logs são streams e eventos sobre o ciclo de vida da sua aplicação. Tenha certeza de que eles contam uma história desse ciclo mostrando como sua aplicação está funcionando e como os erros podem estar acontecendo.

• Liste o fluxo da sua aplicação.
• Logue cada passo do seu fluxo (sempre no nível de log apropriado).
• Revise sempre suas mensagens de log e corrija aquilo que não traz valor ou informação de erro/negócio.

Procure logar mensagens informativas, para facilitar a depuração e a manutenção, no caso de ocorrer algum bug e não não colocar logs em excesso. Em “structs” de entidades, que não tenha nenhuma regra de negócio não deve ser colocado nenhum log. Deve -se criar um método ToString. Com isso, todas as chamadas de log poderão executar a função ToString para retornar uma string da informação(struct) .

As mensagens devem agregar valor. Elas devem permitir que quem está depurando consiga detectar o que gerou um determinado erro, em que momento e com quais entradas/saídas . Observação : verificar a prática de segurança - Prática 9 - Segurança.

Exemplo:

log.Error ( “Erro no banco de dados” ) // ERRADO 

log.Error(“[Conectar banco de dados] Ocorreu um erro na conexão com o usuário :%v , error : %v “ , user_db , error ) //CORRETO 

Prática 6 - Log a ocorrências das exceções

Quando você escolhe logar simplesmente a mensagem de uma exceção, provavelmente você terá informações de qual linha do código gerou essa exceção e de qual local do código aquele erro se originou. No entanto, será difícil saber quais dados geraram determinada exceção somente olhando a stacktrace.

Se você realmente precisa logar a stacktrace da sua exceção, tenha certeza que você deixou claro (e sucinto) no seu log as causas daquela exceção. Dessa forma, será mais fácil rastrear o erro e identificar qual informação pode ter sido perdida.

{
  "level": "error",
  "time": "2022-03-22T12:39:50.930-0300",
  "file": "logger/logconfig.go:114",
  "msg": "Let's do error instead.",
  "app": "cadastro usuario",
  "version": "v2.1",
  "stacktrace": "logger/logger.LogConfig\n\tlogger-go-poc/logger/logconfig.go:114\nmain.main\n\t/home/golang/logger-go-poc/calc.go:11\nruntime.main\n\t/usr/lib/go-1.13/src/runtime/proc.go:203"
}

Sempre logar os panics que ocorrer - Todos panics devem ser logados todos os seus detalhes. Tal registro deve ser feito no primeiro momento que a execução for capturada.Estas exceções devem ser gravadas no nível ERROR.

Sempre que uma exceção que não seja considerada ERROR for capturada, ela deve ser logada no modo WARN. Devem ser gravados o nome do arquivo, o nome do método, uma mensagem amigável, e a exceção que ocorreu.

Prática 7 - Use sempre a configuração

Não especificar o nível de log com programação, deixar para o arquivo de configuração do log, o ideal seria não utilizar nenhuma configuração de modo programático que necessite a recompilação do código para configurar as saídas, níveis e formatos do log. Na configuração do log podemos ter a flexibilidade de desligar determinados canais de log, o que não interessa durante a depuração.

Prática 8 – Log o processamento de rotinas executadas em 'batch'

Para o processamento de rotinas em modo 'batch' ( não executado com ação de usuários) , devem ser gravadas as informações de início e fim do processo, e com o nível de INFO. Para o processamento de cada registro no lote, devem ser gravadas informações que indicam que o processamento está sendo realizado e quando foi finalizado. ( rotina de cálculo de comissões sistemas de vendas para o envio para folha de pagamento).

Exemplo : Operação de acesso a bancos de dados deve ser logada o início e no fim da execução de métodos que atuam com a camada de persistência.Esta informação deve ser gravada no nível INFO, devem ser gravados o nome do arquivo, o nome do método e as strings completa da instrução SQL .

Prática 9 - Segurança

Não logar informações confidenciais para o arquivo de log como senha de usuários, valores de variáveis que sejam confidenciais, como valores financeiros com a identificação de quem pertence ou originou, lembretes de senhas junto com a identificação do usuário.

Prática 10 -Evitar efeitos colaterais

Logs não devem deixar sua aplicação mais lenta. Quando estiver montando seu log não faça consulta em bancos de dados e/ou chamadas a APIs ou sistemas externos. Isso pode tornar sua aplicação mais lenta.

logger.Errorf(“USER ID: %v”, repository.GetUser(session_id).GetID() )

Neste caso, todas as vezes que esse log é executado, uma consulta é feita a um banco. A depender da quantidade de vezes que esse fluxo é executado por seu banco, você pode tornar o sistema lento com a ocupação de recursos de rede e hardware.

Prática 11 -Não utilize panic

É comumente aceito que as libs não devem usar panic. Outro bug é o log.Fatal de algumas libs, que tem o mesmo efeito do panic, o que viola a regra de responsabilidade única.

Há dois problemas com o panic. Primeiro, é tratado de forma diferente do erro, mas na verdade é um erro, um subtipo de erro. Agora, o código de tratamento de erros precisa lidar tanto com erro quanto com pânico. Apenas o programa de controle principal de nível superior deve tomar a decisão sobre como lidar com um erro, todas as outras funções chamadas devem apenas propagar o erro para o nível superior.

Se você está chamando outra biblioteca e ela gera panic em seu código, para proteger seu código de parar, você precisa capturar o panic e se recuperar dele.

Prática 12 - Utilizar log na integração com sistemas externos

Quando estamos em produção e interagindo com aplicações e APIs externas, provavelmente será impossível ter acesso a esses logs de terceiros. Integrações em geral demandam um esforço considerável, então considere logar as informações que saem e voltam para seu sistema. Desse modo você conseguirá mapear se uma informação enviada a um sistema externo está voltando da maneira esperada.

O valor gerado aqui é que você conseguirá mapear quando e com quais dados alguma comunicação externa pode ter dado errado.

Prática 13 - Logar argumentos e valores de retorno das funções complexas

Quando um bug ocorre em produção, tudo que você terá serão os logs, pois muito provavelmente não será possível usar algo como um debugger e simular a situação de erro.

Assim sendo, sempre considere adicionar argumentos e retorno de métodos nos seus logs. Desse modo você consegue mapear quais entradas e quais saídas estão sendo geradas e entender onde tem um bug na sua solução.Tenha certeza de que você conseguirá identificar threads e trabalho paralelo. Utilize sempre identificadores para te ajudar a saber em qual fluxo você está.Considere usar esses logs num nível apropriado (Debug, por exemplo) para não deixar sua stream de logs muito “verbosa”.

Prática 14 - Analisar desempenho

Mecanismos de log são muitos custosos por depender de I/O, as práticas indicadas diz para colocar mensagens de log em todo lugar que o desenvolvedor considerar coerente, sempre respeitando seu nível adequado exibição, estas definições não são contraditórias , pois certas mensagens de log são gravadas somente se o nível atual de execução do log for menor ou igual ao nível definido para esta mensagem. Deste modo, o log terá uma alto custo quando esta mensagem for realmente gravada. Caso contrário o overhead é pequeno.

Caso for percebido e comprovado que uma aplicação não está correspondendo como desempenho esperado devido ao log, é necessário apenas configurar o log para ser desligado no arquivo de configuração.

Prática 15 -Analisar e realizar backup de logs

A geração de mensagens de erro deverá gerar um alarme para algum incidente que foi logado na aplicação.

Procedimentos:

• Analisar os logs quando for observado alguma inconsistência ou quando for relatado algum erro por usuários do sistema.

• Definir o descarte de logs periodicamente - definir por quanto tempo os logs deverão ser salvo - e o que deve ser salvo e descartado. Geralmente após um mês ou 15 dias o log costuma ficar irrelevante para ser armazenado.

• Quando ocorrer algum incidente os logs referente ao incidente devem ser catalogados e armazenados - após a resolução do incidente indicar no pós mortem onde se localiza os logs para uma posterior consulta sobre a ocorrência do incidente.

Ser avisado quando ocorrer alguma fatalidade do sistema no ambiente de produção.

Considerações Finais

O mecanismo de logging só compensa quando as mensagens gravadas realmente são utilizadas:

• Informações importantes para acompanhamento;
• Auxílio na identificação de problemas pelo administrador;
• Informações para rastreamento de ações, sejam elas de usuários ou de outra aplicação que utiliza o seu componente de serviço.

Gerar apenas o log não é importante, os arquivos ou saídas geradas devem ser observados e acompanhados para prevenir ou detectar a ocorrência de falha na aplicação.

O que pode ser boa prática para um determinado problema pode ser considerado como uma péssima prática para outro, os conjuntos de prática descritos servem como um guia e deve ser utilizado com bom senso.