initial support for '@' symbol in message template #79038

tkrafael · 2022-11-30T14:54:53Z

With this change, users will be able to create message templates containing '@' symbol.
This allows initial compatibility with https://messagetemplates.org/ and with serilog sink.
This issue #197 can be resolved (it was closed without a proper solution).

@maryamariyan fixed an issue not related with templating, she added support for reseverd keyword parameters by prefixing them with '@' symbol (#64779)

I made those changes, tried to not break things and tried to not add performance issues. Please let me know if there's anything I have to change to allow this PR to be accepted.

ghost · 2023-01-02T09:18:49Z

Tagging subscribers to this area: @dotnet/area-extensions-logging
See info in area-owners.md if you want to be subscribed.

Issue Details

With this change, users will be able to create message templates containing '@' symbol.
This allows initial compatibility with https://messagetemplates.org/ and with serilog sink.
This issue #197 can be resolved and #60698 will also be resolved (it was closed without a proper solution).

@maryamariyan fixed an issue not related with templating, she added support for reseverd keyword parameters by prefixing them with '@' symbol (#64779)

I made those changes, tried to not break things and tried to not add performance issues. Please let me know if there's anything I have to change to allow this PR to be accepted.

Author:	tkrafael
Assignees:	-
Labels:	`area-Extensions-Logging`
Milestone:	-

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

tarekgh · 2023-01-03T18:14:04Z

@tkrafael looks the CI is waiting for you to accept the license/cla to run the tests. Could you please handle any request you are getting? or update if no action is needed from your side.

tkrafael · 2023-01-04T01:00:27Z

I have read the CLA Document and I hereby sign the CLA

dnfadmin · 2023-01-04T16:00:06Z

All CLA requirements met.

tkrafael · 2023-01-05T19:16:20Z

Resulting generate file for Roslyn3.11:

// <auto-generated/>
#nullable enable

namespace Microsoft.Extensions.Logging.Generators.Tests.TestClasses
{
    partial class AtSymbolTestExtensions
    {
        [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "42.42.42.42")]
        private static readonly global::System.Action<global::Microsoft.Extensions.Logging.ILogger, global::System.String, global::System.Exception?> __M0Callback =
            global::Microsoft.Extensions.Logging.LoggerMessage.Define<global::System.String>(global::Microsoft.Extensions.Logging.LogLevel.Information, new global::Microsoft.Extensions.Logging.EventId(0, nameof(M0)), "M0 {event}", new global::Microsoft.Extensions.Logging.LogDefineOptions() { SkipEnabledCheck = true }); 

        [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "42.42.42.42")]
        internal static partial void M0(global::Microsoft.Extensions.Logging.ILogger logger, global::System.String @event)
        {
            if (logger.IsEnabled(global::Microsoft.Extensions.Logging.LogLevel.Information))
            {
                __M0Callback(logger, @event, null);
            }
        }
        [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "42.42.42.42")]
        private static readonly global::System.Action<global::Microsoft.Extensions.Logging.ILogger, global::System.String, global::System.Exception?> __M1Callback =
            global::Microsoft.Extensions.Logging.LoggerMessage.Define<global::System.String>(global::Microsoft.Extensions.Logging.LogLevel.Information, new global::Microsoft.Extensions.Logging.EventId(1, nameof(M1)), "M1 {@myevent}", new global::Microsoft.Extensions.Logging.LogDefineOptions() { SkipEnabledCheck = true }); 

        [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "42.42.42.42")]
        internal static partial void M1(global::Microsoft.Extensions.Logging.ILogger logger, global::System.String @myevent)
        {
            if (logger.IsEnabled(global::Microsoft.Extensions.Logging.LogLevel.Information))
            {
                __M1Callback(logger, @myevent, null);
            }
        }
    }
}

Roslyn4.0:

// <auto-generated/>
#nullable enable

namespace Microsoft.Extensions.Logging.Generators.Tests.TestClasses
{
    partial class AtSymbolTestExtensions
    {
        [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "42.42.42.42")]
        private static readonly global::System.Action<global::Microsoft.Extensions.Logging.ILogger, global::System.String, global::System.Exception?> __M0Callback =
            global::Microsoft.Extensions.Logging.LoggerMessage.Define<global::System.String>(global::Microsoft.Extensions.Logging.LogLevel.Information, new global::Microsoft.Extensions.Logging.EventId(0, nameof(M0)), "M0 {event}", new global::Microsoft.Extensions.Logging.LogDefineOptions() { SkipEnabledCheck = true }); 

        [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "42.42.42.42")]
        internal static partial void M0(global::Microsoft.Extensions.Logging.ILogger logger, global::System.String @event)
        {
            if (logger.IsEnabled(global::Microsoft.Extensions.Logging.LogLevel.Information))
            {
                __M0Callback(logger, @event, null);
            }
        }
        [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "42.42.42.42")]
        private static readonly global::System.Action<global::Microsoft.Extensions.Logging.ILogger, global::System.String, global::System.Exception?> __M1Callback =
            global::Microsoft.Extensions.Logging.LoggerMessage.Define<global::System.String>(global::Microsoft.Extensions.Logging.LogLevel.Information, new global::Microsoft.Extensions.Logging.EventId(1, nameof(M1)), "M1 {@myevent}", new global::Microsoft.Extensions.Logging.LogDefineOptions() { SkipEnabledCheck = true }); 

        [global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "42.42.42.42")]
        internal static partial void M1(global::Microsoft.Extensions.Logging.ILogger logger, global::System.String @myevent)
        {
            if (logger.IsEnabled(global::Microsoft.Extensions.Logging.LogLevel.Information))
            {
                __M1Callback(logger, @myevent, null);
            }
        }
    }
}

tkrafael · 2023-01-05T19:24:45Z

Found that if LoggerMessageAttribute is used without loglevel, it creates a struct object, thus causing the issue described by @tarekgh
I'll include this test and improve code to avoid this problem.

tkrafael · 2023-01-06T15:40:56Z

Please note I added comments inside code to describe where changes were made. Roslyn does not generated those comments.
Generated struct using '@' symbols:

/// <summary> This API supports the logging infrastructure and is not intended to be used directly from your code. It is subject to change in the future. </summary>
[global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "42.42.42.42")]
[global::System.ComponentModel.EditorBrowsableAttribute(global::System.ComponentModel.EditorBrowsableState.Never)]
private readonly struct __UseAtSymbol4Struct : global::System.Collections.Generic.IReadOnlyList<global::System.Collections.Generic.KeyValuePair<string, object?>>
{
    private readonly global::System.String @myevent;
    private readonly global::System.Int32 _otherevent;

    public __UseAtSymbol4Struct(global::System.String @myevent, global::System.Int32 otherevent)
    {
        // solved here.
        this.@myevent = @myevent;
        this._otherevent = otherevent;

    }

    public override string ToString()
    {
        var otherevent = this._otherevent;
        // not creating local var as @myevent can be read directly from "this".
        return $"Force use of Struct with error, {@myevent} {otherevent}";
    }

    public static readonly global::System.Func<__UseAtSymbol4Struct, global::System.Exception?, string> Format = (state, ex) => state.ToString();

    public int Count => 3;

    public global::System.Collections.Generic.KeyValuePair<string, object?> this[int index]
    {
        get => index switch
        {
            // adds name correctly when name contains '@'
            0 => new global::System.Collections.Generic.KeyValuePair<string, object?>("@myevent", this.@myevent),
            1 => new global::System.Collections.Generic.KeyValuePair<string, object?>("otherevent", this._otherevent),
            2 => new global::System.Collections.Generic.KeyValuePair<string, object?>("{OriginalFormat}", "Force use of Struct with error, {@myevent} {otherevent}"),

            _ => 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();
}

And partial method implementation:

[global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "42.42.42.42")]
public static partial void UseAtSymbol4(this global::Microsoft.Extensions.Logging.ILogger logger, global::Microsoft.Extensions.Logging.LogLevel level, global::System.String @myevent, global::System.Int32 otherevent, global::System.Exception ex)
{
    if (logger.IsEnabled(level))
    {
        logger.Log(
            level,
            new global::Microsoft.Extensions.Logging.EventId(3, nameof(UseAtSymbol4)),
            new __UseAtSymbol4Struct(@myevent, otherevent),
            ex,
            __UseAtSymbol4Struct.Format);
    }
}

When using LoggerMessage.Define:

[global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "42.42.42.42")]
private static readonly global::System.Action<global::Microsoft.Extensions.Logging.ILogger, global::System.String, global::System.Exception?> __M1Callback =
    global::Microsoft.Extensions.Logging.LoggerMessage.Define<global::System.String>(global::Microsoft.Extensions.Logging.LogLevel.Information, new global::Microsoft.Extensions.Logging.EventId(1, nameof(M1)), "M1 {@myevent}", new global::Microsoft.Extensions.Logging.LogDefineOptions() { SkipEnabledCheck = true }); 

[global::System.CodeDom.Compiler.GeneratedCodeAttribute("Microsoft.Extensions.Logging.Generators", "42.42.42.42")]
internal static partial void M1(global::Microsoft.Extensions.Logging.ILogger logger, global::System.String @myevent)
{
    if (logger.IsEnabled(global::Microsoft.Extensions.Logging.LogLevel.Information))
    {
        __M1Callback(logger, @myevent, null);
    }
}

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

tarekgh · 2023-01-06T18:02:49Z

@tkrafael this change should fix the issue #78013. right? could you add a test case as

[LoggerMessage(0, LogLevel.Debug, "MMC request sent {@request}")]
partial void LogRequestSent(RequestRequest request);

Note the parameter name not having @ sign.

CC @vpetrusevici

vpetrusevici · 2023-01-06T18:16:52Z

@tarekgh
yep. you can try as @request also. This character will be ignored. I suppose it's related to params like @event becaouse you can't use just event.
Anyway I think it should work for both cases

vpetrusevici · 2023-01-06T18:22:19Z

What's about $ caracter? It's also used like @ but to force .ToString() using instead of Json. Will it works?
It's not so critical for me, but I just think it should be supported too.

tarekgh · 2023-01-06T18:34:29Z

What's about $ caracter? It's also used like @ but to force .ToString() using instead of Json. Will it works?

We can track this to fix it later. I think fixing @ is the priority here.

tkrafael · 2023-01-06T19:13:29Z

@tkrafael this change should fix the issue #78013. right? could you add a test case as
[LoggerMessage(0, LogLevel.Debug, "MMC request sent {@request}")]
partial void LogRequestSent(RequestRequest request);
Note the parameter name not having @ sign.

CC @vpetrusevici

Failing, checking how to solve it.

tkrafael · 2023-01-06T23:51:39Z

I've added unit tests to validate parsing and code emit.
Also fixed LoggerMessage.Define when using '@' symbol, avoiding using Struct classes when possible.

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

tarekgh

Thanks @tkrafael for the provided help here!

initial support for '@' symbol in message template

2e093c5

marek-safar added the area-Extensions-Logging label Jan 2, 2023

tarekgh added this to the 8.0.0 milestone Jan 3, 2023

tarekgh reviewed Jan 3, 2023

View reviewed changes

src/libraries/Microsoft.Extensions.Logging.Abstractions/gen/LoggerMessageGenerator.Emitter.cs Outdated Show resolved Hide resolved

tarekgh added the needs-author-action An issue or pull request that requires more info or actions from the author. label Jan 3, 2023

ghost removed the needs-author-action An issue or pull request that requires more info or actions from the author. label Jan 4, 2023

tarekgh closed this Jan 4, 2023

tarekgh reopened this Jan 4, 2023

Fix var name issue when using LoggerMessage.Define

720dd50

tarekgh reviewed Jan 6, 2023

View reviewed changes

src/libraries/Microsoft.Extensions.Logging.Abstractions/gen/LoggerMessageGenerator.Emitter.cs Outdated Show resolved Hide resolved

tarekgh reviewed Jan 6, 2023

View reviewed changes

src/libraries/Microsoft.Extensions.Logging.Abstractions/gen/LoggerMessageGenerator.Emitter.cs Outdated Show resolved Hide resolved

tarekgh reviewed Jan 6, 2023

View reviewed changes

src/libraries/Microsoft.Extensions.Logging.Abstractions/gen/LoggerMessageGenerator.Emitter.cs Outdated Show resolved Hide resolved

tarekgh reviewed Jan 6, 2023

View reviewed changes

src/libraries/Microsoft.Extensions.Logging.Abstractions/gen/LoggerMessageGenerator.Emitter.cs Outdated Show resolved Hide resolved

Nicoletti@ubuntu added 2 commits January 6, 2023 16:26

fix code formatting

14e79b6

Fix mechanism to find correct template name

9f760ee

update code with tests and more fixes

693620e

tarekgh reviewed Jan 7, 2023

View reviewed changes

src/libraries/Microsoft.Extensions.Logging.Abstractions/gen/LoggerMessageGenerator.Emitter.cs Show resolved Hide resolved

build-analysis bot mentioned this pull request Jan 7, 2023

Build fails with "eng/common/tools.sh: line 474: 537 Segmentation fault" #76759

Closed

tarekgh approved these changes Jan 9, 2023

View reviewed changes

tarekgh merged commit 5da4a9e into dotnet:main Jan 9, 2023

tarekgh mentioned this pull request Jan 9, 2023

[LSG] Objects logging using @ operator in logging source generator attribute #78013

Closed

tkrafael mentioned this pull request Jan 9, 2023

Feature/logging messagetemplate compat #80364

Merged

tarekgh mentioned this pull request Jan 11, 2023

[LSG] LoggerMessage source generator generates error when using template destructuring #69490

Closed

ghost locked as resolved and limited conversation to collaborators Feb 8, 2023

initial support for '@' symbol in message template #79038

initial support for '@' symbol in message template #79038

Uh oh!

Conversation

tkrafael commented Nov 30, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

ghost commented Jan 2, 2023

Uh oh!

Uh oh!

tarekgh commented Jan 3, 2023

Uh oh!

tkrafael commented Jan 4, 2023

Uh oh!

dnfadmin commented Jan 4, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

tkrafael commented Jan 5, 2023

Uh oh!

tkrafael commented Jan 5, 2023

Uh oh!

tkrafael commented Jan 6, 2023

Uh oh!

Uh oh!

Uh oh!

Uh oh!

Uh oh!

tarekgh commented Jan 6, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

vpetrusevici commented Jan 6, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

vpetrusevici commented Jan 6, 2023

Uh oh!

tarekgh commented Jan 6, 2023

Uh oh!

tkrafael commented Jan 6, 2023

Uh oh!

tkrafael commented Jan 6, 2023

Uh oh!

Uh oh!

tarekgh left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

tkrafael commented Nov 30, 2022 •

edited

Loading

dnfadmin commented Jan 4, 2023 •

edited

Loading

tarekgh commented Jan 6, 2023 •

edited

Loading

vpetrusevici commented Jan 6, 2023 •

edited

Loading