Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Enhance user-facing API for strongly-typed ILogger messages #36022

Closed
Tracked by #44314 ...
lodejard opened this issue Nov 9, 2019 · 82 comments · Fixed by #51064
Closed
Tracked by #44314 ...

Enhance user-facing API for strongly-typed ILogger messages #36022

lodejard opened this issue Nov 9, 2019 · 82 comments · Fixed by #51064
Assignees
Labels
api-approved API was approved in API review, it can be implemented area-Extensions-Logging blocking Marks issues that we want to fast track in order to unblock other important work Bottom Up Work Not part of a theme, epic, or user story Team:Libraries User Story A single user-facing feature. Can be grouped under an epic.
Milestone

Comments

@lodejard
Copy link

lodejard commented Nov 9, 2019

Is your feature request related to a problem? Please describe.

I'm trying to declare a strongly-typed code path for ILogger messages, but it is difficult to use the Action-returning static method LoggerMessage.Define<T1,T2,...,Tn> in a way that's approachable and maintainable by an entire team.

Describe the solution you'd like

It would be great if there was a strongly-typed struct which could wrap the underlying LoggerMessage.Define call and Action<ILoggerFactory, ...., Exception> field - even completely hide the actual Action signature. Ideally it would also provide more appropriate intellisense on the struct method which calls the action. If would be even cleaner if it could be initialized without repeating the generic argument types, and in most end-user applications if the EventId number was optional it could be derived from the EventId name instead.

internal static class MyAppLoggerExtensions
{
  private readonly static LogMessage<string, int> _logSayHello = (
    LogLevel.Debug, 
    nameof(SayHello), 
    "The program named {ProgramName} is saying hello {HelloCount} times");

  /// <summary>
  /// The program named {ProgramName} is saying hello {HelloCount} times
  /// </summary>
  /// <param name="logger">The logger to write to</param>
  /// <param name="programName">The {ProgramName} message property</param>
  /// <param name="helloCount">The {HelloCount} message property</param>
  public static void SayHello(this ILogger<MyApp> logger, string programName, int helloCount)
  { 
    _logSayHello.Log(logger, programName, helloCount);
  }
}

A LogMessage struct would be a allocation-free. Having implicit operators for tuples which match the constructor parameters enables field initialization without needing to repeat the generic argument types.

public struct LogMessage<T1, ..., Tn>
{
  public LogMessage(LogLevel logLevel, EventId eventId, string formatString);
  public LogMessage(LogLevel logLevel, int eventId, string formatString);
  public LogMessage(LogLevel logLevel, string eventName, string formatString);

  public LogLevel LogLevel {get;}
  public EventId EventId {get;}
  public string FormatString {get;}

  public void Log(ILogger logger, T1 value1, ..., Tn valuen);
  public void Log(ILogger logger, Exception exception, T1 value1, ..., Tn valuen);

  public static implicit operator LogMessage<T1, ..., Tn>((LogLevel logLevel, EventId eventId, string formatString) parameters);
  public static implicit operator LogMessage<T1, ..., Tn>((LogLevel logLevel, int eventId, string formatString) parameters);
  public static implicit operator LogMessage<T1, ..., Tn>((LogLevel logLevel, string eventName, string formatString) parameters);
}

Describe alternatives you've considered

Having one struct per LogLevel could also remove the need to have the first "LogLevel" argument in the initializer - but that would be a larger number of classes and intellisense wouldn't list the level names for you like typing LogLevel. does

@analogrelay analogrelay transferred this issue from dotnet/extensions May 7, 2020
@Dotnet-GitSync-Bot Dotnet-GitSync-Bot added area-System.Runtime untriaged New issue has not been triaged by the area owner labels May 7, 2020
@analogrelay analogrelay added this to the Future milestone May 7, 2020
@maryamariyan maryamariyan removed the untriaged New issue has not been triaged by the area owner label Jul 1, 2020
@maryamariyan maryamariyan added needs more info api-suggestion Early API idea and discussion, it is NOT ready for implementation labels Oct 19, 2020
@davidfowl
Copy link
Member

davidfowl commented Nov 15, 2020

@lodejard After giving this a second look I wonder how much this matters given that the logger message is mostly used as an internal detail of these static methods. Would it be better to use a type as IDL for code generating one of these objects.

public partial class Log
{
    [LoggerMessage(LogLevel.Debug, 1, nameof(SayHello), "The program named {ProgramName} is saying hello {HelloCount} times")]
    public static partial void SayHello(ILogger logger, string name, int helloCount);
}

Then it would generate this:

public partial class Log
{
    private static readonly Action<ILogger, string, int, Exception?> _sayHello = 
        LoggerMessage.Define<string, int>(LogLevel.Information, new EventId(1, "SayHello"), "The program named {ProgramName} is saying hello {HelloCount} times");

    public static partial void SayHello(ILogger logger, string programName, int helloCount)
    {
        _sayHello(logger, programName, helloCount, null);
    }
}

Usage would look like:

// Without extension methods
Log.SayHello(logger, "Louis", 10);

// With extension methods
logger.SayHello("Louis", 10);

We need partial extension methods @MadsTorgersen @jaredpar. I keep running into cases where small language limitations make the user experience slightly worse for source generators.

@davidfowl
Copy link
Member

cc @noahfalk @shirhatti

@geeknoid
Copy link
Member

I've been working on a model that uses C# 9.0 source generators. The developer writes:

    [LogInterface(generatedTypeName: "DiagExtensions", generateExtensionMethods: true)]
    interface IDiagExtensions
    {
        [LogMethod("Could not open socket to `{hostName}`", LogLevel.Critical)]
        void CouldNotOpenSocket(string hostName);
    }

And the following is generated automatically:

namespace LoggingExample
{

    static class DiagExtensions
    {
        
        private readonly struct __CouldNotOpenSocketStruct__ : IReadOnlyList<KeyValuePair<string, object>>
        {
            private readonly string hostName;

            public __CouldNotOpenSocketStruct__(string hostName)
            {
                this.hostName = hostName;

            }

            public string Format()
            {
                return $"Could not open socket to `{hostName}`";
            }

            public KeyValuePair<string, object> this[int index]
            {
                get
                {
                    switch (index)
                    {
                        case 0:
                            return new KeyValuePair<string, object>(nameof(hostName), hostName);

                        default:
                            throw new ArgumentOutOfRangeException(nameof(index));
                    }
                }
            }

            public int Count => 1;

            public IEnumerator<KeyValuePair<string, object>> GetEnumerator()
            {
                yield return new KeyValuePair<string, object>(nameof(hostName), hostName);

            }

            IEnumerator IEnumerable.GetEnumerator()
            {
                return GetEnumerator();
            }
        }
        private static readonly EventId __CouldNotOpenSocketEventId__ = new(0, nameof(CouldNotOpenSocket));

        public static void CouldNotOpenSocket(this ILogger logger, string hostName)
        {
            if (logger.IsEnabled((LogLevel)5))
            {
                var s = new __CouldNotOpenSocketStruct__(hostName);
                logger.Log((LogLevel)5, __CouldNotOpenSocketEventId__, s, null, (s, ex) => s.Format());
            }
        }

    }
}

There is also an option to generate a wrapper type for the ILogger, rather than extension methods:

    [LogInterface(generatedTypeName: "DiagWrapper")]
    interface IDiagWrapper
    {
        [LogMethod("Could not open socket to `{hostName}`", LogLevel.Critical)]
        void CouldNotOpenSocket(string hostName);
    }

which comes out as:

namespace LoggingExample
{

    sealed class DiagWrapper : IDiagWrapper
    {
        private readonly ILogger __logger;

        public DiagWrapper(ILogger logger) => __logger = logger;

        
        private readonly struct __CouldNotOpenSocketStruct__ : IReadOnlyList<KeyValuePair<string, object>>
        {
            private readonly string hostName;

            public __CouldNotOpenSocketStruct__(string hostName)
            {
                this.hostName = hostName;

            }

            public string Format()
            {
                return $"Could not open socket to `{hostName}`";
            }

            public KeyValuePair<string, object> this[int index]
            {
                get
                {
                    switch (index)
                    {
                        case 0:
                            return new KeyValuePair<string, object>(nameof(hostName), hostName);

                        default:
                            throw new ArgumentOutOfRangeException(nameof(index));
                    }
                }
            }

            public int Count => 1;

            public IEnumerator<KeyValuePair<string, object>> GetEnumerator()
            {
                yield return new KeyValuePair<string, object>(nameof(hostName), hostName);

            }

            IEnumerator IEnumerable.GetEnumerator()
            {
                return GetEnumerator();
            }
        }
        private static readonly EventId __CouldNotOpenSocketEventId__ = new(0, nameof(CouldNotOpenSocket));

        public void CouldNotOpenSocket(string hostName)
        {
            if (__logger.IsEnabled((LogLevel)5))
            {
                var s = new __CouldNotOpenSocketStruct__(hostName);
                __logger.Log((LogLevel)5, __CouldNotOpenSocketEventId__, s, null, (s, ex) => s.Format());
            }
        }

    }
}

I believe this code is both more convenient and more efficient than existing approaches used in the wild.

@tarekgh tarekgh modified the milestones: Future, 6.0.0 Nov 16, 2020
@geeknoid
Copy link
Member

geeknoid commented Nov 17, 2020

Based on the example I provided above, I propose that we extend the framework with support to automatically generate strongly-type logging methods, based on a developer-authored interface type. The developer provides the minimum amount of information necessary, and the source generator produces a highly efficient set of logging methods. The generated logging methods can be produced as extension methods on ILogger, or can be produced as a type that wraps ILogger and exposes instance logging methods.

More specifically:

  • Introduce the types LogInterfaceAttribute and LogMethodAttribute to the Microsoft.Extensions.Logging namespace in the Microsoft.Extensions.Logging.Abstraction assembly.
    /// <summary>
    /// Indicates an interface defines strongly-typed logging methods
    /// </summary>
    /// <remarks>
    /// This interface is a trigger to cause code generation of strongly-typed methods
    /// that provide a convenient and highly efficient way to log through an existing
    /// ILogger interface.
    /// 
    /// The declaration of the interface to which this attribute is applied cannot be
    /// nested in another type.
    /// </remarks>
    [System.AttributeUsage(System.AttributeTargets.Interface, AllowMultiple = false)]
    public sealed class LogInterfaceAttribute : Attribute
    {
        /// <summary>
        /// Creates an attribute to annotate an interface as triggering the generation of strongly-typed logging methods.
        /// </summary>
        /// <param name="generatedTypeName">Determines the name of the generated type.</param>
        /// <param name="generateExtensionMethods">Determines whether the generated type uses extension methods or instance methods.</param>
        public LogInterfaceAttribute(string generatedTypeName, bool generateExtensionMethods = false) => (GeneratedTypeName, GenerateExtensionMethods) = (generatedTypeName, generateExtensionMethods);

        /// <summary>
        /// Gets the name of the generated type.. 
        /// </summary>
        public string GeneratedTypeName { get; }

        /// <summary>
        /// Gets whether the generated type exposes the strongly-typed methods as extension methods or instance methods.
        /// </summary>
        public bool GenerateExtensionMethods { get; }
    }

    /// <summary>
    /// Provides information to guide the production of a strongly-typed logging method.
    /// </summary>
    /// <remarks>
    /// This attribute is applied to individual methods in an interface type annotated with [LogInterface].
    /// </remarks>
    [System.AttributeUsage(System.AttributeTargets.Method, AllowMultiple = false)]
    public sealed class LogMethodAttribute : Attribute
    {
        /// <summary>
        /// Creates an attribute to guide the production of a strongly-typed logging method.
        /// </summary>
        /// <param name="message">The message text output by the logging method. This string is a template that can contain any of the method's parameters.</param>
        /// <param name="level">THe logging level produced when invoking the strongly-typed logging method.</param>
        /// <example>
        /// [LogInterface("Diag")]
        /// interface IDiag
        /// {
        ///     [LogMethod("Could not open socket for {hostName}", LogLevel.Critical)]
        ///     void CouldNotOpenSocket(string hostName);
        /// }
        /// </example>
        public LogMethodAttribute(string message, LogLevel level) => (Message, Level) = (message, level);

        /// <summary>
        /// Gets the message text for the logging method.
        /// </summary>
        public string Message { get; }

        /// <summary>
        /// Gets the logging level for the logging method.
        /// </summary>
        public LogLevel Level { get; }
    }
  • Introduce a source generator in the Microsoft.Extensions.Logging.Generators namespace in a new Microsoft.Extensions.Logging.Generators.dll assembly. This source generator would interpret the [LogInterface] and [LogMethods] attributes to generate strongly-typed logging methods for every logging method defined by the user. The motivation for putting the generator logic into a separate assembly is to avoid pulling in this build-time assembly into the application distribution.

I haven't contributed to this project before, but I'd be happy to learn the ropes and get something like the above checked in.

@davidfowl
Copy link
Member

davidfowl commented Nov 17, 2020

A couple of pieces of feedback:

  • I think we should ditch the interface and instead should directly use the static partial class with static methods. It feels a bit strange to use an interface as IDL if we don't generate an implementation (the extension method case).
  • We need to define how event ids and event names are generated based on the methods. They can't change if new methods are added or removed. These attributes should optionally let you specify an EventId and EventName as an override.
  • We need to clearly define what happens when the type of method is unsupported:
    • Do we support generic methods? What does the event name become then?
    • Do we support overloads? How does it fail? Does it throw? I propose a diagnostic error.
  • EventSource has the EventAttribute as the attribute, I'd prefer a LoggerMessage attribute since that mathes the type we have today (LoggerMessage). We might also need a [Logger] attribute since we don't have a base class but it would be a way to identify the static class to generate methods into.
  • We need to discuss how methods that pass exceptions get handled. They should automagically get passed into the exception part of the Log method.
  • We should error when the message template references a property (case insensitive) that isn't a declared parameter.
[AttributeUsage(AttributeTargets.Class, Inherited = false, AllowMultiple = false)]
public sealed class LoggerAttribute : Attribute
{
}

[AttributeUsage(System.AttributeTargets.Method, Inherited = false, AllowMultiple = false)]   
public sealed class LoggerMessageAttribute : Attribute
{
    public LoggerMessageAttribute(LogLevel logLevel, string formatString)
    {
        LogLevel = logLevel;
        FormatString = formatString;
    }

    public LogLevel LogLevel { get; }

    public string FormatString { get; }

    public int? EventId { get; set; }

    public string EventName { get; set; }
}

In the generated code:

  • If the event id is null, it will generate one based on the name.
  • If the event name if null, it will use the method name as the event name.
[Logger]
public partial class Log
{
    [LogMessage(LogLevel.Debug, "The program named {ProgramName} is saying hello {HelloCount} times")]
    public static partial void SayHello(ILogger logger, string name, int helloCount);
}

Would generate in the same class (note that it's partial):

public partial class Log
{
    private static readonly Action<ILogger, string, int, Exception?> _sayHello = 
        LoggerMessage.Define<string, int>(LogLevel.Information, new EventId(1, "SayHello"), "The program named {ProgramName} is saying hello {HelloCount} times");

    public static partial void SayHello(ILogger logger, string programName, int helloCount)
    {
        _sayHello(logger, programName, helloCount, null);
    }
}

Alternative generated code (based on the above):

public partial class Log
{
    private readonly struct __SayHelloStruct__ : IReadOnlyList<KeyValuePair<string, object>>
    {
        private readonly string programName;
        private readonly int helloCount;

        public __SayHelloStruct__(string programName, int helloCount)
        {
            this.programName = programName;
            this.helloCount = helloCount;

        }

        public string Format()
        {
            return $"The program named {programName} is saying hello {helloCount} times";
        }

        public KeyValuePair<string, object> this[int index]
        {
            get
            {
                switch (index)
                {
                    case 0:
                        return new KeyValuePair<string, object>(nameof(programName), programName);

                    case 1:
                        return new KeyValuePair<string, object>(nameof(helloCount), helloCount);

                    default:
                        throw new ArgumentOutOfRangeException(nameof(index));
                }
            }
        }

        public int Count => 1;

        public IEnumerator<KeyValuePair<string, object>> GetEnumerator()
        {
            yield return new KeyValuePair<string, object>(nameof(programName), programName);
            yield return new KeyValuePair<string, object>(nameof(helloCount), helloCount);
        }

        IEnumerator IEnumerable.GetEnumerator()
        {
            return GetEnumerator();
        }
    }

    // Generated EventId from the event name
    private static readonly EventId __SayHelloEventId__ = new(1, nameof(SayHello));

    public static partial void SayHello(string programName, int helloCount)
    {
        if (__logger.IsEnabled((LogLevel)2))
        {
            var message = new __SayHelloStruct__(programName, helloCount);
            __logger.Log((LogLevel)2, __SayHelloEventId__, message, null, (s, ex) => s.Format());
        }
    }
}

This is more efficient than LoggerMessage.Define (we can move all of the format string parsing to compile time) but bloats the codegen a little bit as there's a unique struct per method. There's an in between here where we can use a predefined generic struct like this (

private readonly struct LogValues<T0, T1, T2, T3, T4, T5> : IReadOnlyList<KeyValuePair<string, object>>
), but it would have a bigger runtime representation as it would need to store reference to something that held onto the names of the values.

I'd recommend we go with the more efficient codegen sacrificing code size but am open to suggestions.

@davidfowl
Copy link
Member

Another benefit would be that we can improve startup time by shifting to this model completely in ASP.NET Core itself (see #44746)

@7sharp9
Copy link

7sharp9 commented Nov 17, 2020

How would this be consumed by non C# languages?

@geeknoid
Copy link
Member

@davidfowl Thanks for the excellent feedback.

  • About using a partial class to as IDL, I think that's a reasonable pattern and is where I started originally. But I also really like the idea of a wrapping type rather than interface methods. The IntelliSense experience is so much nicer since you don't have the pollution (of temptation) of things like Logger.LogInformation available. It'd be easy to make the generator flexible here, let me experiment a bit.

  • EventId handling you suggest makes total sense.

  • I'll add error checking to deal with oddball method declaration types.

  • I don't like the attribute [Logger] as that conflates things with ILogger/Logger. This stuff is not itself a logger, its all about wrapping a logger. Any other ideas?

  • The model I implemented for exceptions is that it takes the first parameter that is an exception type and passes that as the exception parameter to the logger. To reference the exception in the message, you just use the parameter name in a template like any other parameter.

  • You'll already get appropriate errors if you specify invalid symbols in the format string. That happens naturally since the format string is emitted as-is in the generated code and the C# compiler will complain of any problems.

@cgillum
Copy link

cgillum commented Nov 17, 2020

I love the idea of using source generators to make structured logging easier. I had to implement my own mini-framework for this recently and it’s still much more work to maintain than I’d like. One blocker I ran into though is the limitation of 6 parameters in LoggerMessage.Define. I would hope a source generator solution would not be as limited in terms of structured log parameters.

@geeknoid
Copy link
Member

geeknoid commented Nov 17, 2020

How about three attributes:

[LoggerExtensions] - applied to a partial class, code generation will produce static extension methods in that class
[LoggerWrapper] - applied to an interface, code generation will produce a wrapper class around ILogger
[LoggerMessage] - applied to methods to declare a logging message.

@lodejard
Copy link
Author

I like this a lot!! It's very close to something I prototyped earlier (with Castle dynamic proxy) to pitch to our team to evolve our strongly-typed logging story.

I would suggest this is more like a specialization of a logger interface rather than a wrapper - so optionally inheriting ILogger<T> would be completely appropriate. There are some use cases to talk about later but there are a handful of reasons I'd strongly recommend public interface ISomethingLogger : ILogger<Something> as a starting point.

Curious how much overhead there is for the message format parsing. Is that something that can be quantified or profiled? Otherwise I'd suggest LoggerMessage.Define is a fine starting point and could be optimized later as a private implementation detail later on if we need.

Regarding EventId - totally agree! That is are very undervalued piece of data most user code leaves out. I'd suggest the method name like "SayHello" makes a perfect EventId string. In the absence of a user provided number having a stable hash of the name would be a fine EventId int.

I'd suggest having the Exception parameter be either first or last rather than anywhere in the list. TBH, last would probably be most natural. In the existing LogWarning(...) overloads the Exception is first only because of how overload resolution works with variable params...

(More thoughts --- need to run to meeting for now though)

@davidfowl
Copy link
Member

I would suggest this is more like a specialization of a logger interface rather than a wrapper - so optionally inheriting ILogger would be completely appropriate. There are some use cases to talk about later but there are a handful of reasons I'd strongly recommend public interface ISomethingLogger : ILogger as a starting point.

I'm not a fan of having to inject something different that I have to today. That's why I like the extension/static method approach.

If we have this extension approach then I am suggest that it's optional.

Curious how much overhead there is for the message format parsing. Is that something that can be quantified or profiled? Otherwise I'd suggest LoggerMessage.Define is a fine starting point and could be optimized later as a private implementation detail later on if we need.

Enough to affect the startup time (which we now care about more now). I'm fine with simple codegen to start but @geeknoid already it working and we can compare them.

@lodejard
Copy link
Author

I'm not a fan of having to inject something different that I have to today. That's why I like the extension/static method approach.

If we have this extension approach then I am suggest that it's optional.

Makes sense - also I found enough of the old prototype code to kit together as an example.

https://github.com/lodejard/logger-interfaces/blob/main/LoggerCodeGen/Program.cs

TBH having analyzer codefix to turn logger.LogInformation(...) lines into extension methods was my first thought also. There were some folks who pushed back on the idea --- there was just enough code in the extension methods cs file (and redundancy with parameter types repeated in several places) that ended up being a nudge towards using an interface as a logging DSL.

In both cases (interface and/or extensions) I'd suggest an analyzer codefix acting on logger.LogXxxx calls could be a key part of the experience.

@geeknoid
Copy link
Member

I created a repo for my current work on this front: https://github.com/geeknoid/LoggingGenerator. Comments welcome.

@geeknoid
Copy link
Member

geeknoid commented Nov 17, 2020

@lodejard What kind of heuristic are you thinking of to convert LogXXX calls to extension methods? New names need to be invented for the strongly-typed methods, so I'm not sure where those should come from.

@lodejard
Copy link
Author

lodejard commented Nov 18, 2020

@geeknoid good question! At the time was thinking if the overload involved a new EventId(...) or reference to a static EventId field with an initializer - then an initial event name (and number) could be picked up that way.

Failing that, if it's a single Logger.LogXXX(...) being hit by fixup, would try to do the same thing as "extract method" --- where the line becomes Logger.Message1(...) where Message1 remains selected and in rename mode.

In the case that you are "entire project | solution" a code-base that has only format strings the options are limited. Some possibilities as thought exercise:

  1. You could try to synthesize a short name from the message, though I suspect that will would never give you great results (especially across different languages).
  2. That said at the time I recall thinking, instead of moving to strong method name in one step, have a different fixup for those Log overloads for "add EventId". That would result in Logger.LogXXX(new EventId(42, "EventName"), ...); and you would also have an analyzer error squiggle when the constant "EventName" appears in that constructor "Please provide a meaningful event name"
  3. Instead of an intermediate state for multi fixup go right to creating all of the Message1, Message2, etc. with intentionally bad names. An analyzer warning on those logger method names could also prompt the user to ctrl-R-R rename something meaningful.

Typing that out loud - I think I'd lean towards #2 actually. Even if a user didn't want to go all of the way to strongly-typed log messages, it would be a genuinely useful fixup IMO to be able to add new EventId in every log line in a solution. Especially if the analyzer could figure out the "highest visible plus one" EventId number to put in spot-by-spot.

  1. Was also kind of kicking around the idea of a user-assisted hint in the format string. For example, in Logger.LogInformation("SayHello: The user {AccountName} has said {Greeting}", username, hellotext); if you match the pattern "alphanum+colon+1ormorespace+message" break it into name "SayHello" and message "The user {AccountName} has said {Greeting}".

#4 might be a stretch --- it's not a format that you expect naturally. I was thinking of it because it's the flow I would like to use myself personally. e.g. Declare any new messages inline as I'm working with minimal effort (and without switching to another file) then when I'm ready to turn the change into a PR (and done fussing with message text) I'd ctrl-dot to strongly-type all of the messages in the solution.

@lodejard
Copy link
Author

@geeknoid @davidfowl to attempt a summary of strawman :) this is based on just #2 from above

Step one, solution-wide fixup to eventid names where missing:
Logger.LogInformation("{User} says hi.", user);
fixup -> Logger.LogInformation(new EventId(73, "EventName"), "{User} says hi.", user);

Step two, every "EventName" is an error
edit -> Logger.LogInformation(new EventId(73, "SayHello"), "{User} says hi.", user);

Step three, solution-wide fixup to strongly-type events
Logger.LogInformation(new EventId(42, "SayHello"), "{User} says hi.", user);
fixup -> Logger.SayHello(user);

@davidfowl
Copy link
Member

I think the code fix and source generator complement each other but aren't directly coupled. We should focus on fleshing out the design for the source generator and then follow up with how we move existing calls to it (if possible)

@bartonjs bartonjs added api-approved API was approved in API review, it can be implemented and removed api-ready-for-review API is ready for review, it is NOT ready for implementation labels Apr 9, 2021
@geeknoid
Copy link
Member

As the original author of this design, I'd like to record my objection to hurting usability of the feature by simplifying the attribute's constructor. The rationale provided above ("because it's complicated validation logic done by the generator") is not a rationale for decreasing the quality of the developer experience. Stripping the constructor doesn't yield an appreciable reduction in the generator's complexity or size. And finally, the logic has already been implemented, has 100% unit test coverage, and is already in production use in our internal version of the code.

As Maryam points out above, the first selling point for this feature is "shorter and simpler syntax". By stripping all parameters from the constructor, usability suffers:

[LoggerMessage(0, LogLevel.Critical, "Could not open socket to `{hostName}`")]
public partial void CouldNotOpenSocket(string hostName);

bloats to:

[LoggerMessage(EventId = 0, LogLevel = LogLevel.Critical, Message = "Could not open socket to `{hostName}`")]
public partial void CouldNotOpenSocket(string hostName);

Why would you require a developer to type in those extra 31 characters when it is completely avoidable? When you have 20 of those logging methods declared in your app's source code, you'd be wasting 620 extra characters for not discernable reason.

Please reconsider this decision.

@stephentoub
Copy link
Member

And finally, the logic has already been implemented, has 100% unit test coverage, and is already in production use in our internal version of the code.

Regardless of the merits of the other arguments, this is not a reason we should consider when deciding on the design for this library. :-)

@stephentoub
Copy link
Member

because it's complicated validation logic done by the generator

This may not be coming across as I believe it was intended. One of the concerns raised, I believe by @shirhatti, was that some of the arguments that are required today may become optional "tomorrow", e.g. event id. Other arguments are already optional, like log level, depending on the signature of the logging method written. It ends up being up to the generator, examining both the attribute and the method signature, to decide whether the combination is valid, in a way we can't control just via the attribute constructor. If we decide to enable id to be optional, then we don't have a good way to do that without adding more constructors or settable properties anyway, whereas the generator can simply change its validation logic and generation strategy based on the policy du jour. Using the settable property approach is recognizing that everything is or may eventually be optional, and leaving it up to the generator to control everything around the user experience.

FWIW, I don't belive it meaningfully harms the user experience.

@bartonjs can correct me if I've channeled him poorly.

@geeknoid
Copy link
Member

Harming usability in today's experience to prevent potentially adding more constructors in the future seems like an odd trade-off to me. Constructors can be added in the future, including the no-parameter constructor. So that's really not a good motivation IMO as having improved usability today doesn't impose any constraint on the future.

I consider wasteful ceremony imposed by an API to be a usability issue in general. The substantial complications added to the C# language over the years strictly for the sake of avoiding developers typing redundant ceremonious text serves as a strong testament to that point.

@geeknoid
Copy link
Member

geeknoid commented Apr 10, 2021

And finally, the logic has already been implemented, has 100% unit test coverage, and is already in production use in our internal version of the code.

Regardless of the merits of the other arguments, this is not a reason we should consider when deciding on the design for this library. :-)

It does matter if the rationale provided is "complicated logic in the generator".

@stephentoub
Copy link
Member

It does matter if the rationale provided is "complicated logic in the generator".

Again, this wasn't saying "oh man this is going to be hard to implement so we shouldn't expose the API we want", this was saying "the generator handles all the logic so we can expose the API we want".

@geeknoid
Copy link
Member

Regarding:

Error 10: Either generics should work, or it also should check that it's not in a generic type

The constraint is currently that the logging method cannot be generic. The type the method is in can be generic, and method arguments can be of generic types. But the method itself cannot be generic.

@stephentoub
Copy link
Member

stephentoub commented Apr 10, 2021

The constraint is currently that the logging method cannot be generic

What leads to that constraint being necessary? I'm unclear what it prevents that couldn't be achieved via a type parameter, which is currently allowed. Hence the suggestion that both should be allowed or disallowed equally. Is there a technical limitation?

@geeknoid
Copy link
Member

The constraint is currently that the logging method cannot be generic

What leads to that constraint being necessary? I'm unclear what it prevents that couldn't be achieved via a type parameter, which is currently allowed. Hence the suggestion that both should be allowed or disallowed equally. Is there a technical limitation?

I don't believe there is a technical problem. I didn't see the value in a generic logging method so I didn't put the extra effort necessary to parse, emit, and test this code path. This seemed like something that could clearly be added in the future if a need ever arose. You wouldn't want to complicate the generator logic prematurely, right? :-)

I don't understand why it would be a good idea to say "if you can't do generic methods, than you shouldn't do generic types either". Those seem orthogonal. It's quite possible (and indeed common) for a logging method to be introduced in a generic type. But introducing a generic method by itself seems much less likely.

@geeknoid
Copy link
Member

In the implementation, there is a substantial difference in supporting generic types vs. generic methods. Generic types are mostly free. Support generic methods is more involved as the code generator needs to not only parse these definitions, it needs to generate a corresponding signature. So it would need to parse N generic definitions along with their corresponding constraints, and then emit them back out on the generated method.

@stephentoub
Copy link
Member

stephentoub commented Apr 10, 2021

You wouldn't want to complicate the generator logic prematurely, right?

I feel like I need to reiterate again that, to my knowledge, no one has expressed concern about how complex the generator is.

why it would be a good idea to say "if you can't do generic methods, than you shouldn't do generic types either"

It depends on the reason for the limitation. One reason, for example, would be that the purpose of such generated logging methods is to enforce strong typing on the structured logging, such that, for example, you could map each argument to its own database column or the like. A T parameter, regardless of whether it comes from a generic method parameter or a generic type parameter, could easily cause problems for that, with various calls each contributing their own unique type that then may not be supported by the underlying store. So if the concern were that, you'd want to ban it for any generic parameter, regardless of where it came from.

Instead, you've stated that's not the reason, but rather purely an artificial constraint based on viewed demand and the difficulty of implementation. In that case, sure, there's no reason to cut off the easier thing that "just works", though I expect in the fullness of time you'll want to remove the generic method limitation as well.

But introducing a generic method by itself seems much less likely.

Really? We do that in a variety of places. For example, we want a semi-structured trace logging method that can be used to trace out messages in a large number of places, with some arguments fixed for all tracing sites and some variable, e.g.

Log(httpConnectionPool, httpConnection, "Trace: {0}", additionalData);

where additionalData may be a value type. We don't want to add overloads for every possible T that additionalData may be, nor do we want to have to add guard calls around every use of Log to prevent additionalData from being boxed. If this Log could actually be Log<T>, it'd be simple to do. We could work around that by putting this Log method on its own generic type, and instead write Tracing<TypeOfAdditionalData>.Log(httpConnectionPool, httpConnection, "Trace: {0}", additionalData), but then we lose type inference and it's more code at every usage site, plus it ends up then needing to be separate from the rest of the logging methods we use.

That said, for the particular cases where the above arises, we're much more likely to use C# 10 interpolation support, write:

Log(ttpConnectionPool, httpConnection, $"Trace: {additionalData}");

and then not only avoid boxing for additionalData, but also not have to add a guard at the call site even if additionalData is actually a complicated and potentially expensive expression.

Which is to say, I believe there are uses, but we ourselves in the core libraries aren't going to use this mechanism, so this feedback is about use cases rather than strong need. If we can't support generic method parameters right now because it actually is too complex for the generator right now and we want to wait for further feedback before investing in it, that's reasonable.

@Kahbazi
Copy link
Member

Kahbazi commented Apr 10, 2021

Does the source generator only target the LoggerMessageAttribute or does it also target attributes that inherits LoggerMessageAttribute?
A user could creates its own attribute which inherits from LoggerMessageAttribute and set the constructor with whichever property that the application needs.

public class LogErrorAttribute : LoggerMessageAttribute
{
    public LogErrorAttribute(int eventId, string message)
    {
        EventId = eventId;
        Message = message;
        Level = LogLevel.Error;
    }
}

public class LogInfoAttribute : LoggerMessageAttribute
{
    public LogErrorAttribute(int eventId, string message)
    {
        EventId = eventId;
        Message = message;
        Level = LogLevel.Information;
    }
}

@maryamariyan
Copy link
Member

A user could creates its own attribute which inherits from LoggerMessageAttribute and set the constructor with whichever property that the application needs.

Note that this is a sealed attribute

@Kahbazi
Copy link
Member

Kahbazi commented Apr 10, 2021

Note that this is a sealed attribute

Oh I missed that. So I think what I'm asking is that could it not be sealed so the users could customize their own log attribute?

@geeknoid
Copy link
Member

@Kahbazi, I think that's an intriguing idea, but it wouldn't 'just work' I think. Given how attributes are parsed, there's dedicated logic that looks at ctor parameters or properties, etc. Maybe there's a way to write attribute parsing logic that is inherently more generic in nature and could tolerate inheritance like that, but that's now how the source generator works at the moment.

@maryamariyan maryamariyan mentioned this issue Apr 13, 2021
13 tasks
@ghost ghost added the in-pr There is an active PR which will close this issue when it is merged label Apr 13, 2021
@ghost ghost removed the in-pr There is an active PR which will close this issue when it is merged label Apr 16, 2021
@maryamariyan
Copy link
Member

@lodejard the logging generator got submitted into Microsoft.Extensions.Logging package version 6.0.0-preview.4.21216.3,
and here is a Hello World type gist using it.

Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
api-approved API was approved in API review, it can be implemented area-Extensions-Logging blocking Marks issues that we want to fast track in order to unblock other important work Bottom Up Work Not part of a theme, epic, or user story Team:Libraries User Story A single user-facing feature. Can be grouped under an epic.
Projects
None yet
Development

Successfully merging a pull request may close this issue.