AspNetCore.Docs icon indicating copy to clipboard operation
AspNetCore.Docs copied to clipboard

Why does LoggerMessage call IsEnabled for the loggerProvider, but i should still call it in loggerProvider.Log(..) ?

Open sommmen opened this issue 5 years ago • 6 comments

Hiya,

From the docs:

public class ColoredConsoleLogger : ILogger
{
    private readonly string _name;
    private readonly ColoredConsoleLoggerConfiguration _config;

    public ColoredConsoleLogger(string name, ColoredConsoleLoggerConfiguration config)
    {
        _name = name;
        _config = config;
    }

    public IDisposable BeginScope<TState>(TState state)
    {
        return null;
    }

    public bool IsEnabled(LogLevel logLevel)
    {
        return logLevel == _config.LogLevel;
    }

    public void Log<TState>(LogLevel logLevel, EventId eventId, TState state, 
                        Exception exception, Func<TState, Exception, string> formatter)
    {
        if (!IsEnabled(logLevel))
        {
            return;
        }

        if (_config.EventId == 0 || _config.EventId == eventId.Id)
        {
            var color = Console.ForegroundColor;
            Console.ForegroundColor = _config.Color;
            Console.WriteLine($"{logLevel} - {eventId.Id} " +
                              $"- {_name} - {formatter(state, exception)}");
            Console.ForegroundColor = color;
        }
    }
}

Docs

As we can see here, I should call IsEnabled in the Log() message myself. This was quite confusing, given that its a method i should implement myself. In that case i'd expect the method to be called for me - especially it being public and all.

That being said my understanding now is that i should call it myself - which is fine, but what suprises me is that LoggerMessage actually already calls IsEnabled:

        /// <summary>
        /// Creates a delegate which can be invoked for logging a message.
        /// </summary>
        /// <param name="logLevel">The <see cref="LogLevel"/></param>
        /// <param name="eventId">The event id</param>
        /// <param name="formatString">The named format string</param>
        /// <returns>A delegate which when invoked creates a log message.</returns>
        public static Action<ILogger, Exception> Define(LogLevel logLevel, EventId eventId, string formatString)
        {
            var formatter = CreateLogValuesFormatter(formatString, expectedNamedParameterCount: 0);

            return (logger, exception) =>
            {
                if (logger.IsEnabled(logLevel))
                {
                    logger.Log(logLevel, eventId, new LogValues(formatter), exception, LogValues.Callback);
                }
            };
        }

source.dot.net

I am now confused - why is IsEnabled checked here, whilst i should already check it in my Log() method?

Related: https://stackoverflow.com/a/44586621/4122889


Document Details

Do not edit this section. It is required for docs.microsoft.com ➟ GitHub issue linking.

sommmen avatar May 25 '20 09:05 sommmen

@BrennanConroy how do you tacklog logging related issues these days? Apply a label, or move to somewhere else?

mkArtakMSFT avatar Oct 21 '20 17:10 mkArtakMSFT

how do you tacklog logging related issues these days? Apply a label, or move to somewhere else?

Most logging issues go to Runtime, but this probably doesn't need to move.

Calling IsEnabled from inside Log is considered a good practice since it can be called from anyone with an ILogger instance and there is no guarantee that they checked IsEnabled manually. On the reverse side, IsEnabled isn't guaranteed to be called by all logger providers so it's better for LoggerMessage to call IsEnabled than to rely on all logger providers calling it. Plus, IsEnabled should be a very fast check in most implementations.

BrennanConroy avatar Oct 21 '20 17:10 BrennanConroy

@Rick-Anderson is the above writeup enough? Can you handle this issue now?

mkArtakMSFT avatar Oct 21 '20 17:10 mkArtakMSFT

cc @serpent5

Rick-Anderson avatar Oct 21 '20 17:10 Rick-Anderson

@Rick-Anderson It looks like this custom logger example also exists over in the .NET Docs. Are there any plans to remove it from your docs here and link to that example? I think the only real difference is in how to register the logger, so I wonder if this IsEnabled stuff would fit better over there, or at least be added to both versions if both continue to exist.

serpent5 avatar Oct 24 '20 20:10 serpent5

We should probably just show how to register the logger here, then point to the .NET Docs.

Rick-Anderson avatar Oct 24 '20 21:10 Rick-Anderson

Moved to https://github.com/dotnet/docs/issues/33978 because this sample doesn't exist anymore in this repo.

Rick-Anderson avatar Feb 15 '23 01:02 Rick-Anderson