Tags: .NET, C#, CI, DI, Tools

This blog is not about how Java is better than C# or vice versa. It's about using existing features a language offers you - every language has its own strength.

I went to London Continuous Delivery meetup a few weeks ago where Sean Reilly presented a logging library with operations in mind - opslogger. The library is created in Java and one of the questions was when it will be ported in .NET. In .NET we don't have to create a library for this purpose, we can extend existing libraries applying what C# language offers. If you’re a .NET developer then extension methods shouldn’t be new to you but if you’re an ops guy show this article to your devs.

The main idea of the library is that it does logging for operations. I really liked it and agree with the fact that people who look after our apps are left behind in terms of what to log. Although I think the logging is for both operations and developers. The first look after the performance and the behaviour and the latter came to the scene for troubleshooting.
The library is very opinionated, for example, you can't use different levels - there is just one level. You either log or you don't. There's no log rotation, and I agree with what Sean is saying that devops know how to configure it so you don't need a tool to do that. But, how about the applications you deploy on clients machines? In .NET world that will be Windows Forms and WPF applications. You need log rotation and you need different levels - you don't want to log everything every time on a client machine. Also, I like having different methods for logging: debug with some message and object to be serialized as parameters and a different method to log exception with Exception instance. For example:

Log.Debug("Request info", request);
Log.Error("Exception when executing payment", ex);

The idea I liked in the framework is that you don't log random messages but you have a set of predefined identifications plus your log message. For example, every time the application starts you log:

APP-001 Application started.

The code in the opslogger library looks like this:

logger.log(START_APP, "Application started.");

and START_APP is an enum with value "APP-0001"

 If you're a .NET developer you know we can easily implement the same approach using existing logging libraries and extension methods. We have nice logging libraries with a vast amount of features. Why should we create one just for logging specific messages? What opslogger library does is that it uses a set identification messages.

I used to use log4net in the past, but I switched to NLog. If you're still using log4net I definitely recommend to have a look at NLog. In this example I will use NLog.

I have created a sample ASP.NET MVC application to prove the idea. You can find it on github.

We're going to extend NLog with a set of predefined methods with specific messages. For example:

 public static class LoggerExtension
    {
        public static void ActionInit(this ILogger logger, string message)
        {
            logger.Debug($"APP-001 {message}");
        }
        public static void Performance(this ILogger logger, string message)
        {
            logger.Debug($"PERFORMANCE-001 {message}");
        }
    }

And we'll use it like that:

Logger.ActionInit("HomeController Index");

Have a look at log output below. You can see that it's easy to search for particular messages. Let's say you want to filter all the performance logs, in this case you use PERFORMANCE-001 tag and depending what system you use to store logging you can have a nice filter/view of the data.

2016-03-10 14:04:26.1665|DEBUG|NLogExtension.Controllers.HomeController|APP-001 HomeController Index

2016-03-10 14:04:26.1860|DEBUG|NLogExtension.Controllers.HomeController|Get all users

2016-03-10 14:04:26.8906|DEBUG|NLogExtension.Controllers.HomeController|PERFORMANCE-001 Getting users in: 700

2016-03-10 14:04:26.8946|DEBUG|NLogExtension.Controllers.HomeController|Searching for active items

2016-03-10 14:04:27.1998|DEBUG|NLogExtension.Controllers.HomeController|PERFORMANCE-001 Searching active items in: 301

2016-03-10 14:04:27.2478|DEBUG|NLogExtension.Controllers.HomeController|Sample debug message

2016-03-10 14:10:06.0037|DEBUG|NLogExtension.Controllers.HomeController|APP-001 HomeController Index

2016-03-10 14:10:06.0322|DEBUG|NLogExtension.Controllers.HomeController|Get all users

2016-03-10 14:10:06.7354|DEBUG|NLogExtension.Controllers.HomeController|PERFORMANCE-001 Getting users in: 700

2016-03-10 14:10:06.7464|DEBUG|NLogExtension.Controllers.HomeController|Searching for active items

2016-03-10 14:10:07.0559|DEBUG|NLogExtension.Controllers.HomeController|PERFORMANCE-001 Searching active items in: 300

2016-03-10 14:10:07.0559|DEBUG|NLogExtension.Controllers.HomeController|Sample debug message

2016-03-10 14:10:07.5652|DEBUG|NLogExtension.Controllers.HomeController|APP-001 HomeController About

2016-03-10 14:10:08.8938|DEBUG|NLogExtension.Controllers.HomeController|APP-001 HomeController Contact

As you can see we can achieve the same output as opslogger with any logger library we want in a very flexible way.

Comments