Esta semana tive uma necessidade de log específica em um de nossos sistemas, que acabou gerando uma excelente adição para o nosso framework de desenvolvimento. A necessidade era saber o que acontecia em produção que acabava gerando um bug raro de valores no final do dia, e que fomos incapazes de reproduzir mesmo com uma grande quantidade de testes unitários. Aparentemente o bug está associado a uma condição de multi-usuário que é muito complicada de reproduzir. Para resolver este bug precisaríamos saber a seqüência exata em que as operações foram realizadas, e isto só seria possível com log.
A necessidade de log de negócio acaba surgindo vez por outra em aplicações. E, praticamente para cada sistema que eu já participei, foi feita uma solução diferente para log, com vantagens e desvantagens. Alguns usam log em banco, colocando triggers nas tabelas e replicando as informações, o que é extremamente simples de fazer mas gera grandes problemas de contenção e espaço utilizado. Outros usam versões do log4net gerando dados em arquivos, o que também é relativamente simples de fazer porém gera também dificuldade em ambientes massivamente multi-usuário – sem falar na dificuldade de processar os arquivos depois. Já fiz também log em banco, com e sem log4net, com bons resultados, mas sempre com uma solução específica para cada caso, o que causava um bom esforço de manutenção.
Outro ponto que sempre me incomodou é a questão da intrusividade das funções de log na regra de negócio. Tirando a solução em trigger de banco, qualquer implementação de log4net foi sempre feita com chamadas específicas de log dentro da rotina de negócio. Isto polui a rotina e dificulta a manutenção. Eu sempre tentei criar algo tipo AOP, mas nunca consegui uma solução boa. Mesmo atualmente, as bibliotecas conhecidas de AOP (PostSharp, Spring.Net etc.) não são uma boa opção para o nosso ambiente por serem um framework completo, de grande impacto…. Usar qualquer uma delas só pra log de algumas regras de negócio pra mim seria usar um canhão pra matar uma mosca.
Assim, resolvemos desta vez fazer algo decente, já incorporado ao framework, e que usasse uma abordagem AOP na medida do possível. Graças à tecnologia do Castle Windsor IoC usada atualmente no framework, isto foi relativamente simples de ser feito. Definimos na nossa arquitetura que o log de uma regra deveria ser expresso através da observação de parâmetros e retornos da função, antes e depois dela ser executada. Através do uso destas condições pré e pós, é possível identificar exatamente como aquela função afetou os dados.
Para implementar, o que fizemos foi usar o log4net para salvar eventos em banco. Até aí, solução padrão. O passo seguinte foi definir atributos AOP para marcar uma regra de negócio como sendo logada. O ideal teria sido definir as condições pré e pós no próprio atributo, porém o C# atualmente não suporta nada que não seja estático nos atributos; e usar strings eu acho uma prática ruim. A solução usada foi definir um tipo para o atributo que apontasse para uma classe que definiria quais são todas as condições, utilizando lambda.
O resultado ficou excelente. Abaixo está um exemplo do atributo na regra de negócio:
[Log(typeof(AtualizarValorDePosicaoLog))]
public void AtualizarValorAnterioDePosicao(Contrato contrato,
                                    Posicao posicao, decimal valor) {
 
E no tipo de definição das condições, fica assim:
public class AtualizarValorDePosicaoLog : LoggerBase {

  public AtualizarValorDePosicaoLog() : base(
    Properties.PreCondition("valor"),
    Properties.PreCondition<Contrato>(
      c => c.Id, c => c.Tipo, c => c.TipoBacen,
      c => c.Moeda, c => c.Posto, c => c.ValorMoedaEstrangeira, 
      c => c.ValorMoedaNacional, c => c.ValorUSD, c => c.TipoPagamento),
    Properties.PreCondition<Posicao>(
      p => p.Id, p => p.ValorPosicaoAnterior, p => p.Conformidade,
      p => p.Baixa, p => p.Transferencias, 
      p => p.TotalCompra, p => p.TotalVenda, p => p.Moeda, p => p.Posto,
      p => p.Tipo),

    Properties.PostCondition<Posicao>(
      p => p.Id, p => p.ValorPosicaoAnterior, p => p.Conformidade,
      p => p.Baixa, p => p.Transferencias, 
      p => p.TotalCompra, p => p.TotalVenda, p => p.Moeda, p => p.Posto,
      p => p.Tipo)) { }
    }
 
Na execução, o interceptor da classe de serviço busca o atributo, instancia o tipo de definição e coleta os dados, antes e depois da rotina executar. Para minimizar o impacto em tempo de execução, o logger simplesmente armazena um dicionário com todas as condições recolhidas, serializando num XML. Posteriormente, de maneira assíncrona e com baixa prioridade, um executor analisa os registros de log gerados e expande cada condição em tabelas do tipo dicionário.
Com isto o impacto ficou bem pequeno e conseguimos fazer algo quase puramente AOP e sem nenhuma definição em string! Finalmente conseguimos uma implementação boa para log, que deve nos atender por muito tempo.
Nesta solução, alem da equipe da WhiteFox, tivemos a colaboração do arquiteto Fernando Bichara, da Perlink.
.NET, AOP, Castle Windsor, Desenvolvimento, Framework, Log
4 Comentários
Tags
.NET activewriter Agile Android anemic model angularjs AOP Arquiteto Arquitetura ASP.NET ASP.NET. NET ASP.NET MVC azure BACEN backbonejs boxing development C# Castle Monorail Castle Windsor comparing Concorrência DDD Desenvolvimento Desenvolvimento Ágil DSL Empreendedorismo entiy framework Escalabilidade Framework Fábrica de Sofware Gerenciamento HQL Interface iOS Iterator Junior knockoutjs Lambda Linguagens Log Mensageria Microservices monorail MVC MVC Web API NH nhibernate Object.Equal ORM P+ P4Ed Poliedro Processos Produtividade Repositório REST Scrum Segurança ServiceBroker sql SQL Server TFS TFS 2010 TI unboxing value types view engine Visual Studio Visual Studio 2015 Web web.api White Fox XChange XSLT Ágil
Latest
RT @dotnetfdn: Solution1 is the 1st conference of the C# community discord server. From Nov 17 to Nov 24 we will learn about the new featur… 3 weeks ago
RT @pragprog: Practices of an Agile Developer by Venkat Subramaniam @venkat_s and Andy Hunt @PragmaticAndy Stop doing things the hard way.… 3 weeks ago
javascript.plainenglish.io/40-ridiculousl… 1 year ago
RT @martinfowler: A recurring question: "can we reasonably call ourselves software engineers?" Often this is discussed by people with littl… 1 year ago