Tuesday, March 8, 2011

Wrasslin with Log4Net

I have a love-hate relationship with Log4Net. It is powerful, capable of doing everything I have ever wanted, yet configuration is always a challenge for me to get right. I wish there was a good, free GUI configuration tool available for it. In this post I will share the current Log4Net configuration that I am using. It is a moderately sophisticated configuration, relative to many of the posted samples. This example shows use of console appenders, event log appenders, file appenders, and multiple loggers. I also illustrate how to call Log4Net in a way that allows logging configuration changes to take effect immediately while a process is running.

Here are some points of interest. As I stumble through a configuration, the log4net.Internal.Debug AppSettings key is very helpful in showing me where my mistake lies. In order to take advantage of multiple loggers, it took me a while to figure out the secret sauce that made things work. First, loggers are hierarchical in nature. I found that I needed to specify all appenders used at the root logger level. Then each logger name I used specified the ones I used it for it. The key here was setting Additivity=”FALSE” otherwise I got an error indicating that the appender was closed.
I also found the concept of a single log message being able to be processed by multiple appenders to be powerful. One use was that I use a ConsoleAppender while I am testing to see the Log4Net output without having to pull up a log file. The message is still written to logs too, so I can verify that I log precisely what I intend. At the other end of the logging severity, I log all errors (both ERROR and FATAL) to a file but also log fatal errors to the Windows Event log for easy processing.
A couple of items on my to-do list are exploring buffered file appending and rolling over logs after they reach a maximum size. The BufferingForwardingAppender allows you to utilize the Unit of Work pattern to by aggregating a bunch of messages for the expensive, synchronous act of logging. The drawback to using this approach is that if you are concerned about troubleshooting program abends, you might lose the last few entries in this scenario. Also, although Log4Net is generally threadsafe, this appender is not.

<?xml version="1.0"?>
<configuration>
  <configSections>
    <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net" />
  </configSections>
  <appSettings>
    <!--if having trouble getting log4net to work turn its detailed internal logging on-->
    <!--<add key="log4net.Internal.Debug" value="true"/>-->
  </appSettings>
  <log4net>
    <root>
      <level value="ALL" />
      <appender-ref ref="FatalFile" />
      <appender-ref ref="ErrorFile" />
      <appender-ref ref="WarningFile" />
      <appender-ref ref="DebugFile" />
      <appender-ref ref="SomeInfoFile" />
      <appender-ref ref="SomeExtraFile" />
    </root>

    <logger name="PrimaryLogs" additivity="FALSE">
      <level value="ALL" />
      <appender-ref ref="FatalFile" />
      <appender-ref ref="ErrorFile" />
      <appender-ref ref="WarningFile" />
      <appender-ref ref="DebugFile" />
      <appender-ref ref="SomeInfoFile" />
    </logger>

    <logger name="ExtraLogs" additivity="FALSE">
      <level value="ALL" />
      <appender-ref ref="SomeExtraFile" />
    </logger>
    <appender name="FatalFile" type="log4net.Appender.EventLogAppender">
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%5thread] %type{1}.%method() - %message%newline%exception" />
      </layout>
      <filter type="log4net.Filter.LevelRangeFilter">
        <levelMin value="FATAL" />
        <levelMax value="FATAL" />
      </filter>
    </appender>
    <appender name="SomeExtraFile" type="log4net.Appender.RollingFileAppender">
      <file value="C:\logs\ AppLateMessage.txt" />
      <lockingModel type="log4net.Appender.FileAppender+MinimalLock" />
      <appendToFile value="true" />
      <staticLogFileName value="false" />
      <rollingStyle value="Date" />
      <datePattern value="'.'yyyyMMdd-HH'.log'" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%5thread] %type{1}.%method() - %message%newline%exception" />
      </layout>
      <filter type="log4net.Filter.LevelRangeFilter">
        <levelMin value="WARN" />
        <levelMax value="WARN" />
      </filter>
    </appender>
    <appender name="ErrorFile" type="log4net.Appender.RollingFileAppender">
      <file value="C:\logs\ AppError.txt" />
      <lockingModel type="log4net.Appender.FileAppender+MinimalLock" />
      <appendToFile value="true" />
      <staticLogFileName value="false" />
      <rollingStyle value="Date" />
      <datePattern value="'.'yyyyMMdd-HH'.log'" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%5thread] %type{1}.%method() - %message%newline%exception" />
      </layout>
      <filter type="log4net.Filter.LevelRangeFilter">
        <levelMin value="ERROR" />
        <levelMax value="FATAL" />
      </filter>
    </appender>
    <appender name="SomeInfoFile" type="log4net.Appender.RollingFileAppender">
      <file value="C:\logs\ AppSomeInfoFile.txt" />
      <lockingModel type="log4net.Appender.FileAppender+MinimalLock" />
      <appendToFile value="true" />
      <staticLogFileName value="false" />
      <rollingStyle value="Date" />
      <datePattern value="'.'yyyyMMdd-HH'.log'" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%5thread] %type{1}.%method() - %message%newline%exception" />
      </layout>
      <filter type="log4net.Filter.LevelRangeFilter">
        <levelMin value="INFO" />
        <levelMax value="INFO" />
      </filter>
    </appender>
    <appender name="WarningFile" type="log4net.Appender.RollingFileAppender">
      <file value="C:\logs\AppWarning.txt" />
      <lockingModel type="log4net.Appender.FileAppender+MinimalLock" />
      <appendToFile value="true" />
      <staticLogFileName value="false" />
      <rollingStyle value="Date" />
      <datePattern value="'.'yyyyMMdd-HH'.log'" />
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%5thread] %-5level %type{1}.%method() - %message%newline%exception" />
      </layout>
      <filter type="log4net.Filter.LevelRangeFilter">
        <levelMin value="WARN" />
        <levelMax value="FATAL" />
      </filter>

    </appender>
    <appender name="DebugFile" type="log4net.Appender.ConsoleAppender">
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%-5level %type{1}.%method() - %message%newline%exception" />
      </layout>
      <filter type="log4net.Filter.LevelRangeFilter">
        <levelMin value="DEBUG" />
        <levelMax value="ERROR" />
      </filter>
    </appender>
  </log4net>
</configuration>

No comments:

Post a Comment