[.NET Core] Easy logging with log4net - Make logging even better

⚠ This article directly follows another one, please read this first: [.NET Core] Easy logging with log4net

In the previous guide, we created a solution with two projects:

  • Banana: The project calling the logger
  • Banana.Toolbox: The project library containing the static logger

We currently only have one logging method (.Log()) which is fine for little projects but what if I tell you that we can get more information than only the datetime, the project and the log message?

This is easy to add and we’re going to also write some more useful methods!

Adding log level

At the moment, the only log level that we have is “DEBUG”. This is the lowest level and should not be use in a production environment. We’re going to use 5 different log levels:

  • Debug: Everything that is useful only when we need to debug the application without using a debugger
  • Info: Some information that are useful even when we’re not debugging
  • Warn: Something happened, maybe something weird or something we will maybe need to take care later
  • Error: An error happened but the application can continue to live, we need to take care of this
  • Fatal: A fatal error and the application needs to stop its execution. We need to avoid this situation as much as possible.

This is how I use these different log levels but feel free to adapt it at your taste.

We now need to differentiate the log levels when the .Log() is called, let’s first create a new file in the toolbox project, logger folder: LogType.cs. This will be an enum containing the log levels:

1
2
3
4
5
6
7
8
9
10
11
12
namespace Banana.Toolbox.Logger
{
    // https://logging.apache.org/log4net/release/sdk/index.html
    public enum LogType
    {
        Debug,
        Info,
        Warn,
        Error,
        Fatal
    }
}

Then, let’s say that the default logging level is “Debug” thus we won’t have to specify everytime the log level. And as the “Debug” level should be the more used, it seems better for me like this.

In the Log method from Logger.cs, add a new parameter: LogType type with the default value LogType.Debug:

1
2
3
4
5
6
public static void Log(string message, LogType type = LogType.Debug)
{
    EnsureLogger();

    _log.Debug($"Test log: {message}");
}

Now we need to tell Log4Net that we want to use its different level. Do a switch on type and call the rights methods. Don’t forget to remove the old message test:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
public static void Log(string message, LogType type = LogType.Debug)
{
    EnsureLogger();

    switch (type)
    {
        case LogType.Fatal:
            _log.Fatal(message);
            break;
        case LogType.Error:
            _log.Error(message);
            break;
        case LogType.Warn:
            _log.Warn(message);
            break;
        case LogType.Info:
            _log.Info(message);
            break;
        case LogType.Debug:
        default:
            _log.Debug(message);
            break;
    }
}

Then, in the main program, let’s call all these log type to see what we get in the output file:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
using System;
using Banana.Toolbox.Logger;

namespace Banana
{
    class Program
    {
        static void Main(string[] args)
        {
            Console.WriteLine("Hello World!");

            Logger.Log("Message from the main program"); // Will be debug (as default)
            Logger.Log("Test INFO level", LogType.Info);
            Logger.Log("Test WARN level", LogType.Warn);
            Logger.Log("Test ERROR level", LogType.Error);
            Logger.Log("Test FATAL level", LogType.Fatal);
        }
    }
}

Here is what you should get:

Adding file name, line number and method name

This is something I find really useful when I read my log files: where does exactly come this log line from!

As C# is absolutely fantastic, we can get the “Caller” information through method attributes and this will give us what we need to add to the log. It uses C# Reflection but I never seen any slowdown even with huge amount of logging.

Let’s modify our beloved Log method to add:

  • [CallerFilePath] string path = @“C:\Unknown.cs”: The full path to the caller filename
  • [CallerLineNumber] int line = 0: The line number from the caller file
  • [CallerMemberName] string method = “” The method from the caller file

This will be optional parameters with unused default value, these should never be set when calling the Log method or this will override the real information that we need.

Don’t forget to also add these info with the message. You should get something like this:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
public static void Log(
    string message, LogType type = LogType.Debug,
    [CallerFilePath] string path = @"C:\Unknown.cs", [CallerLineNumber] int line = 0, [CallerMemberName] string method = ""
    )
{
    EnsureLogger();

    // Add the caller file information
    message = $"{path}:{line} ({method}) {message}";

    switch (type)
    {
        case LogType.Fatal:
            _log.Fatal(message);
            break;
        case LogType.Error:
            _log.Error(message);
            break;
        case LogType.Warn:
            _log.Warn(message);
            break;
        case LogType.Info:
            _log.Info(message);
            break;
        case LogType.Debug:
        default:
            _log.Debug(message);
            break;
    }
}

Let’s try this again, run the application and check the log!

This is better but… We don’t need the caller file full path. To keep everything clean, I suggest to create a new private method “PrefixLog” that will format the log message by adding it the relevant information:

1
2
3
4
5
6
private static string PrefixLog(string path, int line, string method)
{
    var file = new FileInfo(path);

    return $"{file.Name}:{line} ({method})";
}

And call it in the Log method:

1
2
// Add the caller file information
message = $"{PrefixLog(path, line, method)} {message}";

Run again and see the result in the log file:

Better! We now have everything we need to do some beautiful log files.

Bonus methods!

If like me, you have some common log lines that you want to call easily without retyping them all the time, you can add more methods to the Logger class.

First, we move the EnsureLogger() call and the switch block to another private method. If we don’t do that, in each new logging method we will need to write these lines again and… This would be really bad.

I called this method ProcessLog, it will need the log message (already prefixed and formatted) and the log level. Here is what you should have:

1
2
3
4
5
6
7
8
9
10
public static void Log(
    string message, LogType type = LogType.Debug,
    [CallerFilePath] string path = @"C:\Unknown.cs", [CallerLineNumber] int line = 0, [CallerMemberName] string method = ""
    )
{
    // Add the caller file information
    message = $"{PrefixLog(path, line, method)} {message}";

    ProcessLog(message, type);
}
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
private static void ProcessLog(string message, LogType type)
{
    EnsureLogger();

    switch (type)
    {
        case LogType.Fatal:
            _log.Fatal(message);
            break;
        case LogType.Error:
            _log.Error(message);
            break;
        case LogType.Warn:
            _log.Warn(message);
            break;
        case LogType.Info:
            _log.Info(message);
            break;
        case LogType.Debug:
        default:
            _log.Debug(message);
            break;
    }
}

If you try it now, you shouldn’t see any difference in the output file.

Now, we can add extra methods to the Logger class that will help us to gain some precious time. Here is what methods I use in every project:

  • LogIn: Called in every function, this is the first line I write everytime and I use it to know that we’ve entered a new method or function
  • LogOut: Same as above, except that this is for when we exit a method or a function.
  • LogException: When I want to log an exception message

And the code I use for these methods:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
public static void LogIn(
    string message = "",
    [CallerFilePath] string path = @"C:\Unknown.cs", [CallerLineNumber] int line = 0, [CallerMemberName] string method = "")
{
    var prefix = PrefixLog(path, line, method);

    ProcessLog($"{prefix} >>>>>>>>>> IN >>>>>>>>>>", LogType.Debug);

    // Extra message to add?
    if (!string.IsNullOrWhiteSpace(message))
        ProcessLog($"{prefix} {message}", LogType.Debug);
}

public static void LogOut(
    string message = "",
    [CallerFilePath] string path = @"C:\Unknown.cs", [CallerLineNumber] int line = 0, [CallerMemberName] string method = "")
{
    var prefix = PrefixLog(path, line, method);

    // Extra message to add?
    if (!string.IsNullOrWhiteSpace(message))
        ProcessLog($"{prefix} {message}", LogType.Debug);

    ProcessLog($"{prefix} <<<<<<<<<< OUT <<<<<<<<<<", LogType.Debug);
}

public static void LogException(
    Exception exception, LogType type = LogType.Error,
    [CallerFilePath] string path = @"C:\Unknown.cs", [CallerLineNumber] int line = 0, [CallerMemberName] string method = "")
{
    var prefix = PrefixLog(path, line, method);

    ProcessLog($"{prefix} [EXCEPTION] - Message: {exception.Message}", type);

    // Log every inner exception too
    while (exception.InnerException != null)
    {
        ProcessLog($"{prefix} [INNER EXCEPTION] - Message: {exception.Message}", type);

        exception = exception.InnerException;
    }
}

Adapt the main program file to use the new methods:

1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
static void Main(string[] args)
{
    Logger.LogIn();

    var exception =
        new Exception("Example exception",
            new Exception("Example inner exception",
                new Exception("Example inner exception 2")));

    Logger.Log("Message from the main program"); // Will be debug (as default)
    Logger.Log("Test INFO level", LogType.Info);
    Logger.Log("Test WARN level", LogType.Warn);
    Logger.Log("Test ERROR level", LogType.Error);
    Logger.Log("Test FATAL level", LogType.Fatal);

    Logger.LogException(exception);

    Logger.LogOut();
}

And the output log file will be…

You can now have a nice log file with some handful methods! Feel free to improve the Logger class with your proper code 😊

Download the example solution here: https://github.com/MayakoLyyn/Log4Net-dotnetcore