Way 2 Web

Web development tips


 
Logging

Logger wars

There's no shortage of logger components for .NET. Many of them are open source, in the great Java tradition. All of them are competing for your attention.

log4net is the .NET version of the popular Java logger, log4j. Another contender is Nlog. Even Microsoft came out with their Enterprise Library with logging capabilities.

Which should you use? That is the subject of much debate. If you have simple logging tasks in mind, all of the them will serve you well, although they use slightly different logging models.

log4net is a very versatile logger and is easilly configurable, although documentation can be sketchy. The rest of this article demonstrates how log4net can be used in an ASP application.

Writing to the log

using log4net;

//define logger at the start of the class
private static readonly ILog logger = log4net.LogManager.GetLogger(
    System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);
...
try { 
    ...
    //debug log
    if (logger.IsDebugEnabled) {
        logger.Debug("Starting the revolution...");
    }
    ...
} catch(Exception e){
    //log error
    if (logger.IsErrorEnabled) {
        logger.Error("Caught during the revolution", e);
    }
}

Configuration

Log4net uses an XML configuration, which can be placed either in web.config or in a separate file. (More on this later.)

First, define log appenders using <appender> tags. This determines where your log entries will be sent - text file, email, event log, database tables, etc. In this example we'll use file (FileAppender) and email (SmtpAppender) appenders.

Second, connect the log appenders to the application using <appender-ref> tags in the <root> section.

<log4net debug="false">
  <appender name="FileAppender" type="log4net.Appender.FileAppender">
    <param name="File" value="..\logs\log-file.txt" />
    <param name="AppendToFile" value="true" />
    <layout type="log4net.Layout.PatternLayout">
      <param name="ConversionPattern" value="%d [%t] %-5p %c [%x] - %m%n" />
    </layout>
  </appender>
  <appender name="SmtpAppender" type="log4net.Appender.SmtpAppender,log4net">
    <to value="tech-support@my-domain.com" />
    <from value="logger@my-domain.com" />
    <subject value="WOWO log message" />
    <smtpHost value="mail.my-domain.com" />
    <bufferSize value="20" />
    <lossy value="false" />
    <threshold value="DEBUG" />
    <!--   <filter type="log4net.Filter.LevelRangeFilter">
      <levelMin value="DEBUG" />
      <levelMax value="FATAL" />
    </filter> -->
    <evaluator type="log4net.Core.LevelEvaluator,log4net">
      <threshold value="ERROR" />
    </evaluator>
    <layout type="log4net.Layout.PatternLayout,log4net">
      <conversionPattern value="%property{log4net:HostName} :: %level :: 
        %message %newlineLogger: %logger%newlineThread: %thread%newlineDate: 
        %date%newlineNDC: %property{NDC}%newline%newline" />
    </layout>
  </appender>
  <root>
    <appender-ref ref="SmtpAppender"/>
    <appender-ref ref="FileAppender"/>
    <level value="ALL"/>"
  </root>
</log4net>

Note that you can specify the minimum log level for which to listen (Fatal, Error, Info, Debug) either in the <root> section or within each <appender> using the <level> and <threshold> tags respectively.

A more complex specification is the LevelRangeFilter, which uses minimum and maximum levels.

The email log appender (SmtpAppender) writes logs to a buffer. Obviously, bufferSize defines the size of this buffer. When will the email be sent? This depends on the value of lossy and evaluator.

If <lossy value="false"/>, the email will be sent when the buffer is full, emptying the buffer. If <lossy value="true"/>, however, when the buffer is full, new logs will displace older logs. The email is sent only when an "important" log arrives, as specified by evaluator. This allows you to minimise the email overhead. In the above example, an email is only sent when, for example, an ERROR log arrives. The email, however, will contain all the other "less significant" logs that preceded the ERROR.

When placing the configuration XML in web.config, you'll need to add another bit of XML to web.config as well:

<configSections>
    <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
</configSections>

Like the log4net configuration XML, it should be on the same xml level as <system.web/>.

Then you'll need to tell the application to load the configuration settings when it starts. This can be done either in AssemblyInfo.cs or Global.asax.cs.

//In AssemblyInfo.cs

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

//In Global.asax.cs

public void Application_Start(object sender, EventArgs e) {
		log4net.Config.XmlConfigurator.Configure();
}

When using a separate log4net.config file, for example, change this to:

//In AssemblyInfo.cs

[assembly: log4net.Config.XmlConfigurator(ConfigFile="log4net.config",Watch=true )]

//In Global.asax.cs

public void Application_Start(object sender, EventArgs e) {
		log4net.Config.XmlConfigurator.ConfigureAndWatch( 
                new System.IO.FileInfo(
                    AppDomain.CurrentDomain.SetupInformation.ApplicationBase + 
                    "log4net.config"));
}

Use either AssemblyInfo.cs or Global.asax.cs. Not both!

Site-wide error catching

What about those unhandled errors that an ASP application throws? You've configured your server to redirect the user to a default error page, but you'd like to receive notification of the error too.

The answer lies in Global.asax.cs:

public void application_Error(object sender, EventArgs e) {    
        Exception ex = HttpContext.Current.Server.GetLastError();
        while (ex.InnerException != null) ex = ex.InnerException;
        
        if(ex is HttpException && ((HttpException)ex).ErrorCode == 404) {
            if(logger.IsWarnEnabled) {
                logger.Warn("404 - Page not found", ex);
            }
        } else {
            if(logger.IsFatalEnabled) {
                logger.Fatal("Mayday! Unhandled error!", ex);
            }
        }
        // HttpContext.Current.Server.ClearError();
        // Response.Redirect("SomeOtherPage.aspx");
    }
}

The ClearError() method will prevent the server from redirecting to your default error page. Use it when you want to redirect manually.

Adding context info

Log4net has a mechanism for easilly adding contextual information, called the "Nested Dynamic Context."

using(NDC.push(this.Account.ID)){
    logger.Debug("This log will be associated with the account ID");
}

Issues

  • Logs are used to report errors. But what if an error occurs within the logger?

    Log4net "swallows" such errors if they occur, which is a good thing for your real world application. Unfortunately, it also swallows up errors that you would like thrown, such as errors in your log4net configuration file.

    In other words, make sure your logger is working by writing a few debug messages such as "Application started.." in your Global.asax. This way if your log file is empty, you'll know something is amiss.

  • A case in point: web hosts often use ASP 2.0's default "Medium" trust level for customer applications. Unfortunately, this blocks log4net from reading in its configuration data. If you use a separate log4net config file, the error is "swallowed" and you're none the wiser.

    This seems to be an open issue for log4net users. The only current workaround is to beg/bribe your web host to raise the trust level.

    Others have suggested keeping the log4net config XML in web.config and adding requirePermission="false" to the <section> tag. While this may circumvent the call to ConfigurationPermission, if you plan to use a FileAppender or SmtpAppender, your code will still fail when requesting FileIOPermission and SecurityPermission respectively.

References