From b02968d617f36034a1f764671d3c55d1b6082b82 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?C=C3=A9dric=20Luthi?= Date: Wed, 30 Mar 2022 01:09:08 +0200 Subject: [PATCH] Observe Microsoft.Extensions.Logging.LogLevel.None Before this commit: `LogLevel.None` is converted to `LogEventLevel.Fatal` and events with a `None` level are logged as fatal. After this commit: `LogLevel.None` is observed and logs and events with a `None` level are ignored. The `None` level is documented as such: > Not used for writing log messages. Specifies that a logging category should not write any messages. Note: this erroneous behaviour was seen in a real-world scenario: 1. `BuildOrgConnectUri CoreClass ()` is [logged as `TraceEventType.Start `][1] 2. `TraceEventType.Start` is [converted to `LogLevel.None`][2] 3. `LogLevel.None ` is [converted to `LogEventLevel.Fatal`][3] As a result, `BuildOrgConnectUri CoreClass ()` is logged as fatal whereas it should have been ignored. [1]: https://github.com/microsoft/PowerPlatform-DataverseServiceClient/blob/0.6.1/src/GeneralTools/DataverseClient/Client/ConnectionService.cs#L3207 [2]: https://github.com/microsoft/PowerPlatform-DataverseServiceClient/blob/0.6.1/src/GeneralTools/DataverseClient/Client/DataverseTraceLogger.cs#L675 [3]: https://github.com/serilog/serilog-extensions-logging/blob/dev/src/Serilog.Extensions.Logging/Extensions/Logging/LevelConvert.cs#L39 --- .../Extensions/Logging/SerilogLogger.cs | 6 ++++- .../SerilogLoggerTests.cs | 23 +++++++++++++++++++ 2 files changed, 28 insertions(+), 1 deletion(-) diff --git a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs index 1b1f895..80ba75f 100644 --- a/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs +++ b/src/Serilog.Extensions.Logging/Extensions/Logging/SerilogLogger.cs @@ -44,7 +44,7 @@ public SerilogLogger( public bool IsEnabled(LogLevel logLevel) { - return _logger.IsEnabled(LevelConvert.ToSerilogLevel(logLevel)); + return logLevel != LogLevel.None && _logger.IsEnabled(LevelConvert.ToSerilogLevel(logLevel)); } public IDisposable BeginScope(TState state) @@ -54,6 +54,10 @@ public IDisposable BeginScope(TState state) public void Log(LogLevel logLevel, EventId eventId, TState state, Exception exception, Func formatter) { + if (logLevel == LogLevel.None) + { + return; + } var level = LevelConvert.ToSerilogLevel(logLevel); if (!_logger.IsEnabled(level)) { diff --git a/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs b/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs index f37e9eb..b60e7f2 100644 --- a/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs +++ b/test/Serilog.Extensions.Logging.Tests/SerilogLoggerTests.cs @@ -55,6 +55,7 @@ public void LogsCorrectLevel() logger.Log(LogLevel.Warning, 0, TestMessage, null, null); logger.Log(LogLevel.Error, 0, TestMessage, null, null); logger.Log(LogLevel.Critical, 0, TestMessage, null, null); + logger.Log(LogLevel.None, 0, TestMessage, null, null); Assert.Equal(6, sink.Writes.Count); Assert.Equal(LogEventLevel.Verbose, sink.Writes[0].Level); @@ -65,6 +66,22 @@ public void LogsCorrectLevel() Assert.Equal(LogEventLevel.Fatal, sink.Writes[5].Level); } + + [Theory] + [InlineData(LogLevel.Trace, true)] + [InlineData(LogLevel.Debug, true)] + [InlineData(LogLevel.Information, true)] + [InlineData(LogLevel.Warning, true)] + [InlineData(LogLevel.Error, true)] + [InlineData(LogLevel.Critical, true)] + [InlineData(LogLevel.None, false)] + public void IsEnabledCorrect(LogLevel logLevel, bool isEnabled) + { + var (logger, _) = SetUp(LogLevel.Trace); + + Assert.Equal(isEnabled, logger.IsEnabled(logLevel)); + } + [Theory] [InlineData(LogLevel.Trace, LogLevel.Trace, 1)] [InlineData(LogLevel.Trace, LogLevel.Debug, 1)] @@ -72,36 +89,42 @@ public void LogsCorrectLevel() [InlineData(LogLevel.Trace, LogLevel.Warning, 1)] [InlineData(LogLevel.Trace, LogLevel.Error, 1)] [InlineData(LogLevel.Trace, LogLevel.Critical, 1)] + [InlineData(LogLevel.Trace, LogLevel.None, 0)] [InlineData(LogLevel.Debug, LogLevel.Trace, 0)] [InlineData(LogLevel.Debug, LogLevel.Debug, 1)] [InlineData(LogLevel.Debug, LogLevel.Information, 1)] [InlineData(LogLevel.Debug, LogLevel.Warning, 1)] [InlineData(LogLevel.Debug, LogLevel.Error, 1)] [InlineData(LogLevel.Debug, LogLevel.Critical, 1)] + [InlineData(LogLevel.Debug, LogLevel.None, 0)] [InlineData(LogLevel.Information, LogLevel.Trace, 0)] [InlineData(LogLevel.Information, LogLevel.Debug, 0)] [InlineData(LogLevel.Information, LogLevel.Information, 1)] [InlineData(LogLevel.Information, LogLevel.Warning, 1)] [InlineData(LogLevel.Information, LogLevel.Error, 1)] [InlineData(LogLevel.Information, LogLevel.Critical, 1)] + [InlineData(LogLevel.Information, LogLevel.None, 0)] [InlineData(LogLevel.Warning, LogLevel.Trace, 0)] [InlineData(LogLevel.Warning, LogLevel.Debug, 0)] [InlineData(LogLevel.Warning, LogLevel.Information, 0)] [InlineData(LogLevel.Warning, LogLevel.Warning, 1)] [InlineData(LogLevel.Warning, LogLevel.Error, 1)] [InlineData(LogLevel.Warning, LogLevel.Critical, 1)] + [InlineData(LogLevel.Warning, LogLevel.None, 0)] [InlineData(LogLevel.Error, LogLevel.Trace, 0)] [InlineData(LogLevel.Error, LogLevel.Debug, 0)] [InlineData(LogLevel.Error, LogLevel.Information, 0)] [InlineData(LogLevel.Error, LogLevel.Warning, 0)] [InlineData(LogLevel.Error, LogLevel.Error, 1)] [InlineData(LogLevel.Error, LogLevel.Critical, 1)] + [InlineData(LogLevel.Error, LogLevel.None, 0)] [InlineData(LogLevel.Critical, LogLevel.Trace, 0)] [InlineData(LogLevel.Critical, LogLevel.Debug, 0)] [InlineData(LogLevel.Critical, LogLevel.Information, 0)] [InlineData(LogLevel.Critical, LogLevel.Warning, 0)] [InlineData(LogLevel.Critical, LogLevel.Error, 0)] [InlineData(LogLevel.Critical, LogLevel.Critical, 1)] + [InlineData(LogLevel.Critical, LogLevel.None, 0)] public void LogsWhenEnabled(LogLevel minLevel, LogLevel logLevel, int expected) { var (logger, sink) = SetUp(minLevel);