Utilizando o NLog

Materiais de apoio

Há um tutorial bastante simples e direto para utilizar o NLong no pacote oficial do github.

Há também o vídeo “NLog: Logging to a file = Code in 60 Seconds”

É um vídeo muito mais simples que o citado no post do log4net, mostrando muito menos detalhes, mas já dá para ver que é muito rápido começar a utilizar o NLog.

Há muita documentação no wiki do pacote oficial do GitHub.

1 - Instalar na aplicação o pacote nuget, que pode ser feito via comando no Package Manager Console:

Install-Package NLog

Para ser um acelerador, aconselho instalar a configuração na aplicação:

Install-Package NLog.Config

Há diversos instaladores específicos para facilitar ainda mais o uso, dependendo do projeto que for necessário:

• NLog.Web - pacote contem targets e layout-renderes específicos para o ASP.Net and IIS.
• NLog.Windows.Forms - pacote contem targets específicos Windows.Forms
• NLog.Extended - MSMQ target, AppSetting layout renderer
• NLog.Config - Configuração NLog exemplo/inicial
• NLog.Schema - XSD Schema para o NLog config xml - para, entre outras coisas, ter o Intellisense no Visual Studio

2 - Configurar NLog.config

Aqui o NLog fica muito mais simples, já que o intellisense do Visual Studio ajuda em toda a configuração do arquivo.

O nível (level) do NLog possibilita as essas opções:

• Trace - log muito detalhado, o que pode incluir alto volume de informação (como payload do protocolo). Este nível de log é tipicamente habilitado somente durante o desenvolvimento.
• Debug - informação de depuração, menos detalhada que o trace, tipicamente não habilitado em produção.
• Info - mensagens de informação, que normalmente são habilitado no ambiente de produção
• Warn - mensagens de avisos, tipicamente para assuntos não críticos, que podem ser recuperadas ou falhas temporárias
• Error - mensagens de erros - na maioria das vezes estas são exceções
• Fatal - erros muito sérios

O que é o appender do log4net no NLog é o Targets (https://github.com/nlog/nlog/wiki/Targets)

Há também vários layouts disponívels (https://github.com/nlog/nlog/wiki/Layouts)

E é possível configurá-los com várias opções (https://github.com/NLog/NLog/wiki/Layout-renderers)

O resultado é uma configuração extremamente simples:

	<?xml version="1.0" encoding="utf-8" ?>
	<nlog xmlns="http://www.nlog-project.org/schemas/NLog.xsd"
	xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
	xsi:schemaLocation="http://www.nlog-project.org/schemas/NLog.xsd NLog.xsd"
	autoReload="true"
	throwExceptions="false"
	internalLogLevel="Off" internalLogFile="c:\temp\nlog-internal.log" >
	<targets>
	<target name="logfile" xsi:type="File" fileName="mylogfile.txt" />
	<target name="console" xsi:type="Console" />
	<target name="debugger" xsi:type="Debugger" />
	<target name="trace" xsi:type="Trace" />
	</targets>
	<rules>
	<logger name="*" minlevel="Trace" writeTo="logfile" />
	<logger name="*" minlevel="Info" writeTo="console" />
	<logger name="*" minlevel="Debug" writeTo="debugger" />
	<logger name="*" minlevel="Trace" writeTo="trace" />
	</rules>
	</nlog>

view raw app.config.xml hosted with ❤ by GitHub

 Também é fácil fazer a configuração do log através de programação, como nesta resposta do Stack Overflow "Add, enable and disable NLog loggers programmatically".

3 Definir a instância da classe

Há um método para facilitar a configuração da instância na classe:

private static Logger logger = LogManager.GetCurrentClassLogger();

view raw cs hosted with ❤ by GitHub

4 Efetuar log

logger.Trace("");
logger.Debug("");
logger.Info("");
logger.Warn("");
logger.Error("");
logger.Fatal("");

logger.Log(LogLevel.Info, "");

O código fonte do exemplo está disponível no GitHub.

Conhecendo o log4Net

Para conhecer o log4Net há algumas boas referências:

• Artigo no code project (log4net Tutorial)
• Video explorando e explicando o tutorial anterior

São necessários 5 passos para utilizar o log4net:

1 - Instalar na aplicação o pacote nuget, que pode ser feito via comando no Package Manager Console:

Install-Package log4net

2 - Configurar no app.config ou web.config o log, seguindo a documentação

A vantagem de definir as configurações do log nesses arquivos é poder alterá-las em ambiente de execução, sem necessidade de compilar as soluções

	<?xml version="1.0" encoding="utf-8" ?>
	<configuration>
	<configSections>
	<section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
	</configSections>
	<log4net>
	<!--Para logar no console https://logging.apache.org/log4net/log4net-1.2.13/release/sdk/log4net.Appender.ConsoleAppender.html-->
	<appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
	<filter type="log4net.Filter.LevelRangeFilter">
	<levelMin value="WARN" />
	<levelMax value="ERROR" />
	</filter>
	<layout type="log4net.Layout.PatternLayout">
	<conversionPattern value="%date [%thread] [%logger] %-5level %logger [%ndc] - %message%newline" />
	</layout>
	</appender>
	<!--Para salvar em arquivo https://logging.apache.org/log4net/log4net-1.2.13/release/sdk/log4net.Appender.FileAppender.html-->
	<appender name="FileAppender" type="log4net.Appender.FileAppender">
	<file value="mylogfile.txt" />
	<appendToFile value="false" />
	<lockingModel type="log4net.Appender.FileAppender+MinimalLock" />
	<layout type="log4net.Layout.PatternLayout">
	<conversionPattern value="%date [%thread] [%logger] %level %logger - %message%newline" />
	</layout>
	<filter type="log4net.Filter.LevelRangeFilter">
	<levelMin value="INFO" />
	<levelMax value="FATAL" />
	</filter>
	</appender>
	<!--Para gerenciar maximo e historico de arquivo https://logging.apache.org/log4net/log4net-1.2.13/release/sdk/log4net.Appender.RollingFileAppender.html-->
	<appender name ="RollingFileAppender" type="log4net.Appender.RollingFileAppender">
	<file value="myRollingLogfile.txt"/>
	<appendToFile value ="true" />
	<rollingStyle value="Size" />
	<maximumFileSize value="10MB" />
	<maxSizeRollBackups value="5"/>
	<staticLogFileName value ="true" />
	<layout type="log4net.Layout.PatternLayout">
	<conversionPattern value="%date [%thread] [%logger] %level %logger - %message%newline" />
	</layout>
	</appender>
	<root>
	<level value="INFO" />
	<appender-ref ref="ConsoleAppender" />
	<appender-ref ref="FileAppender"/>
	<appender-ref ref="RollingFileAppender"/>
	</root>
	</log4net>
	<startup>
	<supportedRuntime version="v4.0" sku=".NETFramework,Version=v4.6" />
	</startup>
	</configuration>

view raw config hosted with ❤ by GitHub

No elemento <confisections> configuramos que no arquivo haverá a seção para o log4net. No elemento <log4net>definimos a configuração do log.

<root>

O <root> é necessário para definir o nível(level) de log através do elemento (filtrando mensagens de relevância menor que a definida) e há 7 níveis:

1. OFF - Nada é logado
2. FATAL
3. ERROR
4. WARN
5. INFO
6. DEBUG
7. ALL - Tudo é logado

Por exemplo, se o nível do log for definido para ERROR, somente mensagens de ERROR e FATAL serão armazenadas.

Além disso é necessário adicionar a tag <appender-ref> referenciando os appenders  (Que falaremos abaixo)

No exemplo acima no estou utilizando:

• ConsoleAppender, ou seja, os logs sao enviados ao Console
• FileAppender, para salvar em disco (No qual configuerei para salvar somente a última execução com a tag <appendtofile value="false">)

RollingFileAppender (Para salvar um histórico de arquivo limitando quantidade e tamanho)

Uma propriedade comum que utilizei nesses appenders foram os elementos <layout> e o <conversionpattern>. Há algumas opções interessantes como:

• timestamp  = Número de milissegundos desde o início da aplicação)
• %20timestamp = Para garantir que item a ser logado tenha no mínimo 20 caracteres, adicionando espaço. No exemplo acima, fará para o valor do timestamp
• %property{user} = que podemos definir uma propriedade definida no código

Para entender todas as demais configurações feitas, sugiro consultar a documentação que está no link de cada appender citado.

Ainda há várias outras opções de Appenders como podemos ver na documentação.

Também é possivel customizar appenders, como no exemplo deste link que faz um appender para CSV.

No vídeo ainda é demonstrado o o AdoNetAppender salvando informações na base de dados.

Há ainda a documentação de todos os filtros disponíveis.

3 Aplicar as configurações do app.config

Ao adicionar essa linha de código(para organizacao, no program.cs abaixo dos using), toda a configuração do log4net será feita lendo o arquivo de configuração (E recarregada em caso de alterações):

[assembly: log4net.Config.XmlConfigurator(Watch = true)]

Ou para a web:

http://stackoverflow.com/questions/10204171/configure-log4net-in-web-application

4 Configurar a instância

Para configurar a instância, são indicadas 2 formas:

1) Se você utilizar a Framework anterior a 4.5, deverá instanciar em toda classe conforme abaixo:

private static readonly log4net.ILog log = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);

view raw cs hosted with ❤ by GitHub

Dessa forma o log é instanciado por classe e você saberá onde o log foi feito. O parâmetro string que esta sendo passado por reflector facilitar o copiar e colar, mas gera uma pequena perda de desempenho (Ja que a instância estática é criada uma vez por cada classe)


2) A partir da framework 4.5 é possivel resolver o nome do log em momento de compilacao, utilizando o código abaixo:

private static readonly log4net.ILog log = LogHelper.GetLogger();

view raw cs hosted with ❤ by GitHub

O código do LogHelper está disponível aqui:

	using System;
	using System.Collections.Generic;
	using System.Linq;
	using System.Runtime.CompilerServices;
	using System.Text;
	using System.Threading.Tasks;
	namespace Log4NetExample
	{
	public class LogHelper
	{
	/// <summary>
	/// http://www.thomaslevesque.com/2012/06/13/using-c-5-caller-info-attributes-when-targeting-earlier-versions-of-the-net-framework/
	/// https://msdn.microsoft.com/pt-br/library/system.runtime.compilerservices.callerfilepathattribute%28v=vs.110%29.aspx
	/// </summary>
	/// <param name="fileName">Valor definido em momento de compilacao</param>
	/// <returns></returns>
	public static log4net.ILog GetLogger([CallerFilePath] string fileName = "")
	{
	return log4net.LogManager.GetLogger(fileName);
	}
	}
	}

view raw LogHelper.cs hosted with ❤ by GitHub

5 Efetuar log

A parte mais fácil é utilizar o log. Basta utilizar a instância criada na classe e chamar os métodos:

• Debug()
• Info()
• Warn()
• Error()
• Fatal()
  
  

O código fonte do exemplo está disponível no GitHub.

Log de aplicações (Avaliando as boas opções)

O log pode ajudar, mas cuidado com o excesso

O post “The problem with loggin” explica alguns cuidados para não se exceder ao usar log.

O System.Diagnostics não é suficiente?

No post “Logging best practices” há uma crítica em relação ao excesso de frameworks alternativas de log, que ao invés de preencher os Gaps que faltam no Trace padrão, o reinventam completamente. Um examplo de proposta que preenche os Gaps é o Essential Diagnostics (http://essentialdiagnostics.codeplex.com/)

Quais as outras frameworks?

No post “When should I use Tracing vs Logger.NET, Enterprise Library, log4net or Ukadc.Diagnostics?” estão listadas várias opções de pacotes de Log.

No nuget, olhando a estatística de mais baixados de 6 semanas do dia 30/1/2016 estão:

• log4net (250K de downloads) (https://www.nuget.org/stats/packages/log4net?groupby=Version)
• NLog (150K de downloads) (https://www.nuget.org/stats/packages/NLog?groupby=Version)

No github, o NLog está com mais popularidade:

• NLog tem mais Estrelas, pessoas contribuindo e mais commits recentes (https://github.com/NLog/NLog/graphs/commit-activity)
• log4net vem sofrendo menos contribuições:
  (https://github.com/apache/log4net/graphs/commit-activity)

No post “log4net vs. Nlog”ainda é discutido a percepção de diversos outros desenvolvedores.

Nos próximos posts, vou falar fazer exemplo dos dois pacotes. Tanto o System.Diagnostics, o log4net e o NLog são excelentes opções - mas pensando no que é mais simples de utilizar(e principalmente configurar) eu acabei preferindo o NLog.

Teste unitário com Selenium WebDriver (Simples exemplo com o Chrome e Firefox)

O vídeo(Selenium WebDriver - Install + Hello World with Visual Studio, C#)  é um ótimo passo a passo de como utilizar o Selenium Webdriver com uma aplicação c#.

Para demonstrar, adicionei ao GitHub um simples exemplo de teste unitário fazendo uma busca no Bing utilizando Chrome e Firefox.

As dependências dos projeto foram instaladas com o Nuget utilizando os seguintes comandos:
Install-Package Selenium.WebDriver
(Pacote básico para permitir o Selenium Webdriver e o firefox)

Install-Package Selenium.WebDriver.ChromeDriver
(Pacote para permitir os testes com o Chrome)

O código acontece no método SearchAndNavigateTest, que basicamente abre a url do Bing, busca pela palavra chave "aplicacoesweb selenium" e clica no primeiro link que contiver "aplicacoesweb.blogspot" no atribute href.

	private static void SearchAndNavigateTest(IWebDriver driver)
	{
	try
	{
	driver.Navigate().GoToUrl("http://www.bing.com/");
	driver.Manage().Timeouts().ImplicitlyWait(TimeSpan.FromSeconds(30));
	IWebElement searchInput = driver.FindElement(By.Id("sb_form_q"));
	searchInput.SendKeys("aplicacoesweb selenium");
	searchInput.SendKeys(Keys.Return);
	IWebElement webSiteAnchor = driver.FindElement(By.XPath(("//a[contains(@href,\"aplicacoesweb.blogspot\")]")));
	webSiteAnchor.Click();
	}
	finally
	{
	driver.Close();
	}
	}

view raw UnitTest1.SearchAndNavigateTest.cs hosted with ❤ by GitHub

Este código é executado no FireFox e no Chrome no teste unitário TestMethod1()

Caching (OutputCacheAttribute e DonutCachingAttribute)

O OutputCacheAttribute, atributo nativo no ASP.NET MVC, permite que façamos cache de resultados de actions para futuras respostas às requisições dos usuários. Há várias opções de configuração e é sugerido de se utilizar esse artifício quando você precisa otimizar o desempenho de sua aplicação.

Otimizar desempenho é uma tarefa que deve ser feita de maneira muito criteriosa. Primeiro é importante você saber qual o problema atual a ser resolvido e as métricas da situação, por exemplo, está consumindo muito processamento determinada action (Atinge 100% de CPU, gasta muita memória e/ou demora muito tempo para retorno ao usuário). Deve-se tomar o cuidado para não aplicar uma solução de cache que poderá resolver os problemas anteriores, mas acabar gerando um outro problema de consumo de memória por manter as informações em cache. Por isso a importância das métricas antes e depois de aplicar a solução.

Decidindo pela aplicação do OutputCacheAttribute é importante ainda saber que ele gera um cache respeitando configurações de variação por action do Controller, por tempo (Duration), por parâmetros de unicidade (VaryByContentEncoding, VaryByCustom, VaryByHeader, VaryByParam) e por local (Client, Downstream, Server). Se for decidido que o cache será no servidor é importante saber que futuras requisições nas condições de unicidade configuradas anteriormente receberá a informação do cache completa, ou seja, se o cache foi criado pela requisição de um usuário com perfil de administrador (que tem mais opções de menu que um usuário comum), todos os usuários ao requisitarem a página em cache irão ver a página como o administrador (com as opções de menu que não deveria ver).

Se você tiver essa situação, para resolvê-la, há a teoria de cache chamada de Donut Hole Caching, que basicamente você pode escolher qual a parte do conteúdo deseja fazer cache e/ou qual deve ser atualizada automaticamente pelo contexto do usuário requisitante, este artigo em inglês explica a teoria de maneira detalhada e lúdica.

Há uma implementação de pacote para utilizar o Donut Hole Caching no pacote Nuget MvcDonutCaching que também tem o fonte disponível no Github. Neste artigo há uma explicação de todas as dificuldades e escolhas feitas para viabilizar a implementação, mas basicamente a grande sacada é que utilizando o pacote, é possível definir ChildActions como dinâmicas para serem carregadas, mesmo quando o resto da página está em cache. Para viabilizar isso o pacote adiciona  comentário HTML para marcar pontos de atualização de parte de conteúdo nas próximas requisições, quando utilizado as extensões @HtmlAction(), @Html.RenderAction() e definindo o parâmetro excludeFromParentCache, conforme código abaixo:

	public static void RenderAction(this HtmlHelper htmlHelper, [AspMvcAction] string actionName, [AspMvcController] string controllerName, RouteValueDictionary routeValues, bool excludeFromParentCache)
	{
	if (excludeFromParentCache)
	{
	var serialisedActionSettings = GetSerialisedActionSettings(actionName, controllerName, routeValues);
	htmlHelper.ViewContext.Writer.Write("<!--Donut#{0}#-->", serialisedActionSettings);
	}
	htmlHelper.RenderAction(actionName, controllerName, routeValues);
	if (excludeFromParentCache)
	{
	htmlHelper.ViewContext.Writer.Write("<!--EndDonut-->");
	}
	}

view raw cs hosted with ❤ by GitHub

O ActionFilter (DonutOutputCacheAttribute) irá atualizar esses "buracos" no método OnResultExecuted.