O problema com o registro em log

Um post recente do Stack Overflow descreveu o estilo de registro de um programador. Aqui está o que ele registra:

Nível INFO

O início e o fim do método

O início e o fim de quaisquer loops principais

O início de qualquer instrução importante de case/switch

Nível de DEBUG

Todos os parâmetros passados para o método
método

Qualquer contagem de linhas dos conjuntos de resultados que eu recupero

Todas as linhas de dados que possam conter dados suspeitos ao serem passadas para o método

Quaisquer caminhos de arquivos “gerados”, cadeias de conexão ou outros valores que possam ser confundidos ao serem “juntados” pelo ambiente.

Nível de ERRO

Exceções tratadas

Tentativas de login inválidas (se a segurança for um problema)

Dados incorretos que interceptei para relatar

Nível FATAL

Não quero destacar o o autor aqui, mas isso me parece um pouco … excessivo.

Embora eu mesmo nunca tenha sido um grande registrador, um dos meus colegas de equipe no Stack Overflow é. Portanto, ao criar o Stack Overflow, incluímos log4nete registrei várias informações nos diversos níveis. Eu não era necessariamente um grande fã dessa abordagem, mas achei que não havia problema.

O registro em log tem um certo charme sedutor. Por que não registrar o máximo que puder, sempre que puder? Mesmo que o senhor não esteja planejando usá-lo hoje, quem sabe ele poderá ser útil para a solução de problemas amanhã. Que diabo, registre tudo! O que isso poderia prejudicar?

É claro que o registro em log parece inofensivo, mas deixe-me dizer aos senhores que ele pode causar alguns graves prejudicado. Encontramos um bug de registro recursivo particularmente desagradável:

Na thread nº 1, nosso código estava fazendo coisas de registro (bloqueio) / banco de dados (bloqueio)
No thread nº 2, nosso código estava fazendo coisas do banco de dados (bloqueio) / coisas do registro (bloqueio)

Se essas coisas acontecessem suficientemente próximas umas das outras sob carga pesada, isso resultava em – o senhor adivinhou – um cenário clássico de deadlock fora de ordem. Não sei se o senhor veria isso em um aplicativo com pouca carga, mas em nosso site isso acontecia cerca de uma vez por dia, em média.

Não culpo a log4net por isso, culpo nosso código de baixa qualidade. Passamos dias solucionando esses deadlocks com … espere por isso … adicionando mais registros! O que naturalmente tornou o problema pior e ainda mais difícil de resolver. Por fim, fomos forçados a fazer despejos de memória e usar ferramentas de análise de despejo. Com a generosa ajuda do Greg Varveris, finalmente conseguimos identificar o culpado: nossa estratégia de registro. Que irônico. E quero dizer real ironia, não do tipo falso da Alanis Morrissette.

Embora eu acredite muito no registro de exceções, nunca fui um grande fã do registro no sentido geral de “vamos registrar tudo o que for possível”:

Registro em log significa mais código. Se o senhor estiver usando uma estrutura de registro tradicional como o log4net, cada evento registrado representa pelo menos uma linha adicional de código. Quanto mais o senhor registra, maior fica o código. Esse é um problema sério, porque o senhor o código é o inimigo. Código de registro visível é desordem. como comentários excessivosele obscurece ativamente o código que está fazendo o trabalho real no aplicativo.
O registro em log não é gratuito. A maioria das estruturas de registro é bastante eficiente, mas não é infinitamente rápida. Cada linha de log que o senhor grava no disco tem um custo de desempenho geral para o aplicativo. Isso também pode ser complicado se o senhor estiver dissecando objetos complexos para colocá-los no log; isso leva mais tempo.
Se vale a pena salvar em um arquivo de log, vale a pena mostrá-lo na interface do usuário. Esse é o paradoxo: se as informações que o senhor está registrando são valiosas, elas merecem ser exibidas no próprio aplicativo, não enterradas em um arquivo de log anônimo em algum lugar. Mesmo que seja apenas para os administradores. Os arquivos de log são, com muita frequência, o lugar onde os dados úteis morrem, sozinhos, sem amor e ignorados.
Quanto mais o senhor registra, menos pode encontrar. Registre coisas suficientes e, eventualmente, seus registros ficarão tão ruidosos que ninguém conseguirá encontrar nada. É muito fácil enterrar-se em uma avalanche de dados de registro. Na verdade, esse é o padrão: qualquer computador é perfeitamente capaz de gerar mais dados de registro do que qualquer um de nós poderia lidar em nossa vida. A despesa oculta aqui não é o registro, é a capacidade intelectual necessária para dar sentido a esses registros gigantescos. Não importa o quanto as suas ferramentas de análise de logs sejam incríveis, ninguém espera extrair um gigabyte de arquivos de log para obter informações úteis de diagnóstico.
O arquivo de log que gritou lobo. Boa sorte em conseguir que todos da sua equipe concordem com as definições exatas de FATAL, ERROR, DEBUG, INFO e quaisquer outros níveis de log que o senhor tenha definido. Se o senhor decidir registrar apenas os problemas mais hediondos do tipo serial-killer e assassino em massa, o mal terá muito menos espaço para se esconder em seus arquivos de log, e será muito menos chato quando o senhor do Veja.

Assim o registro em log é uma grande perda de tempo? Tenho certeza de que algumas pessoas lerão até aqui e chegarão a essa conclusão, independentemente do que eu escrever. Não sou contra o registro em log. Sou contra oabusivo-logging. Como qualquer outra ferramenta do seu kit de ferramentas, quando usada de forma adequada e apropriada, ela pode ajudá-lo a criar programas melhores. O problema com o registro não é o registro em si, é a armadilha sedutora do TOC “só mais um pouco de dados no registro” em que os programadores caem quando implementando registro. O registro em log tem má fama porque muitas vezes é usado de forma abusiva. É uma pena acabar com todo esse código extra gerando volumes e volumes de logs que não ajudam ninguém.

Desde então, removemos todo o registro do Stack Overflow, confiando exclusivamente no registro de exceções. Sinceramente, não sinto nenhuma falta disso. Não consigo nem pensar em um único vez, desde então, que desejei ter um arquivo de registro detalhado gigante para me ajudar a diagnosticar um problema.

Quando se trata de registro, a resposta certa não é “sim, sempre e o máximo possível”. Resista à tendência de registrar tudo. Comece pequeno e simples, registrando apenas os erros mais óbvios e críticos. Adicione (ou, idealmente, injete) mais registros somente conforme demonstrado por necessidades específicas e verificáveis.

Se o senhor não tomar cuidado, essas entradas de registro individuais, por mais finas que sejam, têm uma tendência preocupante de fazer com que seus registros acabem como o infeliz Sr. Creosote.