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

Sdk diagnostic listener EventLevel based on configured LogLevel #2361

Merged
merged 4 commits into from
Mar 23, 2023
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
Original file line number Diff line number Diff line change
Expand Up @@ -34,10 +34,10 @@ internal class SdkSelfDiagnosticsEventListener : EventListener
private readonly IOtelLogger log;
private readonly List<EventSource>? eventSourcesBeforeConstructor = new();

public SdkSelfDiagnosticsEventListener(EventLevel eventLevel, IOtelLogger logger)
public SdkSelfDiagnosticsEventListener(IOtelLogger logger)
{
log = logger;
logLevel = eventLevel;
logLevel = LogLevelToEventLevel(logger.Level);

List<EventSource>? eventSources;
lock (lockObj)
Expand Down Expand Up @@ -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,
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

this is a default log level - I'm wondering if EventLevel.Informational might be little too verbose. LMK if you think I should change it e.g EventLevel.Warning

Copy link
Member

@pellared pellared Mar 23, 2023

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I would rather consider changing the levels of event logs produced by the SDK instead.

_ => throw new ArgumentOutOfRangeException(nameof(loggerLevel), loggerLevel, null)
};
}
}
3 changes: 1 addition & 2 deletions src/OpenTelemetry.AutoInstrumentation/Instrumentation.cs
Original file line number Diff line number Diff line change
Expand Up @@ -14,7 +14,6 @@
// limitations under the License.
// </copyright>

using System.Diagnostics.Tracing;
using OpenTelemetry.AutoInstrumentation.Configurations;
using OpenTelemetry.AutoInstrumentation.Diagnostics;
using OpenTelemetry.AutoInstrumentation.Loading;
Expand Down Expand Up @@ -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;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -21,17 +21,18 @@ internal class InternalLogger : IOtelLogger
private static readonly object[] NoPropertyValues = Array.Empty<object>();

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)
Expand Down
2 changes: 2 additions & 0 deletions src/OpenTelemetry.AutoInstrumentation/Logging/NoopLogger.cs
Original file line number Diff line number Diff line change
Expand Up @@ -27,6 +27,8 @@ private NoopLogger()
{
}

public LogLevel Level => default;

public bool IsEnabled(LogLevel level)
{
return false;
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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;
Expand All @@ -36,31 +35,43 @@ 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]
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"));
}
}

Expand All @@ -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);
}
}

Expand All @@ -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);
}
}
}