There are various of logging solutions in general and specifically for .net. One of my favorite solutions is log4net, the .net port of log4j. I like the fact that log4net is free, supports multiple loggers, supports multiple log target types (“appenders”), supports multi-threaded scenarios, does not seem to affect performance and is usually easy to use.
However, I noticed that usually at new projects, despite reusing log4net over and over, I have a hard time making it actually log something at first run. The thing is that log4net doesn’t seem to report any configuration issues, so it’s like a trial and error till you get it right.
One other thing that I find missing in log4net, is a good real-time log viewer. Although you can always refresh your log table results in the db, or reopen the log file, there’s nothing like having a good viewer which displays the results at run-time. After searching for solutions, I found Log2Console which is free and fantastic. Log2Console supports various logging solutions and not only log4net, so it can be considered an all-around worthy log viewer.
In this post I’ll attempt to help with a quick “first time” successful log4net logging, and putting Log2Console to work.
Setting up log4net depends on writing a valid configuration file. Unfortunately, if you get just a little of it wrong, you may end up wondering why your messages are not logged. This is the configuration file we’ll start with:
- Lines 3-5 is the standard configSections for declaring custom configurations.
- Lines 6-30 is the log4net configuration (which can reside in a different configuration file).
- Lines 7-22 defines a RollingFileAppender which indicates that log messages should be written to a series of log files (you can read about the different Appenders and their configurations here).
- Lines 23-26 define a logger, which uses the RollingFileAppender defined in lines 7-22.
- Lines 27-29 defines the default behavior of the loggers.
And now for the Logger wrapper class. Note on this: you may ask yourself why you need a wrapper class for a logger. Well, you don’t have to write a logger wrapper class, but you probably should. First and foremost, if wrapped, 3rd party components may be quite easily replaced. Let me explain: 3rd party components or www web services should usually be treated as candidates for replacement with alternatives. Think about it. Say you’re using a web service to retrieve currency exchange rate, but the service becomes unavailable. You need an alternative. If your code uses this web service directly from various locations, you’ll have a hard time to replace all occurrences. However, if you wrap the web service with your own code, you’ll only have a particular class or method to replace. Same goes for other 3rd party components, such as a Logger. If you use log4net as your logger, you might consider replacing it some day with an alternate Logger. While this might be unlikely, I still consider this a good practice (BTW: this can be a considered a good practice for your own code too, and not only for 3rd party components).
If you’re still not convinced, then you should always remember that a wrapper class may provide more functionality then just “wrapping”. For example, a wrapper class may add additional information to the messages being logged, determine when messages should and should not be logged, broadcast log messages not via your logging choice etc. Here is a basic logger wrapper class which will be extended a little later on:
- Line 7 declares a reference to the logger defined in the configuration file (“MyProj”).
- Line 9 is one way to have log4net read it’s configuration file.
- Lines 11-34 represent wrapper methods to the log4net’s logging methods.
- Note that I used the Format methods of log4net, which perform a string.Format on the given variables.
If you run the code & configuration above, you’re supposed to end up with a log file in your bin\debug folder.
I’ll extend the LoggerWrapper class later on, but first we’ll discuss Log2Console. The thing is that log4net doesn’t come with a viewer. This figures, considering that appender may logs to a various locations. However, if you do require a “real-time” viewer, there isn’t one built-in. Naturally, in production environments which are stable, logs usually serve as as “black box” in case of errors. But on development workstations, or a new production environment being set up, there is a great value in seeing the logs in real time. Therefore, I was looking for a solution to this – either by viewing one of the logging targets “post logging”, or by having an appender provide real time information, which is how Log2Console works.
Log2Console works with the RemotingAppender. This is great, because there’s no need for a new custom sync. Log2Console “listens” to messages logged using the RemotingAppender and displays them in real time. Here is how to configure a RemotingAppender which will send messages to Log2Console:
- Lines 23-27 configure the RemotingAppender to log messages over tcp port number 7070. This example is based on the sample configuration.
- Line 31 wires the RemotingAppender to MyProj logger.
Download and install Log2Console from codeplex. All that remains is to configure Log2Console to listen to those RemotingAppender messages. Run Log2Console and click on the “Receivers” button:
This will open a simple dialog, from which you can add listeners (“Receivers”). Click “Add” and select “.NET Remoting”:
This creates a receiver with defaults, and even shows a configuration sample:
That’s about. I added several messages in different log levels, just to demonstrates a possible output:
Extending the LoggerWrapper class
Log the method name:
As mentioned earlier, a LoggerWrapper class not only provides the capability to change the logger, but to add functionality. I usually add two things to my logger wrapping class: Log the name of the calling method and add support for logging Exceptions.
As you can see, the class name and method name is concatenated to the actual message. True, you can add more custom logging fields in log4net, but it’s quite comfortable to have the method name embedded in the message. Besides, I’m uncertain if you can add custom fields to Log2Console that can show up in the immediate List View.
Logging the name of the method might be considered expensive, so you may want to use threading, an on/off switch which will determine if this method name detection is enabled, limit the method name logging to certain levels (say Warning or above), or skip it altogether. Personally, I like to log the method name always, and I have not witnessed any performance issue with it.
Logging the method name is based on the StackTrace class, which is a .NET built-in class. The StackTrace provides the calling methods listed from last to first, so we have to skip the Logger Wrapper methods in order to retrieve the correct method name. For example, if we were to take the first method name from the stack trace, it would be WrapMessage (line 17 below). Obviously, this isn’t what we want. So we can either detect programmatically how many method names we have to skip (this should be done only once, of course); or, we can simply hard code this value, assuming that the logger wrapper class method nesting hardly ever changes (line 10 below).
UPDATE: In the oncoming C# 5 there are going to be new CallerInfo Attributes which use optional arguments to provide the calling File path, Method name and Line number, so WrapMessage could use those new attributes instead of using the StackTrace. Unfortunately, it doesn’t seem to be providing the class name which originated the call. You can read about it here.
- Line 10 contains the number of stack frames to skip (i.e. how many method names to skip in order to return the correct method name).
- Lines 17-23 is a private method which performs the actual method name concatenation, regardless of the log level. The format of the message in this example consists of the class name, the method name, and the actual message.
- Line 41 demonstrates how the call to WrapMessage is made, from within the Debug wrapper method. This should be used in all requested logging methods (remember that this can be changed to support only certain log level types, as desired).
I guess that there’s no argument that in most cases Exceptions that are handled should be logged. So, I usually add a PublishException method to my LoggerWrapper class. The argument is usually the exception being logged, but I also return that same Exception as a return value, so you can rethrow it in a single statement, like so:
And the PublishException method is as follows:
- Line 91 returns the base exception, which is the inner most exception (i.e. the root of all trouble). You may decide that you don’t want to do this automatically, and the calling code is responsible to whatever exception should be logged.
- Line 92 logs the message and stack trace of the exception as an Error.
- Line 93 returns the exception so that it can be rethrown (if you do not retain the original exception, the base exception will be returned). Note: you don’t have to rethrow the exception.
One other method I recently added to the Logger Wrapper class, allowed me to create, log and rethrow an exception in the same line of calling code. After all, if we decide to throw an exception ourselves, we might as well log it in the same time. So, instead of the following cumbersome code:
I’d rather do this, which is much more neat and clean:
And the code:
log4net can provide a quick logging solution, whereas Log2Console provides a real-time viewer. There is much more to log4net than covered in this blog post, such as different appenders support, custom fields, threading support and more. You can read all about it in the documentation.