Log4Net Tutorial pt 5: Using Logger Objects

§ June 26, 2008 07:40 by beefarino |

We've done a lot log4net configuration in the last few tutorials; time to mix in some code and discuss loggers.  This post is meant to show you the most common pattern of logger use.

Crack open Visual Studio, create a new console project, and add a reference to the log4net assembly.

Add the following application configuration file to the project:

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

  <log4net>

    <appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%logger [%level]- %message%newline" />
      </layout>
    </appender>

    <root>
      <level value="ALL" />
      <appender-ref ref="ConsoleAppender" />
    </root>
  </log4net>
</configuration>

Add the following code to your program.cs file:

namespace Tutorial5_Loggers
{
    class Program
     {
        private static log4net.ILog Log = log4net.LogManager.GetLogger( System.Reflection.MethodBase.GetCurrentMethod().DeclaringType );

        static void Main( string[] args )
        {
            log4net.Config.XmlConfigurator.Configure();
            Log.Info( "this is an info message" );
            Console.ReadLine();
        }
    }
}

The logger object is created on line 5 via a the call to LogManager.GetLogger.  Compile and run and check out the output; it'll be similar to the following:

Tutorial5_Loggers.Program [INFO]- this is an info message

The first item in the log entry printed to the console is the name of the logger object that issued the log entry.  Because GetLogger was passed a reference to my Program type, the logger name is the fully qualified type name of the Program object.

Add another class to the project:

namespace Tutorial5_Loggers
{
    class MyClass
    {
        private static log4net.ILog Log = log4net.LogManager.GetLogger( System.Reflection.MethodBase.GetCurrentMethod().DeclaringType );

        public static void WriteLog()
        {
            Log.Info( "this is an info message" );
        }
    }
}

and add a call to MyClass.WriteLog to your Main method (see line 7 below):

static void Main( string[] args )
{
    log4net.Config.XmlConfigurator.Configure();

    Log.Info( "this is an info message" );

    MyClass.WriteLog();
    Console.ReadLine();
}

Compile and run, and note the logger name in the second log statement matches the type name of MyClass:

Tutorial5_Loggers.Program [INFO]- this is an info message
Tutorial5_Loggers.MyClass [INFO]- this is an info message

Hierarchical Logger Configuration

You can use loggers this way to isolate logging concerns across your objects, and I wholly recommend you do so.  This will enable you to throttle and direct log output from individual loggers using log4net's hierarchical configuration mechanism.

Update your app.config to the following:

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

  <log4net>
    <appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%logger [%level]- %message%newline" />
      </layout>
    </appender>
    <appender name="FileAppender" type="log4net.Appender.FileAppender">
      <file value="log-file.txt" />
      <appendToFile value="false"/>
      <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%logger [%level]- %message%newline" />
      </layout>
    </appender>

    <root>
      <level value="ALL" />
    </root>
    <logger name="Tutorial5_Loggers">
      <level value="ALL" />
      <appender-ref ref="FileAppender" />
    </logger>
    <logger name="Tutorial5_Loggers.Program">
      <level value="ALL" />
      <appender-ref ref="ConsoleAppender" />
    </logger>
    <logger name="Tutorial5_Loggers.MyClass">
      <level value="ALL" />
    </logger>
  </log4net>
</configuration>

On line 12 we add a file appender to the mix; lines 23-33 provide configuration for specific logger objects.  Note that the logger names correspond directly to the namespace-qualified type names and namespaces from our project.  Specifically:

  • on line 23 a logger is configured specifically for the "Tutorial5_Loggers" namespace; this logger is configured to write logs to the file appender;
  • on line 27, a logger is configured for the Program class; this logger is configured to write logs to the console;
  • on line 31, a logger is configured for the MyClass class; this logger is not configured with an appender.

Compile and run, and you'll notice that:

  • the console output displays only the log statement from the Program class;
  • a "log-file.txt" file is written in the application folder, and this file contains the log statements from both the Program and MyClass types.

Now change the level value for the Tutorial5_Loggers.MyClass from ALL to OFF:

<logger name="Tutorial5_Loggers.MyClass">
  <level value="OFF" />
</logger>

Compile and run, and note that the log-file.txt file no longer contains the log statement from the MyClass object.  

This hierarchical configuration system can be incredibly useful; a common practice is to disable logging of "verbose" objects by targeting their specific type with a logging level set to OFF; another is to provide a "specific-needs" logger configured with a special appender, such as a gateway to the windows event log or a remote log viewer.  However, the system has a few caveats you need to know about:

  • appenders accumulate through the hierarchy: if the Program class and Tutorial5_Logger namespace are each configured to append to the console, any log from the Program class will show up twice in the console (once for the class logger and once for the namespace logger);
  • logger levels deeper in the hierarchy trump the shallow ones: if the Program class logging level is set to ALL and the Tutorial5_Logger namespace logging level is set to OFF, logs from the program class are still written to the appenders configured for Tutorial5_Logger.

Coming Up

The first 5 tutorials have given you some pretty heavy-hitting abilities.  Next time I'll discuss associating context to log messages, which can provide invaluable debugging information. 



Log4Net Tutorial pt 4: Layouts and Patterns

§ June 20, 2008 04:32 by beefarino |

After that rather lengthy post about common appenders, this discussion of patterns and layouts should be short and sweet.

A layout is just a template for your log messages.  Layouts are specified per-appender, and you can specify only one layout for an appender:

<appender name="ColoredConsoleAppender" type="log4net.Appender.ColoredConsoleAppender">
    <layout type="log4net.Layout.SimpleLayout" />
</appender>

We've been using the SimpleLayout in the previous tutorials.  This is the easiest layout to use and yields rather a Spartan log:

DEBUG - this is a debug message
INFO - this is an info message
WARN - this is a warn message
ERROR - this is an error message
FATAL - this is a fatal message

The PatternLayout allows you to specify a printf-style template for your log entries using a "conversion pattern," and gives you the opportunity to decorate each entry with some valuable instance data.  For instance, this configuration:

<appender name="ColoredConsoleAppender" type="log4net.Appender.ColoredConsoleAppender">
    <layout type="log4net.Layout.PatternLayout">
        <conversionPattern value="%date [%thread] %-5level %logger - %message%newline" />
    </layout>
</appender>

produces a log that appears like so:

2008-06-20 12:29:03,541 [2684] DEBUG Tutorial4.Program - this is a debug message
2008-06-20 12:29:03,556 [2684] INFO  Tutorial4.Program - this is an info message
2008-06-20 12:29:03,556 [2684] WARN  Tutorial4.Program - this is a warn message
2008-06-20 12:29:03,556 [2684] ERROR Tutorial4.Program - this is an error message
2008-06-20 12:29:03,556 [2684] FATAL Tutorial4.Program - this is a fatal message

The conversion pattern string can include literal text and the following format expressions:

expressionvalue
%appdomain the friendly name of the appdomain from which the log entry was made
%date the local datetime when the log entry was made
%exception a formatted form of the exception object in the log entry, if the entry contains an exception; otherwise, this format expression adds nothing to the log entry
%file the file name from which the log entry was made; note that using %file has a significant performance impact and I don't recommend using it
%identity the user name of the active user logging the entry; this one is less reliable than %username; note that using %identity has a significant performance impact and I don't recommend using it
%level the severity level of the log entry (DEBUG,INFO, etc)
%line the source code line number from which the log entry was made; slow
%location some rudimentary call stack information, including file name and line number at which the log entry was made; using
%logger the name of the logger making the entry; more on this in a bit
%method the name of the method in which the log entry was made; also slow
%message the log message itself (don't forget this part!)
%newline the value of Environment.NewLine
%timestamp the milliseconds between the start of the application and the time the log entry was made
%type the full typename of the object from which the log entry was made
%username the Windows identity of user making the log entry; slow
%utcdate the UTC datetime when the log entry was made
%% a percent sign (%)

This sample output is from a single log entry using a conversion pattern containing all of the format expressions above:

%appdomain: Tutorial4_LayoutsAndPatterns.vshost.exe
%date: 2008-06-20 13:04:38,020
%exception:
%file: D:\Project\Log4NetTutorial\Log4NetTutorial\Tutorial4_LayoutsAndPatterns\Program.cs
%identity:
%level: INFO
%line: 14
%location: Tutorial4_LayoutsAndPatterns.Program.Main(D:\Project\Log4NetTutorial\Log4NetTutorial\Tutorial4_LayoutsAndPatterns\Program.cs:14)
%logger: Tutorial4_LayoutsAndPatterns.Program
%method: Main
%message: this is an info message
%timestamp: 1015
%type: Tutorial4_LayoutsAndPatterns.Program
%username: MYDOMAIN\username
%utcdate: 2008-06-20 17:04:38,020
%%: %

If you want a highly structured and queryable log, then XMLLayout is for you:

<appender name="ColoredConsoleAppender" type="log4net.Appender.ColoredConsoleAppender">
      <layout type="log4net.Layout.XMLLayout" />
    </appender>

The XMLLayout produces a stream of XML elements representing individual log entries:

<log4net:event logger="Tutorial4_LayoutsAndPatterns.Program" timestamp="2008-06-20T13:17:44.2863922-04:00" level="DEBUG" thread="2156" domain="Tutorial4_LayoutsAndPatterns.vshost.exe" username="POKERTEK\jchristopher">
    <log4net:message>this is a debug message</log4net:message>
    <log4net:global-properties>
        <log4net:data name="log4net:HostName" value="nc-jchri-l-3" />
    </log4net:global-properties>
</log4net:event>
<log4net:event logger="Tutorial4_LayoutsAndPatterns.Program" timestamp="2008-06-20T13:17:44.3176424-04:00" level="INFO" thread="2156" domain="Tutorial4_LayoutsAndPatterns.vshost.exe" username="POKERTEK\jchristopher">
    <log4net:message>this is an info message</log4net:message>
    <log4net:global-properties>
        <log4net:data name="log4net:HostName" value="nc-jchri-l-3" />
    </log4net:global-properties>
</log4net:event>

A few caveats you should note regarding the XMLLayout:

  • the log will contain a flat collection XML elements, but no containing root element; this means that you have to do some fernagling to read the XML as a document;
  • each log entry will contain the username and identity values (see the table above), which are expensive to read and may have a noticable impact on application performance.

Coming Up

That rounds out a lot of our configuration discussion.  Next time I'll jump back into code and discuss logger objects, which are simply sources of log messages.  I'll show you how to organize your logging activity by object types to provide a more tractable log.



Log4Net Tutorial pt 3: Appenders

§ June 9, 2008 15:38 by beefarino |

I've discussed using XML to configure lognet, during which I briefly touched on log4net appenders.  An appender is an object that persists your log messages someplace.  In this post, I'd like to give you a quick overview of the wealth of apppenders available in log4net and show you how you can use them to direct a single log message to multiple places.

A Quick Survey

Here is a quick sampling of the appenders available in the log4net distribution:

Type NameDescription
log4net.Appender.AdoNetAppender Appender that logs to a database.
log4net.Appender.AnsiColorTerminalAppender Appends logging events to the terminal using ANSI color escape sequences.
log4net.Appender.AspNetTraceAppender Appends log events to the ASP.NET TraceContext system.
log4net.Appender.BufferingForwardingAppender Buffers events and then forwards them to attached appenders.
log4net.Appender.ColoredConsoleAppender Appends logging events to the console.
log4net.Appender.ConsoleAppender Appends logging events to the console.
log4net.Appender.DebugAppender Appends log events to the Debug system.
log4net.Appender.EventLogAppender Writes events to the system event log.
log4net.Appender.ForwardingAppender This appender forwards logging events to attached appenders.
log4net.Appender.FileAppender Appends logging events to a file.
log4net.Appender.LocalSyslogAppender Logs events to a local syslog service.
log4net.Appender.MemoryAppender Stores logging events in an array.
log4net.Appender.NetSendAppender Logs entries by sending network messages using the NetMessageBufferSend native function.
log4net.Appender.OutputDebugStringAppender Appends log events to the OutputDebugString system.
log4net.Appender.RemoteSyslogAppender Logs events to a remote syslog daemon.
log4net.Appender.RemotingAppender Delivers logging events to a remote logging sink.
log4net.Appender.RollingFileAppender Appender that rolls log files based on size or date or both.
log4net.Appender.SmtpAppender Send an e-mail when a specific logging event occurs, typically on errors or fatal errors.
log4net.Appender.SmtpPickupDirAppender Send an email when a specific logging event occurs, typically on errors or fatal errors. Rather than sending via smtp it writes a file that  another service, such as the IIS SMTP agent, can use to manage sending the messages.
log4net.Appender.TelnetAppender Appender that allows clients to connect via Telnet to receive log messages.
log4net.Appender.TraceAppender Appends log events to the Trace system.
log4net.Appender.UdpAppender Sends logging events as connectionless UDP datagrams to a remote host or multicast using the UdpClient class.

There's a lot of them, so to keep this post reasonable I'm focusing on the most basic appenders: the console appenders, debug appenders, and file appenders.  However, all of the available appenders are covered in detail in the log4net documentation if you want to learn more about them, and I'll be describing other appenders in upcoming posts as well.

ConsoleAppender and ColoredConsoleAppender

These appenders are useful only for console applications, where they provide immediate feedback during program execution.

There is one configurable aspect of the ConsoleAppender - the target property identifies what output stream to use when outputting log entries:

<appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
    <target value="Console.Error" />
    <layout type="log4net.Layout.SimpleLayout" />
</appender>

It can be either "Console.Out" (the default value if left uspecified) to use the standard output stream or "Console.Error" to use the standard error stream.  

I always favor ColoredConsoleAppender over ConsoleAppender, because the ColoredConsoleAppender will colorize the log message by its severity level.  This makes finding relevant log messages amidst the program output a lot easier.  For example, compare this output from the ConsoleAppender:

to the same output from the ColoredConsoleAppender:

The color mapping is completely configurable, as shown in this example appender configuration XML:

<appender name="ColoredConsoleAppender" type="log4net.Appender.ColoredConsoleAppender">
  <target value="Console.Error" />
  <mapping>
    <level value="FATAL" />
    <foreColor value="Red" />
    <backColor value="White" />
  </mapping>
  <mapping>
    <level value="ERROR" />
    <foreColor value="Red, HighIntensity" />
  </mapping>
  <mapping>
    <level value="WARN" />
    <foreColor value="Yellow" />
  </mapping>
  <mapping>
    <level value="INFO" />
    <foreColor value="Cyan" />
  </mapping>
  <mapping>
    <level value="DEBUG" />
    <foreColor value="Green" />
  </mapping>
  <layout type="log4net.Layout.SimpleLayout" />
</appender>

Each <mapping /> element must contain a severity level, and can also contain a <foreColor /> and/or <backColor /> element.  Color selection is limited to the following choices:

  • Blue
  • Green
  • Red
  • Yellow
  • Purple
  • Cyan
  • White

In addition, you can include "HighIntensity" in the color value to use a brighter shade of a color, as shown in the ERROR color mapping in the above configuration example.

These appenders are useful only for console-based programs.  It won't hurt anything if you try to use this appender from a UI or web application, you just won't see any of your log messages.  

DebugAppender and TraceAppender

These appenders act as adapters on the .NET System.Diagnostics.Debug and System.Diagnostics.Trace classes.  Because of this, there is very little option in their configurations; both appenders have a single configurable property named ImmediateFlush that controls whether log output is flushed to the Debug or Trace writers immediately:

<appender name="DebugAppender" type="log4net.Appender.DebugAppender">
    <immediateFlush value="true" />
    <layout type="log4net.Layout.SimpleLayout" />
</appender>

I use the DebugAppender routinely to help work problems in the debugger - the log output shows up right in the debug output window of Visual Studio.  This can be invaluable when trying to isolate race conditions or realtime effects where a breakpoint would ruin the reproducability of the issue.

I've used the TraceAppender when extending applications where custom TraceListener implementations were already in use; this allowed existing modules using log4net to adapt immediately to the proprietary TraceListeners, no code required.

FileAppender and RollingFileAppender

These appenders write log messages to files.  Their configuration is a bit more involved than the other appenders we've discussed.  A typical configuration for the FileAppender might look like this:

<appender name="FileAppender" type="log4net.Appender.FileAppender">
    <file value="log-file.txt" />
    <appendToFile value="true" />
    <encoding value="utf-8" />
    <layout type="log4net.Layout.SimpleLayout" />
</appender>

Here's a quick summary of the more common configuration attributes for the FileAppender:

  • file: the full or relative path to the log file;
  • appendToFile: boolean indicating whether the log file should be appended (true) or overwritten (false).  If false, the file overwrite occurs during log4net initialization.  If unspecified, the log file is appended;
  • immediateFlush: boolean indicating whether to flush the log file TextWriter after each log message is written.  The default is true (flush each message after its written);
  • lockingModel: allows control over the log file locking strategy.  This can be either "log4net.Appender.FileAppender+MinimalLock" to allow for loose file locking or "log4net.Appender.FileAppender+ExclusiveLock" to lock the file during program execution.  The default is the exlusive lock, and I highly recommend you stick with that lock for performance reasons.

Now that I've described the FileAppender, heed this advice:

Do not use the FileAppender, ever ever ever.  Use the RollingFileAppender instead.

The log file managed by FileAppender will be allowed to grow without bounds.  This will Tonya-Harding your application's stability when given enough time.  The RollingFileAppender provides rudimentary log file management, configurable size- or date-boxing of the log file, and limited rolling backups of the log file.

<appender name="RollingFileAppender" type="log4net.Appender.RollingFileAppender">
    <file value="log-file.txt" />
    <appendToFile value="true" />
    <rollingStyle value="Size" />
    <maxSizeRollBackups value="10" />
    <maximumFileSize value="1MB" />
    <staticLogFileName value="true" />
    <layout type="log4net.Layout.SimpleLayout" />
</appender>

There is a lot of configurability to the RollingFileAppender; in addition to the options available to the FileAppender, the RollingFileAppender includes these parameters:

  • rollingStyle: this controls how log files are "rolled," and can be one of the following values:
    • Once: the log file is rolled every time log4net is initialized (typically at application startup);
    • Size: the log file is rolled once it breaches a certain size;
    • Date: the log file is rolled based on the current date;
    • Composite: the log file is rolled based on size constraints and the current date;
  • maximumFileSize: the size cap on the log file.  This is an expression of size in the form of "#(KB|MB|GB)".  For instance, "100KB" or "10MB";
  • maxSizeRollBackups: the maximum number of rolled log file backups to maintain when rollingStyle is SIZE; when rollingStyle is COMPOSITE, this indicates the maximum number of roll-offs maintained per day; this property has no effect when rollingStyle is ONCE or DATE;
  • datePattern: the date pattern used to roll files based on date.  The value of this parameter needs to adhere to the format used by the SimpleDateFormatter class;
  • staticLogFileName: a bit of a misnomer - when true this setting indicates whether log4net should actively write logs to the configured file (log-file.txt in our example configuration) and maintain rolling backups by copy.  When false, this setting indicates that log4net will actively log to the latest roll-off file (e.g., log-file1.txt, log-file2.txt, log-file3.txt, etc);
  • countDirection: indicates how roll-off file numbering is managed.  When this parameter is >= 0, the newest log file will have the largest number; e.g., log-file.txt.5 will be newer than log-file.txt.4.  When countDirection < 0, the newest log file will have the lowest number; e.g., log-file.txt.1 will be newer than log-file.txt.2.  If unspecified, countDirection defaults to (-1);

Keep in mind that when using a file appender, the user running the logging process must have rights to create and/or modify the log file in order for log messages to be written properly.  In addition, log4net will create the log file if it does not exist, but it will not create directories in the log file path that do not already exist.  If log4net encounters a problem initializing the file appender (e.g., it cannot create the log file for security reasons), the log file will not be written but your application will continue to execute normally.

Using Multiple Appenders

With all of these appenders available, it may seem difficult to choose just one to meet your logging needs.  But why choose one when you can have as many as you want?

Using multiple appenders is a simple task of specifying each appender you need under the root logger, like so:

<root>
    <level value="ALL" />
    <appender-ref ref="DebugAppender" />
    <appender-ref ref="ColoredConsoleAppender" />
</root>

You can use as many appenders as you want; however, know that for each appender you use you will accrue some runtime overhead.  

Coming Up

You now have control over where your log messages persist.  Next time, I'll describe how you can control the format your log messages as they are written out by each appender, including how to insert context information - such as the thread id, timestamp, or user identity - into the log message automagically.

Edit Notes

07.03.2008: Theo pointed out some inaccuracies in the way I was describing the maxSizeRollBackups and countDirection properties of the RollingFileAppender, which I've attempted to correct.  Thanks, Theo!



Log4Net Tutorial pt 2: Basic XML Configuration

§ June 6, 2008 06:07 by beefarino |

Previously, I offered a quick overview of using log4net.

In this post, I'll show you how to use an XML file to configure log4net, and demonstrate some of the basic ways you can control the verbosity of your log.

Using the XML Configurator

Open Visual Studio, create a new console application, and add a reference to the log4net assembly.  Add the following code to your Main() method:

using System;

namespace Tutorial2_BasicXmlConfiguration
{
    class Program
    {
        static void Main( string[] args )
        {
            log4net.Config.XmlConfigurator.Configure();
            log4net.ILog log = log4net.LogManager.GetLogger( typeof( Program ) );

            log.Info( "beginning loop" );

            for( int c = 0; c < 100; ++c )
            {
                log.DebugFormat( "iteration #{0}", c );
            }

            log.Info( "loop has completed" );

            Console.ReadLine();            
        }
    }
}

On line 9, log4net is bootstrapped using the XmlConfigurator.  This configuration strategy relies on an XML document to supply configuration for log4net.  The static Configure method is overloaded to accept the configuration XML from a file, stream, URI, or an XmlElement object; the parameterless form of the method used here instructs log4net to load the XML from the application's configuration file.  

In addition to the Configure method, the XmlConfigurator offers a static ConfigureAndWatch() method that accepts a FileInfo reference.  ConfigureAndWatch() will monitor the configuration XML file and reconfigure log4net when a change is detected.  This allows you to alter logging behavior at whim while the application is running - very handy for troubleshooting applications in the field, but it adds overhead in the form of a FileSystemWatcher used to monitor the configuration file.

Add the following application configuration file to the console project:

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

  <log4net>
    <appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">
      <layout type="log4net.Layout.SimpleLayout" />
    </appender>

    <root>
      <level value="ALL" />
      <appender-ref ref="ConsoleAppender" />
    </root>
  </log4net>
</configuration>

There are a few important things in there.  First is the declaration of the log4net configuration section on line 3; this is mandatory.  The log4net configuration takes up lines 6-15.  There are two parts to the configuration:

  1. one or more appender declarations taking the form of <appender /> elements, and
  2. the root logger declaration, represented by the <root /> XML element.

A real discussion of appenders will have to wait; for now, suffice it to say that a log4net appender is a place where your log entries end up.  In this case, the log is being "appended" to the console.

The root logger controls the general behavior of log4net.  In this example, the root logger is told to send everything to the console appender.

Time to compile and run.  You'll get the following output:

INFO - beginning loop
DEBUG - iteration #0
DEBUG - iteration #1
DEBUG - iteration #2
DEBUG - iteration #3
DEBUG - iteration #4
DEBUG - iteration #5
DEBUG - iteration #6
DEBUG - iteration #7
DEBUG - iteration #8
DEBUG - iteration #9
DEBUG - iteration #10
DEBUG - iteration #11
DEBUG - iteration #12
DEBUG - iteration #13
DEBUG - iteration #14
DEBUG - iteration #15
DEBUG - iteration #16
DEBUG - iteration #17
DEBUG - iteration #18
DEBUG - iteration #19
DEBUG - iteration #20
DEBUG - iteration #21
DEBUG - iteration #22
DEBUG - iteration #23
DEBUG - iteration #24
DEBUG - iteration #25
DEBUG - iteration #26
DEBUG - iteration #27
DEBUG - iteration #28
DEBUG - iteration #29
DEBUG - iteration #30
DEBUG - iteration #31
DEBUG - iteration #32
DEBUG - iteration #33
DEBUG - iteration #34
DEBUG - iteration #35
DEBUG - iteration #36
DEBUG - iteration #37
DEBUG - iteration #38
DEBUG - iteration #39
DEBUG - iteration #40
DEBUG - iteration #41
DEBUG - iteration #42
DEBUG - iteration #43
DEBUG - iteration #44
DEBUG - iteration #45
DEBUG - iteration #46
DEBUG - iteration #47
DEBUG - iteration #48
DEBUG - iteration #49
DEBUG - iteration #50
DEBUG - iteration #51
DEBUG - iteration #52
DEBUG - iteration #53
DEBUG - iteration #54
DEBUG - iteration #55
DEBUG - iteration #56
DEBUG - iteration #57
DEBUG - iteration #58
DEBUG - iteration #59
DEBUG - iteration #60
DEBUG - iteration #61
DEBUG - iteration #62
DEBUG - iteration #63
DEBUG - iteration #64
DEBUG - iteration #65
DEBUG - iteration #66
DEBUG - iteration #67
DEBUG - iteration #68
DEBUG - iteration #69
DEBUG - iteration #70
DEBUG - iteration #71
DEBUG - iteration #72
DEBUG - iteration #73
DEBUG - iteration #74
DEBUG - iteration #75
DEBUG - iteration #76
DEBUG - iteration #77
DEBUG - iteration #78
DEBUG - iteration #79
DEBUG - iteration #80
DEBUG - iteration #81
DEBUG - iteration #82
DEBUG - iteration #83
DEBUG - iteration #84
DEBUG - iteration #85
DEBUG - iteration #86
DEBUG - iteration #87
DEBUG - iteration #88
DEBUG - iteration #89
DEBUG - iteration #90
DEBUG - iteration #91
DEBUG - iteration #92
DEBUG - iteration #93
DEBUG - iteration #94
DEBUG - iteration #95
DEBUG - iteration #96
DEBUG - iteration #97
DEBUG - iteration #98
DEBUG - iteration #99
INFO - loop has completed

Taming log4net Output

This example logs a fair amount of cruft.  The DEBUG-level logging inside of the loop overshadows the INFO-level logging outside of the loop.  In a real scenario, this DEBUG-level output may be necessary when troubleshooting application behavior, but it becomes a lot noise when instrumenting the application in production.

Thankfully log4net provides a filter on the logging output.  In your project's app.config, find the <level /> XML element and alter it like so:

<level value="INFO" />

Compile and run; the program log is significantly truncated:

INFO - beginning loop
INFO - loop has completed

Specifically, all DEBUG-level log entries are missing from the log output.  The level value instructs the logger of the minimum level at which log entries should be processed.  It can be one of these values:

  • ALL: all log entries are appended to the log;
  • DEBUG: Debug, Info, Warn, Error, and Fatal messages are appended to the log.  This is functionally identical to ALL;
  • INFO: Info, Warn, Error, and Fatal messages are appended to the log;
  • WARN: Warn, Error, and Fatal messages are appended to the log;
  • ERROR: Error and Fatal messages are appended to the log;
  • FATAL: only Fatal messages are appended to the log;
  • OFF: all log entries are ignored.  Logging is effectively disabled in this case.

Coming Up

You have enough knowledge at this point to do some pretty powerful things; however, there's a lot more to be had from log4net.  Next time I'll discuss the many varieties of appenders that ship with log4net, and demonstrate how log4net can funnel a single log message to multiple places.