[Logging] A source generator with support for Caller Information attributes

[EricEzaM]

A logging system I have inherited uses [CallerMemberName], [CallerFilePath] and [CallerLineNumber] on every log method (LogInfo, LogWarn, etc). This information is then passed to the log formatter and can be used as required.

I am looking to switch to using the built-in Microsoft ILogger for my logging, but it is difficult to get this functionality due to the fact the log methods use params object[] parameters to pass in values to the message template. The [LoggerMessage] source generator offers a solution to this issue (as well as offering many other benefits I would like to have) as I can add the caller information properties to the end of each log method, e.g.

[LoggerMessage(...)]
public static partial void LogSomething(this ILogger logger, int someParameter,
    [CallerMemberName] string cmn = "", [CallerFilePath] string cfp = "", [CallerLineNumber] int cln = 0);

The issue now is that the message template in the LoggerMessageAttribute constructor arguments would need to include the format for the caller information, which I want to avoid. Rather, the caller information should be added as properties to some context (or scope) that is then later made available to the logger format engine. It can then be used however I like - e.g. a property of a log in a structured log viewer like grafana, or just used in a template when writing to a file.

Now, obviously I could just write a whole new source generator that is based on the Microsoft source generator, but that does have some drawbacks. I would lose the ability to make use of future features added to the source generator, I would increase the amount of code to maintain, etc.

So before I set off writing my own source generator, I am putting the question out there: is it possible to get caller information into the state of a log event without writing a custom logging generator?

I am also aware it does not seem to be common to use these for logging, but in this case it is safe to expose this information in logs and also quite helpful for debugging. It may be removed in the future but for now it is desired as for the initial change I am seeing full feature parity with the current logger.

[dariusclay]

Like you mentioned you can do this manually by doing something like:

[LoggerMessage(...)]
public static partial void LogSomething(this ILogger logger, int someParameter,
    [CallerMemberName] string cmn = "", [CallerFilePath] string cfp = "", [CallerLineNumber] int cln = 0);

This would put the values in the state without the need to modify the message template. However, you would need to do this for every source generated log message.

I do agree this seems like a valid API proposal. Do you have any requirements other than the caller information be included in the log state? IMO this should be OPT-IN only and not default behavior.

[EricEzaM]

Ah ok, so the unused parameters still get put into the state. Obvious now, but I did not initially realise that.

For my use case

Currently I am using a custom ILoggerProvider and ILogger as an adapter that simply passes messages to the old logging system. This way ILogger usage can be used in new code without having to re-write the entire existing logging system. That will be done later, after which the 'adapter' logger can be removed.

For the implementation of ILogger.Log<TState> on the custom Logger class, I could loop through the properties on the state and find the caller info properties, after which they could be passed to the old logging system log methods:

string callerMemberName = "";
string callerFilePath = "";
int callerLineNumber = 0;

if (state is IEnumerable<KeyValuePair<string, object>> stateProperties)
{
    foreach ((string key, object value) in stateProperties)
    {
        switch (key)
        {
            case "cmn":
                callerMemberName = value.ToString();
                break;
            case "cfp":
                callerFilePath = value.ToString();
                break;
            case "cln" when value is int clnInt:
                callerLineNumber = clnInt;
                break;
        }
    }
}

// Later...
OldLoggerSystem.LogInfo(message, callerMemberName, callerFilePath, callerLineNumber);

It seems this is similar to how Serilog adds additional properties from the log state: https://github.com/serilog/serilog-extensions-logging/blob/dev/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs

For a general use case

It seems that will work for a general use case too, for those using Serilog or NLog as their logging provider (and possibly others). Both of these libraries support adding properties to the log event based on the values inside state if it is IEnumerable<KeyValuePair<string, object>>. I'm not sure if there is any benefit to having these in a BeginScope instead, but if there is, the logger generator could create a scope for unused properties instead.

[LoggerMessage(..., "Log: {someParameter}", UnusedParametersAddedToScope = true)] // cmn, cfp, cln are unused in the template
public static partial void LogSomething(this ILogger logger, int someParameter,
    [CallerMemberName] string cmn = "", [CallerFilePath] string cfp = "", [CallerLineNumber] int cln = 0);

// In the generated code...
if (logger.IsEnabled(...))
{
    // The source generator would determine which properties were unused in the template (this already happens for the diagnostic generation)
    Dictionary<string, object> scopeProperties = new()
    {
        "cfp" = cfp,
        "cmn" = cmn,
        "cln" = cln
    };

    using (logger.BeginScope(scopeProperties))
    {
        logger.Log(...); // Same call as existing generator
    }
}

Logging libraries seem to support either method:

• NLog has layout renderers that can access the properties:
  • From BeginScope: https://github.com/NLog/NLog.Extensions.Logging/wiki/NLog-properties-with-Microsoft-Extension-Logging#beginscope
  • From state: https://github.com/NLog/NLog.Extensions.Logging/wiki/NLog-properties-with-Microsoft-Extension-Logging#logtstate-simple
• Serilog
  • Enrich from log context will include properties from BeginScope: https://github.com/serilog/serilog-extensions-logging?tab=readme-ov-file#notes-on-log-scopes
  • SerilogLogger loops through the state if it is IEnumerable<KeyValuePair<string, object>> and adds the values to the log event as properties: https://github.com/serilog/serilog-extensions-logging/blob/1549fe56d281658d70d1d643745907c0f125e332/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs#L94-L117
• MS Docs suggest using an IEnumerable<KeyValuePair<string, object>> as the state passed to BeginScope to include additional properties: https://learn.microsoft.com/en-us/dotnet/core/extensions/logging?tabs=command-line#log-scopes

So it seems all I really need is to disable SYSLIB1015: Argument '<arg>' is not referenced from the logging message for the CallerInfo parameters.

If there was some way to automatically include the CallerInfo attributes without having to manually specify them on the method, that would be awesome, but I don't think there is anyway of doing that in a good way. (I did think about doing this in a way that the user actually declares a method private static void _LogSomething(int parameter) and then we source generate the entire public method, including the ILogger parameter and the CallerInfo attribute parameters, but that seems like quite a bad idea as you couldn't 'find usages' of that private method to see where the log is used)