Logging .NET apps using NLog

Debugging messages, logs, can become very messy very quickly in development teams. I've decided to set up a sort of logging framework in my last team. Here is what I did.

Logging .NET apps using NLog

Debugging messages, logs, can become very messy very quickly in development teams. I've decided to set up a sort of logging framework in my last team. Here is what I did.

Nlog

I imported the nuget package NLog : https://nlog-project.org/

"NLog is a flexible and free logging platform for various .NET platforms, including .NET standard. NLog makes it easy to write to several targets. (database, file, console) and change the logging configuration on-the-fly."
- https://nlog-project.org/

See the documentation for more information : https://github.com/nlog/nlog/wiki

Supported platforms:

  • .NET Framework 3.5, 4, 4.5, 4.6 & 4.7
  • .NET Standard 1.3+ and 2.0+;
  • .NET Framework 4 client profile
  • Xamarin.Android, Xamarin.iOS, Xamarin.Forms
  • UWP
  • Windows Phone 8
  • Silverlight 4 and 5
  • Mono 4

For ASP.NET Core, check: https://www.nuget.org/packages/NLog.Web.AspNetCore

Initialisation

First we need to initialise NLog. Here is my initialisation method :

private static Logger _logger; //NLog logger

public static void Initialize()
{
    _logger = LogManager.GetLogger("Default") ?? LogManager.GetCurrentClassLogger();
    var config = new NLog.Config.LoggingConfiguration();
    var logFile = new NLog.Targets.FileTarget()
    {
        FileName = "nlog.log",
        Name = "logfile",
        Layout = "${level:upperCase=true}:${message}${exception:format=ToString}"
    };
    var logConsole = new NLog.Targets.ColoredConsoleTarget()
    {
        Name = "logconsole",
        Layout = "${level:upperCase=true}:${message}"
     };

     config.LoggingRules.Add(new NLog.Config.LoggingRule("*", LogLevel.Trace, logConsole));
     config.LoggingRules.Add(new NLog.Config.LoggingRule("*", LogLevel.Debug, logFile));

     LogManager.Configuration = config;
     typeof(Logging).Trace($"Logging started. Log file: {logFile.FileName}");
}

You need to call it as soon as your app is ready, in the Program.Main(); AppDelegate.FinishedLaunching(); for Xamarin.iOS or MainActivity.OnCreate(); for Xamarin.Android.

LoggingHelper.Initialize();

Extension methods

You might ask why the Initialisation method is a static method. Simply because I've put it in a static class in order to define extension methods.

Pros

  • Accessible from every class of the project without having to create huge inheritance tree (core object that all objects would need to inherit from)
  • Passes class, method and line of the caller to the logging system automatically through System.Runtime.CompilerServices

Cons

  • Does not exist on a static class or in a static method. It needs a this. See the workaround below.

BuildLogLine function

The function BuildLogLine is where the concatenation happens. Feel free to tweak it. You can add the app's uptime, the file line etc.

private static string BuildLogLine<T>(T caller, string message = "", string callerFunction = "")
{
    StringBuilder sb = new StringBuilder();

    var type = caller as Type;
    var callerName = (type != null ? type : caller.GetType()).Name;
    sb.Append($@" {callerName}");

    if (!String.IsNullOrWhiteSpace(callerFunction))
        sb.Append($@".{callerFunction}");

    if (!String.IsNullOrWhiteSpace(message))
        sb.Append($@": {message}");

    return sb.ToString();
}

Code here : Logging.cs

Usage

Regular usage

// this.Info, this.Trace and this.Warn can be used at any point in the code.
this.Info("For your information, this is happening right now");
this.Trace("Here is some raw data I received at this point : { 'name': 'yolo' }");
this.Warn("I don't like this, something weird happened ...");

Static classes and functions

public static class MyStaticClass
{
    public static void MyStaticFunction()
    {
        // Since the keyword "this" is not available in a static context we need to use a ruse.
        // Types are objects, a static class may not have an instance but it has a type !
        typeof(MyStaticClass).Info("For your information, this is happening right now");
        typeof(MyStaticClass).Trace("Here is some raw data I received at this point : { 'name': 'yolo' }");
        typeof(MyStaticClass).Warn("I don't like this, something weird happened ...");
    }
}

Errors and Exceptions

try
{
    myObject.MyMethod(); // throws an exception
}
catch (Exception ex)
{
    // this.Warn can take an exception parameter too.
    // This is useful for logging predictable/expected exceptions.
    typeof(Program).Warn("I knew something had happened !", ex);

    // this.Error always needs an exception.
    // This forces all developers to handle errors with exceptions.
    typeof(Program).Error("Something definitely broke there", ex);
}

Output

A file "nlog.log" has been created with only Info, Warn and Error. This is on purpose so if you save this log on a mobile device and send it (crash report) afterward it's not polluted with Traces.

INFO: MyClass.MyMethod: For your information, this is happening right now
WARN: MyClass.MyMethod: I don't like this, something weird happened ...

WARN: Program.Main: I knew something had happened !
System.Exception: Nope
   at LoggingDemo.MyClass.ThrowException() in /Users/framinosona/Projects/LoggingDemo/MyClass.cs:line 22
   at LoggingDemo.Program.Main(String[] args) in /Users/framinosona/Projects/LoggingDemo/Program.cs:line 20
ERROR: Program.Main: Something definitely broke there
System.Exception: Nope
   at LoggingDemo.MyClass.ThrowException() in /Users/framinosona/Projects/LoggingDemo/MyClass.cs:line 22
   at LoggingDemo.Program.Main(String[] args) in /Users/framinosona/Projects/LoggingDemo/Program.cs:line 20

INFO: MyStaticClass.MyStaticFunction: For your information, this is happening right now
WARN: MyStaticClass.MyStaticFunction: I don't like this, something weird happened ...

And the terminal is more detailed, for debugging purposes :

TRACE: LoggingHelper.Initialize: Logging started. Log file: 'nlog.log'

INFO: MyClass.MyMethod: For your information, this is happening right now
TRACE: MyClass.MyMethod: Here is some raw data I received at this point : { 'name': 'yolo' }
WARN: MyClass.MyMethod: I don't like this, something weird happened ...

TRACE: MyClass.MyMethod

WARN: Program.Main: I knew something had happened !
ERROR: Program.Main: Something definitely broke there

INFO: MyStaticClass.MyStaticFunction: For your information, this is happening right now
TRACE: MyStaticClass.MyStaticFunction: Here is some raw data I received at this point : { 'name': 'yolo' }
WARN: MyStaticClass.MyStaticFunction: I don't like this, something weird happened ...

Here is the full Gist : https://gist.github.com/framinosona/a0eadd93888f84f50a925b1e79b588a8

Tell me if this was helpful ! 👍