Níveis de log - Logback - regra prática para atribuir níveis de log

Estou usando o logback no meu projeto atual.

Ele oferece seis níveis de registro: TRACE DEBUG INFO WARN ERROR OFF

Estou procurando uma regra prática para determinar o nível de log para atividades comuns. Por exemplo, se um encadeamento estiver bloqueado, a mensagem de log deve ser configurada no nível de depuração ou no nível de informações. Ou, se um soquete estiver sendo usado, seu ID específico deve ser registrado no nível de depuração ou no nível de rastreamento.

Aprecio respostas com mais exemplos para cada nível de registro.

Na maioria das vezes, construo sistemas do tipo em larga escala e alta disponibilidade; portanto, minha resposta é tendenciosa para analisá-lo do ponto de vista do suporte à produção; Dito isto, atribuímos aproximadamente o seguinte:

• erro : o sistema está em perigo, os clientes provavelmente estão sendo afetados (ou em breve estarão) e a correção provavelmente requer intervenção humana. A "regra 02:00" se aplica aqui - se você estiver de plantão, deseja ser acordado às 02:00 se essa condição ocorrer? Se sim, registre-o como "erro".

• aviso : ocorreu um evento técnico ou comercial inesperado, os clientes podem ser afetados, mas provavelmente nenhuma intervenção humana imediata é necessária. As pessoas que estão de plantão não serão chamadas imediatamente, mas a equipe de suporte desejará revisar essas questões o mais rápido possível para entender qual é o impacto. Basicamente, qualquer problema que precise ser rastreado, mas pode não exigir intervenção imediata.

• info : coisas que queremos ver em alto volume, caso seja necessário analisar forense um problema. Os eventos do ciclo de vida do sistema (início do sistema, parada) estão aqui. Os eventos do ciclo de vida da "Sessão" (login, logout etc.) estão aqui. Eventos de fronteira significativos também devem ser considerados (por exemplo, chamadas ao banco de dados, chamadas remotas à API). As exceções comerciais típicas podem ser encontradas aqui (por exemplo, falha no login devido a credenciais incorretas). Qualquer outro evento que você ache que precisará ver em produção em alto volume vai aqui.

• debug : praticamente tudo o que não faz com que as "informações" sejam cortadas ... qualquer mensagem que seja útil para rastrear o fluxo no sistema e isolar problemas, especialmente durante as fases de desenvolvimento e controle de qualidade. Usamos logs de nível de "depuração" para entrada / saída da maioria dos métodos não triviais e marcação de eventos interessantes e pontos de decisão nos métodos.

• trace : não usamos isso com frequência, mas isso seria para logs de volume extremamente detalhados e potencialmente altos que você normalmente não deseja ativar, mesmo durante o desenvolvimento normal. Os exemplos incluem despejar uma hierarquia de objetos completa, registrar algum estado durante cada iteração de um loop grande, etc.

Tão ou mais importante do que escolher os níveis de log corretos é garantir que os logs sejam significativos e tenham o contexto necessário. Por exemplo, você quase sempre deseja incluir o ID do encadeamento nos logs para poder seguir um único encadeamento, se necessário. Você também pode empregar um mecanismo para associar informações da empresa (por exemplo, ID do usuário) ao encadeamento para que ele também seja registrado. Na sua mensagem de log, você deverá incluir informações suficientes para garantir que a mensagem possa ser acionada. Um log como "exceção FileNotFound detectada" não é muito útil. Uma mensagem melhor é "Exceção FileNotFound capturada ao tentar abrir o arquivo de configuração: /usr/local/app/somefile.txt. UserId = 12344."

Há também vários bons guias de registro por aí ... por exemplo, aqui está um trecho editado da JCL (Jakarta Commons Logging) :

• error - Outros erros de tempo de execução ou condições inesperadas. Espere que eles fiquem visíveis imediatamente em um console de status.
• aviso - Uso de APIs obsoletas, uso inadequado da API, 'quase' erros, outras situações de tempo de execução indesejáveis ​​ou inesperadas, mas não necessariamente "erradas". Espere que eles fiquem visíveis imediatamente em um console de status.
• info - Eventos de tempo de execução interessantes (inicialização / desligamento). Espere que eles sejam imediatamente visíveis em um console, portanto, seja conservador e mantenha-o no mínimo.
• debug - informações detalhadas sobre o fluxo através do sistema. Espere que eles sejam gravados apenas em logs.
• trace - informações mais detalhadas. Espere que eles sejam gravados apenas em logs.

Minha abordagem, acho que vem mais do desenvolvimento do que do ponto de vista das operações, é:

• Erro significa que a execução de alguma tarefa não pôde ser concluída; um email não pôde ser enviado, uma página não pôde ser renderizada, alguns dados não puderam ser armazenados em um banco de dados, algo assim. Algo deu definitivamente errado.
• Aviso significa que algo inesperado aconteceu, mas que a execução pode continuar, talvez em um modo degradado; estava faltando um arquivo de configuração, mas os padrões foram usados, o preço foi calculado como negativo, então foi fixado em zero etc. um erro muito em breve.
• Info significa que algo normal, mas significativo, aconteceu; o sistema foi iniciado, o sistema parou, o trabalho diário de atualização de inventário foi executado etc. Não deve haver uma torrente contínua disso, caso contrário, há muito o que ler.
• Depuração significa que algo normal e insignificante aconteceu; um novo usuário chegou ao site, uma página foi renderizada, um pedido foi feito, um preço foi atualizado. Este é o material excluído das informações, porque haveria muito delas.
• Rastrear é algo que eu nunca usei.

Isso também pode ajudar tangencialmente, a entender se uma solicitação de log (do código) em um determinado nível resultará na efetivação do log, dado o nível de log efetivo com o qual uma implantação está configurada. Decida com que nível efetivo você deseja configurar sua implantação a partir das outras Respostas aqui e consulte-o para verificar se uma solicitação de log específica do seu código será realmente registrada ...

Para exemplos :

• "Uma linha de código de log registrada no WARN será realmente registrada na minha implantação configurada com ERRO?" A tabela diz: NÃO.
• "Uma linha de código de log registrada no WARN será realmente registrada na minha implantação configurada com DEBUG?" A tabela diz: SIM.

da documentação do logback :

De uma maneira mais gráfica, eis como a regra de seleção funciona. Na tabela a seguir, o cabeçalho vertical mostra o nível da solicitação de log, designado por p, enquanto o cabeçalho horizontal mostra o nível efetivo do logger, designado por q. A interseção das linhas (solicitação de nível) e colunas (nível efetivo) é o booleano resultante da regra de seleção básica.

Portanto, uma linha de código que solicita o log será efetivamente registrada se o nível efetivo de log de sua implantação for menor ou igual ao nível de gravidade solicitado dessa linha de código .

Eu respondo isso vindo de uma arquitetura baseada em componentes, em que uma organização pode estar executando muitos componentes que podem confiar um no outro. Durante uma falha de propagação, os níveis de log devem ajudar a identificar quais componentes são afetados e quais são as causas principais.

• ERRO - Este componente teve uma falha e acredita-se que a causa seja interna (qualquer exceção interna, não tratada, falha da dependência encapsulada ... por exemplo, banco de dados, exemplo REST, seria um exemplo de erro 4xx de uma dependência). Tire-me (mantenedor deste componente) da cama.

• AVISO - Este componente teve uma falha que se acredita ser causada por um componente dependente (o exemplo REST seria um status 5xx de uma dependência). Tire os mantenedores desse componente da cama.

• INFO - Qualquer outra coisa que queremos chegar a um operador. Se você decidir registrar caminhos felizes, recomendo limitar a 1 mensagem de log por operação significativa (por exemplo, por solicitação http recebida).

Para todas as mensagens de log, certifique-se de registrar o contexto útil (e priorize tornar as mensagens legíveis / úteis por humanos, em vez de ter resmas de "códigos de erro")

• DEBUG (e abaixo) - Não deve ser usado (e certamente não na produção). No desenvolvimento, eu recomendaria o uso de uma combinação de TDD e Depuração (quando necessário), em vez de poluir o código com instruções de log. Na produção, o registro INFO acima, combinado com outras métricas, deve ser suficiente.

Uma boa maneira de visualizar os níveis de registro acima é imaginar um conjunto de telas de monitoramento para cada componente. Quando tudo estiver funcionando bem, eles são verdes, se um componente registrar um AVISO, ele ficará laranja (âmbar) se algo registrar um ERRO, ele ficará vermelho.

No caso de um incidente, o componente (causa raiz) deve ficar vermelho e todos os componentes afetados devem ficar laranja / âmbar.

Não diferente de outras respostas, minha estrutura tem quase os mesmos níveis:

1. Erro: erros lógicos críticos no aplicativo, como um tempo limite de conexão com o banco de dados. Coisas que exigem uma correção de bug no futuro próximo
2. Aviso: questões inesquecíveis, mas coisas para prestar atenção. Como uma página solicitada não encontrada
3. Info: usado na primeira linha de funções / métodos, para mostrar um procedimento que foi chamado ou que uma etapa foi aprovada, como uma consulta de inserção realizada
4. log: informações lógicas, como resultado de uma instrução if
5. debug: conteúdo variável relevante para ser assistido permanentemente