How To Do Logging with Caliburn.Micro

Caliburn.Micro Logging Abstraction

This post covers logging. Caliburn.Micro has a simple logging abstraction that consists of an ILog interface, and a LogManager class (see below).

To add logging to any Caliburn.Micro project, you need to implement a class that extends the ILog interface, and you need to replace the delegate for GetLog. In this post, I will show you how to hook up a debug logger that logs to the Output window in Visual Studio, a log4net logger, and an NLog logger. For other loggers, it would be a simple matter to modify these examples to support them.

As always, all of the source code for this project is located in my Github Learning Caliburn.Micro repository.

So lets get started. As with any Caliburn.Micro project, you need a new WPF project with some directories named according to the {:.float_right}convention (Views and ViewModels). See my post Caliburn.Micro – Hello World for the basics of creating a project. Now, lets switch the Target Framework from the Client Profile to just .NET Framework. This is on the Application tab for the project settings. We need to do this because the logging frameworks do not work with the Client Profile at this time.

Debug Logger

The first logger we will implement is the debug logger. The goal of this logger is output its messages to System.Diagnostics.Debug which will show up in the Visual Studio Output window. I chose to place my loggers in a ‘Utils’ directory off the main project, and creatively called it the DebugLogger. Here it is.

I also chose to ignore the Type parameter being passed in, other than to store it. Usually when I am using the debug logger, I find that the type is overkill in the message flow.

The next thing you need to do is set the delegate. I do this in a static constructor for the bootstrapper since this is called before any of the Caliburn.Micro code, or my own code is called. Here is the bootstrapper, also with a highly creative name.

Believe it or not, that’s it. Logging is now hooked up, and here is what a default run will look like.

INFO: [2010-08-08T1518.8063954-04:00] Binding System.Windows.Window+LogJam.ViewModels.ShellViewModel.
INFO: [2010-08-08T1518.8263965-04:00] Setting DC of System.Windows.Window to LogJam.ViewModels.ShellViewModel.
INFO: [2010-08-08T1518.8283966-04:00] Attaching message handler LogJam.ViewModels.ShellViewModel to System.Windows.Window.
INFO: [2010-08-08T1518.8343970-04:00] No bindable control for action CanGenerateLogMessage.
INFO: [2010-08-08T1518.8353970-04:00] Added convention action for GenerateLogMessage as GenerateLogMessage(logTypes,logMessage).
INFO: [2010-08-08T1518.8843999-04:00] No bindable control for action add_PropertyChanged.
INFO: [2010-08-08T1518.8853999-04:00] No bindable control for action remove_PropertyChanged.
INFO: [2010-08-08T1518.8864000-04:00] No bindable control for action NotifyOfPropertyChange.
INFO: [2010-08-08T1518.8874000-04:00] No bindable control for action NotifyOfPropertyChange.
INFO: [2010-08-08T1518.8884001-04:00] No bindable control for action RaisePropertyChangedEventImmediately.
INFO: [2010-08-08T1518.8884001-04:00] No bindable control for action ToString.
INFO: [2010-08-08T1518.8894001-04:00] No bindable control for action Equals.
INFO: [2010-08-08T1518.8904002-04:00] No bindable control for action GetHashCode.
INFO: [2010-08-08T1518.8904002-04:00] No bindable control for action GetType.
INFO: [2010-08-08T1518.9314025-04:00] Action: GenerateLogMessage availability update

The Caliburn.Micro framework starts using our new logging right away, and with some very useful information. Once thing to notice is that it always starts with the binding of the root view-model. You can see logging is done for some initialization tasks, binding, and of course – actions.

One last thing before moving on to the other loggers, and that is how to use the logger for your own code. Happily, just like you would any of the major logging frameworks. Just call LogManager.GetLog, and you get back a logger. Then just call Info, Warn, or Error.

private readonly ILog _log = LogManager.GetLog(typeof(ShellViewModel));

For those used to log4net and NLog, you will notice that the Caliburn.Micro ILog interface does not offer as many logging modes. If you find yourself needing those, then derive from ILog a new interface that adds those extra methods back in, and have your GetLog delegate return a class that implements it. Caliburn.Micro will still use the three methods it knows about, but you are free to use your extra methods.

Log4net Logger

log4net is the old guard of logging in the .NET community. It has probably been used in more projects than any others, and is always the first one I hear about from people when the topic of logging comes up. So, I decided that this would be the first I would implement. log4net has a few things needed to make it work, but first the logger class in which you use it.

Two more things are needed to support log4net. You need to tell it how to configure itself. I usually use the app.config model for log4net, and I place the following attribute into the AssemblyInfo.cs file.

// Configure log4net using the app.config file
[assembly: log4net.Config.XmlConfigurator(Watch = true)]

Then I add the following to app.config inside the configuration tag.

One last change, you need to tell Caliburn.Micro to use the log4net logger by modifying the line in the static constructor for bootstrapper.

LogManager.GetLog = type => new Log4netLogger(type);

At this point, log4net is hooked up and you can use it throughout your code.

NLog Logger

At this point you should have a good idea of the changes needed to implement NLog support. Here is the code.

As you can tell, almost no change from the log4net version. NLog does not need the attribute telling it where the configuration file is, since it follows a conventions based approach to finding it. In this case, I chose to configure it in app.config as well.

Last, we need to modify the bootstrapper.

LogManager.GetLog = type => new NLogLogger(type);

So that’s it for NLog. It is now ready to be used.

Caveats

I have run into two caveats while working with the Caliburn.Micro logging infrastructure that I want to share.

The first is kind of obvious, but I just want to make sure your aware, the logging is not available until after you set the LogManager.GetLog delegate to create your logger. Prior to that everything goes to the NullLogger. In my case, I create it in the bootstrapper static constructor, but this may not be early enough if you do anything in the App class before your bootstrapper is referenced. You may need to move the assignment of the delegate into the App static constructor.

The second issue I ran into is not specific to Caliburn.Micro, but to NLog. If I pass the type into the NLog LogManager.GetLogger() along with the type.Name, I end up in an infinite loop and blow up my stack frame. I am not exactly sure why this happened as I opted not to spend the time to solve it. So I am providing this caveat as a warning against doing it yourself.

Conclusion

Caliburn.Micro makes it very easy to wire up any number of logging infrastructures. I detailed three different ones here, but can be expanded to support the Microsoft Enterprise Library Logging Application Block, or some proprietary logging framework.

I will be leveraging the loggers heavily as we move forward into hooking up Autofac as the IoC, adding support for custom third-party controls, and even dealing with custom chrome windows.

As a reminder, all of the source code for this project is located in my Github Learning Caliburn.Micro repository.

Related

comments powered by Disqus