Logging: Log4Net – Part III

By DimitriC at April 27, 2010 11:48
Filed Under: Programming, tools & Utilities

The idea in Part III is to talk about the more advanced features/settings of Log4Net.

 

First of all, in Part II we saw how we can load the log4net configuration from code by first creating a logger object and then reading the App.config file. You can also use the AssemblyInfo file to do this:

 

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

 

The Watch-flag will tell log4net to keep an eye on the configuration file and reload it every time it has changed. Of course you can also specify your own configuration file by using the ConfigFile property:

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

 

There is also a parameter you can use if you want to load configuration files based on the extension of the file. Do not that the name of the configuration file must be [NameOfYourApp].[ExtensionYouWant]. In my sample application, in the build output, it needs to be Log4NetSample.exe.log4net before I can use the following line in my AssemblyInfo.cs file. This property cannot be used in conjunction with the ConfigFile property.

 

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

 

Do note that this attribute can only be used once per assembly. Also note that these attributes are passive, meaning that as long as your application doesn’t need logging, they won’t be read. It is therefore recommended to make a simple call to LogManager.GetLogger() to read and process the attributes(for example: an informational log-statement saying the application has started). And on recommendation of the log4net-people themselves:

 

Therefore it is imperative to make a logging call as early as possible during the application start-up, and certainly before any external assemblies have been loaded and invoked.

 

There is another way to load a configuration file. You can do this by using the DOMConfigurator located in the log4net.Config class. The DOMConfigurator takes a FileInfo parameter. Using this does exactly the same thing as loading a file using an attribute in the AssemblyInfo. Two methods are provided: Configure(…) and ConfigureAndWatch(…).

 

log4net.Config.DOMConfigurator.Configure(new FileInfo("Log4netSample.exe.config"));

log4net.Config.DOMConfigurator.ConfigureAndWatch(new FileInfo("Log4netSample.exe.config"));

 

 

Threading and Log4net

Since Log4net is thread-safe, you can use it in your multithreaded applications. Next to all the logging information described in the Part II you can also let log4net know on which thread your application has thrown an exception. If your application/component is accessed by multiple clients (which can also be other components), you would like to know what client caused the exception to fire. To get all this information, log4net uses a context. Since debugging a multithreaded application is really hard and inconvenient, logging can give you all the information you need to research an error. Contextual information can be contained in different scopes:

 

- Global (shared by all threads in the current AppDomain)

- Thread (visible only to the current managed thread)

- Logical Thread (a logical thread can jump from one managed thread to another)

- Event (only visible to the code generating the event itself)

 

This information can also be found on the log4net web site.

 

To support logging on multithreaded applications, Log4net provides a ThreadContext. This has a properties map (formerly the Mapped Diagnostic Context or MDC, which has been deprecated) and a stack (formerly the Nested Diagnostic Context or NDC, which has also been deprecated). The use of a context is very interesting when dealing with client server architectures. Here the typical configuration is that you have many clients and only a few servers. Each client will be served by a thread on a server.

 

The properties map (Mapped Diagnostic Context)

 

The properties map allows you to store thread-specific information. In the configuration file, you can access these properties and add them in the PatternLayout-section. For example, let’s say you want to register who’s thread is causing an exception, you can add the username to the log by first inserting it as a property in the context:

 

   1: ThreadContext.Properties["user"] = System.Security.Principal.WindowsIdentity.GetCurrent().Name;

 

You can show it in the logging output by adapting the PatternLayout-section and calling the user-property in the App.config file:

 

<layout type="log4net.Layout.PatternLayout">

             <conversionPattern value="%date %-5level %logger (User: %property{user}): %message%newline" />

</layout>

 

Now, where is this information stored? As previously mentioned, the Mapped Diagnostic Context is deprecated and has been replaced with the Properties-collection. Keep in mind that when inserting your properties to this collection will override any properties with the same name in the GlobalContext class. Here is where all the global debugging information is stored. When your properties are read for use in the log-output (so when using the PatternLayout), they are read from the GlobalContext.

 

 

 

The stacks (Nested Diagnostic Context)

 

As the name might give away, this is a stack implementation. Meaning, you can push a stamp (which is preferably something unique like a clientID/ServerID/user/machine name/… or a combination of these kinds of information) on the stack and every log call (whether it’s a informational, error or warning call) is marked with the stamp you provided. This will ensure you that you can recognize the entries in the log by the stamps attached to it. And just like with the properties map, you can add the stamp to the log output by configuring the PatternLayout, and this time using the ndc-property to include the stamp to the message:

 

<layout type="log4net.Layout.PatternLayout">

                  <conversionPattern value="%date %-5level %logger %ndc : %message%newline" />

</layout>

 

You can add messages to the stack in two ways. These are actually the same, but syntactically different.  You can either first push your stamp to the stack, then log what you need to log and pop the messages back from the stack.

   1: ThreadContext.Stacks["NDC"].Push("RecognizableStampOnNDCStack")
   2: ...
   3: log.ERROR("something went wrong");
   4: ThreadContext.Stacks["NDC"].Pop();

Or you can accomplish the same behavior with a using-statement. At the end of the using-statement, the Pop()-method is called automatically.

   1: using (ThreadContext.Stacks["NDC"].Push("RecognizableStampOnNDCStack"))
   2: {
   3:     ...
   4:     log.Error("something went wrong");
   5: }

 

Hierarchical logging

 

You can define a hierarchy of logging. This means you first define a default level of logging and every definition of logging that is placed after it, gives a more narrowing definition. For example:

 

<root>
<level value="ERROR" />
</root>
<logger name="MyAssembly">
	<level value="WARN" />
</logger>

 

This piece of XML in the configuration file (placed inside the log4net-tags) will ensure that every error in your application is logged and all the warnings in the MyAssembly-namespace too. In the name property you can also provide a class name. If the name in the example above would be “MyAssembly.MyClass”, then all the warnings in MyClass will be logged.

Pingbacks and trackbacks (1)+

Comments are closed