Logging-Generator doesn't use LoggerMessage.Define for > 1 template argument

[gfoidl]

If the template has one argument, then (as expected) LoggerMessage.Define use used. But for > 1 argument it emits the struct-based code.

For the tests I used

<PackageReference Include="Microsoft.Extensions.Logging" Version="6.0.0-preview.4.21216.3" />

Repro:

public static partial class Log
{
    [LoggerMessage(EventId = 1, Level = LogLevel.Information, Message = "Hello {Name}")]
    public static partial void Greet(this ILogger logger, string name);

    [LoggerMessage(EventId = 2, Level = LogLevel.Information, Message = "Hello {Name} from {City}")]
    public static partial void GreetWithCity(this ILogger logger, string name, string city);
}

Generated code

// <auto-generated/>
#nullable enable

    partial class Log 
    {
        [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "6.0.0.0")]
        private static readonly global::System.Action<global::Microsoft.Extensions.Logging.ILogger, global::System.String, global::System.Exception?> __GreetCallback =
            global::Microsoft.Extensions.Logging.LoggerMessage.Define<global::System.String>(global::Microsoft.Extensions.Logging.LogLevel.Information, new global::Microsoft.Extensions.Logging.EventId(1, nameof(Greet)), "Hello {Name}", true); 

        [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "6.0.0.0")]
        public static partial void Greet(this global::Microsoft.Extensions.Logging.ILogger logger, global::System.String name)
        {
            if (logger.IsEnabled(global::Microsoft.Extensions.Logging.LogLevel.Information))
            {
                __GreetCallback(logger, name, null);
            }
        }
        [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "6.0.0.0")]
        private readonly struct __GreetWithCityStruct : global::System.Collections.Generic.IReadOnlyList<global::System.Collections.Generic.KeyValuePair<string, object?>>
        {
            private readonly global::System.String _name;
            private readonly global::System.String _city;

            public __GreetWithCityStruct(global::System.String name, global::System.String city)
            {
                this._name = name;
                this._city = city;

            }

            public override string ToString()
            {
                var Name = this._name;
                var City = this._city;

                return $"Hello {Name} from {City}";
            }

            public static string Format(__GreetWithCityStruct state, global::System.Exception? ex) => state.ToString();

            public int Count => 3;

            public global::System.Collections.Generic.KeyValuePair<string, object?> this[int index]
            {
                get => index switch
                {
                    0 => new global::System.Collections.Generic.KeyValuePair<string, object?>("Name", this._name),
                    1 => new global::System.Collections.Generic.KeyValuePair<string, object?>("City", this._city),
                    2 => new global::System.Collections.Generic.KeyValuePair<string, object?>("{OriginalFormat}", "Hello {Name} from {City}"),

                    _ => throw new global::System.IndexOutOfRangeException(nameof(index)),  // return the same exception LoggerMessage.Define returns in this case
                };
            }

            public global::System.Collections.Generic.IEnumerator<global::System.Collections.Generic.KeyValuePair<string, object?>> GetEnumerator()
            {
                for (int i = 0; i < 3; i++)
                {
                    yield return this[i];
                }
            }

            global::System.Collections.IEnumerator global::System.Collections.IEnumerable.GetEnumerator() => GetEnumerator();
        }

        [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "6.0.0.0")]
        public static partial void GreetWithCity(this global::Microsoft.Extensions.Logging.ILogger logger, global::System.String name, global::System.String city)
        {
            if (logger.IsEnabled(global::Microsoft.Extensions.Logging.LogLevel.Information))
            {
                logger.Log(
                    global::Microsoft.Extensions.Logging.LogLevel.Information,
                    new global::Microsoft.Extensions.Logging.EventId(2, nameof(GreetWithCity)),
                    new __GreetWithCityStruct(name, city),
                    null,
                    __GreetWithCityStruct.Format);
            }
        }
    }

I'd expect that LoggerMessage.Define is used when there are <= 6 template parameters iif they match the arguments of the method.

runtime/src/libraries/Microsoft.Extensions.Logging/gen/LoggerMessageGenerator.Emitter.cs

Line 40 in 9a31832

private static bool UseLoggerMessageDefine(LoggerMethod lm)

looks correct, but I can't debug into it (at the moment) to see what's going on here.

LoggerMessage.Define should be prefered. The struct based variant needs to allocate a new formatting delegate (for __GreetWithCityStruct.Format) on each call.

/cc: @maryamariyan

[dotnet-issue-labeler]

I couldn't figure out the best area label to add to this issue. If you have write-permissions please help me learn by adding exactly one area label.

[ghost]

Tagging subscribers to this area: @maryamariyan
See info in area-owners.md if you want to be subscribed.

Issue Details

---

If the template has one argument, then (as expected) LoggerMessage.Define use used. But for > 1 argument it emits the struct-based code.

For the tests I used

<PackageReference Include="Microsoft.Extensions.Logging" Version="6.0.0-preview.4.21216.3" />

Repro:

public static partial class Log
{
    [LoggerMessage(EventId = 1, Level = LogLevel.Information, Message = "Hello {Name}")]
    public static partial void Greet(this ILogger logger, string name);

    [LoggerMessage(EventId = 2, Level = LogLevel.Information, Message = "Hello {Name} from {City}")]
    public static partial void GreetWithCity(this ILogger logger, string name, string city);
}

Generated code

// <auto-generated/>
#nullable enable

    partial class Log 
    {
        [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "6.0.0.0")]
        private static readonly global::System.Action<global::Microsoft.Extensions.Logging.ILogger, global::System.String, global::System.Exception?> __GreetCallback =
            global::Microsoft.Extensions.Logging.LoggerMessage.Define<global::System.String>(global::Microsoft.Extensions.Logging.LogLevel.Information, new global::Microsoft.Extensions.Logging.EventId(1, nameof(Greet)), "Hello {Name}", true); 

        [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "6.0.0.0")]
        public static partial void Greet(this global::Microsoft.Extensions.Logging.ILogger logger, global::System.String name)
        {
            if (logger.IsEnabled(global::Microsoft.Extensions.Logging.LogLevel.Information))
            {
                __GreetCallback(logger, name, null);
            }
        }
        [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "6.0.0.0")]
        private readonly struct __GreetWithCityStruct : global::System.Collections.Generic.IReadOnlyList<global::System.Collections.Generic.KeyValuePair<string, object?>>
        {
            private readonly global::System.String _name;
            private readonly global::System.String _city;

            public __GreetWithCityStruct(global::System.String name, global::System.String city)
            {
                this._name = name;
                this._city = city;

            }

            public override string ToString()
            {
                var Name = this._name;
                var City = this._city;

                return $"Hello {Name} from {City}";
            }

            public static string Format(__GreetWithCityStruct state, global::System.Exception? ex) => state.ToString();

            public int Count => 3;

            public global::System.Collections.Generic.KeyValuePair<string, object?> this[int index]
            {
                get => index switch
                {
                    0 => new global::System.Collections.Generic.KeyValuePair<string, object?>("Name", this._name),
                    1 => new global::System.Collections.Generic.KeyValuePair<string, object?>("City", this._city),
                    2 => new global::System.Collections.Generic.KeyValuePair<string, object?>("{OriginalFormat}", "Hello {Name} from {City}"),

                    _ => throw new global::System.IndexOutOfRangeException(nameof(index)),  // return the same exception LoggerMessage.Define returns in this case
                };
            }

            public global::System.Collections.Generic.IEnumerator<global::System.Collections.Generic.KeyValuePair<string, object?>> GetEnumerator()
            {
                for (int i = 0; i < 3; i++)
                {
                    yield return this[i];
                }
            }

            global::System.Collections.IEnumerator global::System.Collections.IEnumerable.GetEnumerator() => GetEnumerator();
        }

        [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "6.0.0.0")]
        public static partial void GreetWithCity(this global::Microsoft.Extensions.Logging.ILogger logger, global::System.String name, global::System.String city)
        {
            if (logger.IsEnabled(global::Microsoft.Extensions.Logging.LogLevel.Information))
            {
                logger.Log(
                    global::Microsoft.Extensions.Logging.LogLevel.Information,
                    new global::Microsoft.Extensions.Logging.EventId(2, nameof(GreetWithCity)),
                    new __GreetWithCityStruct(name, city),
                    null,
                    __GreetWithCityStruct.Format);
            }
        }
    }

I'd expect that LoggerMessage.Define is used when there are <= 6 template parameters iif they match the arguments of the method.

runtime/src/libraries/Microsoft.Extensions.Logging/gen/LoggerMessageGenerator.Emitter.cs

Line 40 in 9a31832

private static bool UseLoggerMessageDefine(LoggerMethod lm)

looks correct, but I can't debug into it (at the moment) to see what's going on here.

LoggerMessage.Define should be prefered. The struct based variant needs to allocate a new formatting delegate (for __GreetWithCityStruct.Format) on each call.

/cc: @maryamariyan

Author:	gfoidl
Assignees:	-
Labels:	area-Extensions-Logging, untriaged
Milestone:	-