Neste quinto post irei falar um pouco sobre uma parte que costuma ser muito negligenciada, pelo menos no desenvolvimento de aplicações servidor: Logging. Não terá muitoa ver com agilidade, mas também aqui existem alguns pontos importantes.

O componente de logging que utilizei foi o log4net (inspirado no log4j), do qual tomei conhecimento pela primeira vez através de um post do Pedro Santos. Outras possibilidades são o componente da Microsoft Enterprise Library ou o NLog (que nunca experimentei). O componente é muitíssimo bom e recomendo-o vivamente.

Desde o início do projecto, defini que a lógica de logging seria cidadão de primeira classe. A generalidade dos sistemas com os quais me deparei tem uma infra-estrutura de logging fraca... algumas vezes miserável ou inexistente mesmo! Este é um problema gravíssimo no momento em que o sistema passa a produção, como tenho a certeza que todos vocês reconhecem. O padrão habitual da infra-estrutura de logging, pela minha experiência tem as seguintes características:

• Utilização de apenas dois níveis de log: Erro e Debug. Nível de Aviso, Info ou outros, apesar de estarem disponíveis, são ignorados.
• O nível de Erro regista excepções (ou Err.Raises no VB6). O nível de Debug regista entrada e saída de métodos.
• As outras, poucas mensagens, são do tipo: "Estou aqui 1...", "Estou aqui 2...", "Passei, carago!".

Quando a aplicação passa a produção e começam a surgir os primeiros problemas, o resultado é o óbvio: horas infindas à procura do problema; adição de mensagens de forma totalmente ad-hoc e à pressão. Estou convencido que os problemas com as mensagens de log são fortes indutores do síndrome de abstinência do programador: "Eu preciso de acesso a Produção! Preciso! Dá-me acesso a Produção! Se não me deres acesso, amuo! Como é que eu sei o que se passa com o MEU sistema?"

Eu sou tão culpado disto como todos os outros. No meu primeiro projecto, necessitei de pegar em código legado. A minha primeira decisão? Apagar todas as mensagens de log que o componente continha. Quando chegou a Produção é que foi o bom e o bonito... um episódio muito revelador da minha "verdura" e da preocupação com a qualidade da empresa para que trabalhava...

Bom, neste projecto as coisas foram muito diferentes. Defini diversas linhas de orientação:

• Abandonar os logs "mecânicos" no início e no fim de cada método.
• Pensar em cada momento quais as mensagens de logs necessárias. Qual o texto da mensagem, e quais os dados a "loggar", tendo o devido cuidado com dados potencialmente sensíveis.
• O texto da mensagem de log deve estar sempre o mais próximo possível da linguagem do domínio, com as excepções em que a parte realmente importante é a técnica (detalhes de pedidos HTTP/XML, por exemplo).
• Utilizar todos os níveis de log de forma construtiva. Decidir conscientemente qual o nível de log a que uma dada mensagem pertence.
• Periodicamente, nos code reviews, analisar especificamente os logs. "Se a aplicação falhasse neste ponto, conseguia perceber o que se tinha passado até ao momento?", "Este log deve ser um info, um debug, um warning?"
• Tomar em atenção o potencial impacto na performance das mensagens de log.
• Criar testes unitários para as mensagens de log.

O resultado final, do meu ponto de vista, é muito satisfatório. Ao ler os logs no nível Info, é possível compreender facilmente o fluxo de execução do programa, os seus blocos lógicos. Aumentando o nível para Debug é possível, para além disso, recolher um manancial de informação, detalhada, que permite compreender o que realmente se passou durante a execução do programa.

Os logs foram úteis também numa outra situação. Por vezes, quando criamos testes, é dificíl testar determinados comportamentos internos (privados) de um objecto, existindo múltiplas técnicas para lidar com a situação. Algo de que tomei consciência neste projecto é que em algumas situações os logs permitem testar de forma indirecta esses comportamentos, o que representa uma vantagem adicional. É claro que este deve ser uma espécie de último recurso (ou recurso complementar), mas é mais uma ferramenta que podemos utilizar.

No próximo post... acho que será sobre performance counters. Também é algo muito engraçado.