From 899ef2ba947cb24713bc5e7685c89faa35cef4d6 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?Mateusz=20=C5=81ach?= Date: Thu, 23 Mar 2023 11:37:03 +0100 Subject: [PATCH] Sdk diagnostic listener EventLevel based on configured LogLevel (#2361) --- .../SdkSelfDiagnosticsEventListener.cs | 16 ++++- .../Instrumentation.cs | 3 +- .../Logging/IOtelLogger.cs | 2 + .../Logging/InternalLogger.cs | 7 +- .../Logging/NoopLogger.cs | 2 + .../SdkSelfDiagnosticsEventListenerTests.cs | 67 +++++++++++++------ 6 files changed, 71 insertions(+), 26 deletions(-) diff --git a/src/OpenTelemetry.AutoInstrumentation/Diagnostics/SdkSelfDiagnosticsEventListener.cs b/src/OpenTelemetry.AutoInstrumentation/Diagnostics/SdkSelfDiagnosticsEventListener.cs index e23402229a..b02590b6cf 100644 --- a/src/OpenTelemetry.AutoInstrumentation/Diagnostics/SdkSelfDiagnosticsEventListener.cs +++ b/src/OpenTelemetry.AutoInstrumentation/Diagnostics/SdkSelfDiagnosticsEventListener.cs @@ -34,10 +34,10 @@ internal class SdkSelfDiagnosticsEventListener : EventListener private readonly IOtelLogger log; private readonly List? eventSourcesBeforeConstructor = new(); - public SdkSelfDiagnosticsEventListener(EventLevel eventLevel, IOtelLogger logger) + public SdkSelfDiagnosticsEventListener(IOtelLogger logger) { log = logger; - logLevel = eventLevel; + logLevel = LogLevelToEventLevel(logger.Level); List? eventSources; lock (lockObj) @@ -120,4 +120,16 @@ protected override void OnEventWritten(EventWrittenEventArgs eventData) break; } } + + private static EventLevel LogLevelToEventLevel(LogLevel loggerLevel) + { + return loggerLevel switch + { + LogLevel.Debug => EventLevel.Verbose, + LogLevel.Error => EventLevel.Error, + LogLevel.Warning => EventLevel.Warning, + LogLevel.Information => EventLevel.Informational, + _ => throw new ArgumentOutOfRangeException(nameof(loggerLevel), loggerLevel, null) + }; + } } diff --git a/src/OpenTelemetry.AutoInstrumentation/Instrumentation.cs b/src/OpenTelemetry.AutoInstrumentation/Instrumentation.cs index 957e43ba6c..db0ae84fa4 100644 --- a/src/OpenTelemetry.AutoInstrumentation/Instrumentation.cs +++ b/src/OpenTelemetry.AutoInstrumentation/Instrumentation.cs @@ -14,7 +14,6 @@ // limitations under the License. // -using System.Diagnostics.Tracing; using OpenTelemetry.AutoInstrumentation.Configurations; using OpenTelemetry.AutoInstrumentation.Diagnostics; using OpenTelemetry.AutoInstrumentation.Loading; @@ -115,7 +114,7 @@ public static void Initialize() if (TracerSettings.Value.TracesEnabled || MetricSettings.Value.MetricsEnabled) { // Initialize SdkSelfDiagnosticsEventListener to create an EventListener for the OpenTelemetry SDK - _sdkEventListener = new(EventLevel.Warning, Logger); + _sdkEventListener = new(Logger); // Register to shutdown events AppDomain.CurrentDomain.ProcessExit += OnExit; diff --git a/src/OpenTelemetry.AutoInstrumentation/Logging/IOtelLogger.cs b/src/OpenTelemetry.AutoInstrumentation/Logging/IOtelLogger.cs index bdb1d065fc..9fc79c31ef 100644 --- a/src/OpenTelemetry.AutoInstrumentation/Logging/IOtelLogger.cs +++ b/src/OpenTelemetry.AutoInstrumentation/Logging/IOtelLogger.cs @@ -18,6 +18,8 @@ namespace OpenTelemetry.AutoInstrumentation.Logging; internal interface IOtelLogger { + LogLevel Level { get; } + bool IsEnabled(LogLevel level); void Debug(string messageTemplate, bool writeToEventLog = true); diff --git a/src/OpenTelemetry.AutoInstrumentation/Logging/InternalLogger.cs b/src/OpenTelemetry.AutoInstrumentation/Logging/InternalLogger.cs index 1e728fef19..c380ed6806 100644 --- a/src/OpenTelemetry.AutoInstrumentation/Logging/InternalLogger.cs +++ b/src/OpenTelemetry.AutoInstrumentation/Logging/InternalLogger.cs @@ -21,17 +21,18 @@ internal class InternalLogger : IOtelLogger private static readonly object[] NoPropertyValues = Array.Empty(); private readonly ISink _sink; - private readonly LogLevel _logLevel; internal InternalLogger(ISink sink, LogLevel logLevel) { _sink = sink ?? throw new ArgumentNullException(nameof(sink)); - _logLevel = logLevel; + Level = logLevel; } + public LogLevel Level { get; } + public bool IsEnabled(LogLevel level) { - return level <= _logLevel; + return level <= Level; } public void Debug(string messageTemplate, bool writeToEventLog) diff --git a/src/OpenTelemetry.AutoInstrumentation/Logging/NoopLogger.cs b/src/OpenTelemetry.AutoInstrumentation/Logging/NoopLogger.cs index a225bd5ae2..08c552d172 100644 --- a/src/OpenTelemetry.AutoInstrumentation/Logging/NoopLogger.cs +++ b/src/OpenTelemetry.AutoInstrumentation/Logging/NoopLogger.cs @@ -27,6 +27,8 @@ private NoopLogger() { } + public LogLevel Level => default; + public bool IsEnabled(LogLevel level) { return false; diff --git a/test/OpenTelemetry.AutoInstrumentation.Tests/Diagnostics/SdkSelfDiagnosticsEventListenerTests.cs b/test/OpenTelemetry.AutoInstrumentation.Tests/Diagnostics/SdkSelfDiagnosticsEventListenerTests.cs index 299b42b228..ad8109872a 100644 --- a/test/OpenTelemetry.AutoInstrumentation.Tests/Diagnostics/SdkSelfDiagnosticsEventListenerTests.cs +++ b/test/OpenTelemetry.AutoInstrumentation.Tests/Diagnostics/SdkSelfDiagnosticsEventListenerTests.cs @@ -16,7 +16,6 @@ // Source originated from https://github.com/open-telemetry/opentelemetry-dotnet/blob/23609730ddd73c860553de847e67c9b2226cff94/test/OpenTelemetry.Tests/Internal/SelfDiagnosticsEventListenerTest.cs -using System.Collections.Generic; using System.Diagnostics.Tracing; using FluentAssertions; using FluentAssertions.Execution; @@ -36,14 +35,22 @@ public class SdkSelfDiagnosticsEventListenerTests public void EventSourceSetup_LowerSeverity() { var testSink = new TestSink(); - var logger = new InternalLogger(testSink, LogLevel.Debug); - using var listener = new SdkSelfDiagnosticsEventListener(EventLevel.Error, logger); + var logger = new InternalLogger(testSink, LogLevel.Error); + using var listener = new SdkSelfDiagnosticsEventListener(logger); + + AspNetTelemetryEventSourceForTests.Log.Information(); + AspNetTelemetryEventSourceForTests.Log.Warning(); + OpenTelemetrySdkEventSourceForTests.Log.Verbose(); - // Emitting a Verbose event. Or any EventSource event with lower severity than Error. - AspNetTelemetryEventSourceForTests.Log.ActivityRestored("123"); - OpenTelemetrySdkEventSourceForTests.Log.ActivityStarted("Activity started", "1"); + // Events with both Critical and Error EventLevel are logged as errors. + OpenTelemetrySdkEventSourceForTests.Log.Error(); + OpenTelemetrySdkEventSourceForTests.Log.Critical(); - testSink.Messages.Should().BeEmpty("events with lower severity than error should not be written."); + using (new AssertionScope()) + { + testSink.Messages.Count.Should().Be(2); + testSink.Messages.Should().OnlyContain(msg => msg.Contains("Error")); + } } [Fact] @@ -51,16 +58,20 @@ public void EventSourceSetup_HigherSeverity() { var testSink = new TestSink(); var logger = new InternalLogger(testSink, LogLevel.Debug); - using var listener = new SdkSelfDiagnosticsEventListener(EventLevel.Verbose, logger); + using var listener = new SdkSelfDiagnosticsEventListener(logger); - // Emitting a Verbose event. Or any EventSource event with lower severity than Error. - AspNetTelemetryEventSourceForTests.Log.ActivityRestored("123"); - OpenTelemetrySdkEventSourceForTests.Log.ActivityStarted("Activity started", "1"); + AspNetTelemetryEventSourceForTests.Log.Information(); + AspNetTelemetryEventSourceForTests.Log.Warning(); + OpenTelemetrySdkEventSourceForTests.Log.Verbose(); + OpenTelemetrySdkEventSourceForTests.Log.Error(); using (new AssertionScope()) { - testSink.Messages.Should().Contain(msg => msg.Contains("EventSource=OpenTelemetry-Instrumentation-AspNet-Telemetry-For-Tests, Message=Activity restored, Id='123'")); - testSink.Messages.Should().Contain(msg => msg.Contains("EventSource=OpenTelemetry-Sdk-For-Tests, Message=Activity started.")); + testSink.Messages.Count.Should().Be(4); + testSink.Messages.Should().Contain(msg => msg.Contains("Error")); + testSink.Messages.Should().Contain(msg => msg.Contains("Warning")); + testSink.Messages.Should().Contain(msg => msg.Contains("Information")); + testSink.Messages.Should().Contain(msg => msg.Contains("Debug")); } } @@ -73,10 +84,16 @@ private AspNetTelemetryEventSourceForTests() { } - [Event(4, Message = "Activity restored, Id='{0}'", Level = EventLevel.Informational)] - public void ActivityRestored(string id) + [Event(4, Message = "Activity info.", Level = EventLevel.Informational)] + public void Information() + { + WriteEvent(4); + } + + [Event(5, Message = "Activity warning.", Level = EventLevel.Warning)] + public void Warning() { - WriteEvent(4, id); + WriteEvent(5); } } @@ -89,10 +106,22 @@ private OpenTelemetrySdkEventSourceForTests() { } - [Event(24, Message = "Activity started. OperationName = '{0}', Id = '{1}'.", Level = EventLevel.Verbose)] - public void ActivityStarted(string operationName, string id) + [Event(24, Message = "Activity verbose.", Level = EventLevel.Verbose)] + public void Verbose() + { + WriteEvent(24); + } + + [Event(25, Message = "Activity error.", Level = EventLevel.Error)] + public void Error() + { + WriteEvent(25); + } + + [Event(26, Message = "Activity critical.", Level = EventLevel.Critical)] + public void Critical() { - WriteEvent(24, operationName, id); + WriteEvent(26); } } }