Using Caller Context with Microsoft Logging

Here are the CallerContext and ILoggerExtension class. They allow the compiler special Caller member attributes to be logged during logging. I believe this to be of enormous benefit when trying to fix bugs in the field.

using System.Runtime.CompilerServices;

/// <summary>
/// A class to record the context of a method call.
/// Records the member name, file and line number of where the method call was made.
/// </summary>
public record CallerContext
{
    public CallerContext(
        [CallerMemberName] string memberName = "",
        [CallerFilePath] string sourceFilePath = "",
        [CallerLineNumber] int sourceLineNumber = 0)
    {
        MemberName = memberName;
        FilePath = sourceFilePath;
        LineNumber = sourceLineNumber;
    }
    
    public static CallerContext Create(
        [CallerMemberName] string memberName = "",
        [CallerFilePath] string sourceFilePath = "",
        [CallerLineNumber] int sourceLineNumber = 0)
    {
        return new CallerContext(memberName, sourceFilePath, sourceLineNumber);
    }

    /// <summary>
    /// Member where the call was made
    /// </summary>
    public string MemberName { get; init; }
    /// <summary>
    /// File where the call was made
    /// </summary>
    public string FilePath { get; init; }
    /// <summary>
    /// Line number in the file where the call was made
    /// </summary>
    public int LineNumber { get; init; }
}

/// <summary>
/// ILogger extensions
/// </summary>
public static class ILoggerExt
{
    /// <summary>
    /// Log something but with extra Caller context information <seealso cref="CallerContext"/>
    /// </summary>
    /// <param name="logger">ILogger being invoked</param>
    /// <param name="logLevel">Level of the logging</param>
    /// <param name="context">The caller context <see cref="CallerContext"/></param>
    /// <param name="message">The message to log</param>
    /// <param name="args">The message parameters to log.</param>
    public static void Log(this ILogger logger,
        LogLevel logLevel,
        CallerContext context,
        string message,
        params object[] args)
    {
        Debug.Assert(logger != null, "trying to use a null logger to log something");
        var enhancedMessage = "{@CallerContext} "  + (message ?? "");

        Debug.Assert(args != null, "args cannot be null");

        object[] newArgs = new object[args.Length + 1];
        newArgs[0] = context; // Prepend the context argument
        // Drawback: Could this cause a slowdown in logging over a long period ?
        Array.Copy(args, sourceIndex: 0, newArgs, destinationIndex:1, args.Length); // add the other arguments

        logger.Log(logLevel, enhancedMessage, newArgs.ToArray());
    }
}

Example Usage

ILogger logger = ...
logger.Log(new CallerContext(), LogLevel.Info, "Message with {@parameters} goes here", parameters);
// OR
logger.Log(CallerContext.Create(), LogLevel.Info, "Message with {@parameters} goes here", parameters); // I prefer this one

Getting the Current Method Name

[Test]
public void CurrentMethodNameExperiments()
{
    var method1 = MethodBase.GetCurrentMethod().DeclaringType +
                  "." + MethodBase.GetCurrentMethod().Name + "()";
    var method2 = MethodBase.GetCurrentMethod().ToString();
    var method3 = GetMethodName();
    Debug.WriteLine("Method 1: MethodBase.GetCurrentMethod().DeclaringType + " + 
        "MethodBase.GetCurrentMethod().Name");
    Debug.WriteLine("Method 2: MethodBase.GetCurrentMethod().ToString()");
    Debug.WriteLine("Method 3: Using attributes");
    Debug.WriteLine();
    Debug.WriteLine("Method 1: " + method1);
    Debug.WriteLine("Method 2: " + method2);
    Debug.WriteLine("Method 3: " + method3);
}


public string GetMethodName(
                    [CallerMemberName] string memberName = "",
                    [CallerFilePath] string sourceFilePath = "",
                    [CallerLineNumber] int sourceLineNumber = 0)
{
    string result = memberName + "() in file \"" + sourceFilePath + 
                "\" (" + sourceLineNumber + ")";
    return result;
}

Output looks like this:

Method 1: MethodBase.GetCurrentMethod().DeclaringType + MethodBase.GetCurrentMethod().Name
Method 2: MethodBase.GetCurrentMethod().ToString() 
Method 3: Using attributes
 
Method 1: ClassLibrary1.Tests.CurrentMethodNameExperiments()
Method 2: Void CurrentMethodNameExperiments()
Method 3: CurrentMethodNameExperiments() in file "...\Tests.cs" (49)

Simple Logger using Caller Info Attributes

Since .NET 4.5 There are 3 caller info attributes that are filled in at compile time by the compiler CallerMemberName, CallerFilePath, and CallerLineNumber These strings are inserted at compile time so they are much faster than using reflection.

Here is an example of how to use it to make the simplest logger (only 1 method + 1 property):

using System.Runtime.CompilerServices;

public enum LoggingLevelEnum
{
    Debug = 1,
    Info = 2,
    Warning = 3,
    Error = 4,
    Fatal = 5
}

public interface ISimpleLogger
{
    LoggingLevelEnum LoggingLevel { get; set; }

    void Log(
        Func<string> message,
        LoggingLevelEnum level = LoggingLevelEnum.Debug,
        [CallerMemberName] string member = "",
        [CallerFilePath] string file = "",
        [CallerLineNumber] int line = -1)
}

public class SimpleLogger : ISimpleLogger
{
    public LoggingLevelEnum LoggingLevel { get; set; } = 
        LoggingLevelEnum.Debug;

    public void Log(
        Func<string> message,
        LoggingLevelEnum level = LoggingLevelEnum.Debug,
        [CallerMemberName] string member = "",
        [CallerFilePath] string file = "",
        [CallerLineNumber] int line = -1)
    {
        if (level >= LoggingLevel)
        {
            Trace.WriteLine($"{level.ToString().ToUpper()} Member: {member}, File: {file}, Line: {line} - {message()}");
        }
    }
}

and invoking it:

ISimpleLogger logger = new SimpleLogger();
...
catch(Exception ex)
{
  // The attributed parameters are inserted by the compiler at compile time
  logger.Log(() => { return " Exception caught " + ex.ToString(); }, LogLevelEnum.Error); 
}

Note: Why log using a function returning a string? So that if you have a complex expression for creating the message, it only gets evaluated if the logging level is sufficient. If there is a lot of logging and the logging level is high, it saves a lot of unecessary string concatenation occurring.