From b6e175d2b0c665a4db7df4841db6c46dd5b547f2 Mon Sep 17 00:00:00 2001 From: "Eric J. Smith" Date: Thu, 18 Mar 2021 11:34:56 -0500 Subject: [PATCH 01/11] Add AddOpenTelemetrySelfDiagnosticsLogging to OpenTelemetry.Extensions.Hosting --- examples/AspNetCore/Startup.cs | 4 + examples/AspNetCore/appsettings.json | 1 + .../netstandard2.0/PublicAPI.Unshipped.txt | 1 + .../EventSourceEventFormatting.cs | 93 +++++++++++ .../SelfDiagnosticsEventLogForwarder.cs | 158 ++++++++++++++++++ .../SelfDiagnosticsLoggingHostedService.cs | 54 ++++++ .../OpenTelemetryServicesExtensions.cs | 41 +++++ 7 files changed, 352 insertions(+) create mode 100644 src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatting.cs create mode 100644 src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs create mode 100644 src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsLoggingHostedService.cs diff --git a/examples/AspNetCore/Startup.cs b/examples/AspNetCore/Startup.cs index 625c7c16615..cd5e8188065 100644 --- a/examples/AspNetCore/Startup.cs +++ b/examples/AspNetCore/Startup.cs @@ -55,6 +55,10 @@ public void ConfigureServices(IServiceCollection services) } }); + // Writes OpenTelemetry self diagnostics events to the logging system + // needs to happen before AddOpenTelemetryTracing in order to capture startup issues + services.AddOpenTelemetrySelfDiagnosticsLogging(); + // Switch between Zipkin/Jaeger by setting UseExporter in appsettings.json. var exporter = this.Configuration.GetValue("UseExporter").ToLowerInvariant(); switch (exporter) diff --git a/examples/AspNetCore/appsettings.json b/examples/AspNetCore/appsettings.json index edd66d9db45..d46306b50e6 100644 --- a/examples/AspNetCore/appsettings.json +++ b/examples/AspNetCore/appsettings.json @@ -2,6 +2,7 @@ "Logging": { "LogLevel": { "Default": "Information", + "OpenTelemetry": "Trace", "Microsoft": "Warning", "Microsoft.Hosting.Lifetime": "Information" } diff --git a/src/OpenTelemetry.Extensions.Hosting/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt b/src/OpenTelemetry.Extensions.Hosting/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt index 364f10146db..287fa8513c9 100644 --- a/src/OpenTelemetry.Extensions.Hosting/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt +++ b/src/OpenTelemetry.Extensions.Hosting/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt @@ -1,5 +1,6 @@ Microsoft.Extensions.DependencyInjection.OpenTelemetryServicesExtensions OpenTelemetry.Trace.TracerProviderBuilderExtensions +static Microsoft.Extensions.DependencyInjection.OpenTelemetryServicesExtensions.AddOpenTelemetrySelfDiagnosticsLogging(this Microsoft.Extensions.DependencyInjection.IServiceCollection services) -> Microsoft.Extensions.DependencyInjection.IServiceCollection static Microsoft.Extensions.DependencyInjection.OpenTelemetryServicesExtensions.AddOpenTelemetryTracing(this Microsoft.Extensions.DependencyInjection.IServiceCollection services) -> Microsoft.Extensions.DependencyInjection.IServiceCollection static Microsoft.Extensions.DependencyInjection.OpenTelemetryServicesExtensions.AddOpenTelemetryTracing(this Microsoft.Extensions.DependencyInjection.IServiceCollection services, System.Action configure) -> Microsoft.Extensions.DependencyInjection.IServiceCollection static OpenTelemetry.Trace.TracerProviderBuilderExtensions.AddInstrumentation(this OpenTelemetry.Trace.TracerProviderBuilder tracerProviderBuilder) -> OpenTelemetry.Trace.TracerProviderBuilder diff --git a/src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatting.cs b/src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatting.cs new file mode 100644 index 00000000000..c472c8c0397 --- /dev/null +++ b/src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatting.cs @@ -0,0 +1,93 @@ +// +// Copyright The OpenTelemetry Authors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +// + +using System; +using System.Diagnostics.Tracing; +using System.Globalization; +using System.Linq; +using System.Text; + +namespace OpenTelemetry.Internal +{ + internal static class EventSourceEventFormatting + { + private static readonly StringBuilder Builder = new StringBuilder(); + + public static string Format(EventWrittenEventArgs eventData) + { + var payloadArray = eventData.Payload?.ToArray() ?? Array.Empty(); + + ProcessPayloadArray(payloadArray); + + if (eventData.Message != null) + { + try + { + return string.Format(CultureInfo.InvariantCulture, eventData.Message, payloadArray); + } + catch (FormatException) + { + } + } + + var stringBuilder = Builder; + stringBuilder.Clear(); + + stringBuilder.Append(eventData.EventName); + + if (!string.IsNullOrWhiteSpace(eventData.Message)) + { + stringBuilder.AppendLine(); + stringBuilder.Append(nameof(eventData.Message)).Append(" = ").Append(eventData.Message); + } + + if (eventData.PayloadNames != null) + { + for (int i = 0; i < eventData.PayloadNames.Count; i++) + { + stringBuilder.AppendLine(); + stringBuilder.Append(eventData.PayloadNames[i]).Append(" = ").Append(payloadArray[i]); + } + } + + return stringBuilder.ToString(); + } + + private static void ProcessPayloadArray(object[] payloadArray) + { + for (int i = 0; i < payloadArray.Length; i++) + { + payloadArray[i] = FormatValue(payloadArray[i]); + } + } + + private static object FormatValue(object o) + { + if (o is byte[] bytes) + { + var stringBuilder = new StringBuilder(); + foreach (byte b in bytes) + { + stringBuilder.AppendFormat(CultureInfo.InvariantCulture, "{0:X2}", b); + } + + return stringBuilder.ToString(); + } + + return o; + } + } +} diff --git a/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs new file mode 100644 index 00000000000..4d2fb57a28c --- /dev/null +++ b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs @@ -0,0 +1,158 @@ +// +// Copyright The OpenTelemetry Authors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +// + +using System; +using System.Collections; +using System.Collections.Concurrent; +using System.Collections.Generic; +using System.Diagnostics.Tracing; +using Microsoft.Extensions.Logging; + +namespace OpenTelemetry.Internal +{ + /// + /// SelfDiagnosticsEventListener class enables the events from OpenTelemetry event sources + /// and write the events to an ILoggerFactory. + /// + internal class SelfDiagnosticsEventLogForwarder : EventListener + { + private const string EventSourceNamePrefix = "OpenTelemetry-"; + private readonly object lockObj = new object(); + private readonly EventLevel logLevel; + private readonly List eventSourcesBeforeConstructor = new List(); + private readonly ILoggerFactory loggerFactory; + private readonly ConcurrentDictionary loggers = new ConcurrentDictionary(); + + private readonly Func formatMessage = FormatMessage; + + internal SelfDiagnosticsEventLogForwarder(EventLevel logLevel, ILoggerFactory loggerFactory) + { + this.logLevel = logLevel; + this.loggerFactory = loggerFactory; + + List eventSources; + lock (this.lockObj) + { + eventSources = this.eventSourcesBeforeConstructor; + this.eventSourcesBeforeConstructor = null; + } + + foreach (var eventSource in eventSources) + { + this.EnableEvents(eventSource, this.logLevel, EventKeywords.All); + } + } + + protected override void OnEventSourceCreated(EventSource eventSource) + { + if (eventSource.Name.StartsWith(EventSourceNamePrefix, StringComparison.Ordinal)) + { + // If there are EventSource classes already initialized as of now, this method would be called from + // the base class constructor before the first line of code in SelfDiagnosticsEventListener constructor. + // In this case logLevel is always its default value, "LogAlways". + // Thus we should save the event source and enable them later, when code runs in constructor. + if (this.eventSourcesBeforeConstructor != null) + { + lock (this.lockObj) + { + if (this.eventSourcesBeforeConstructor != null) + { + this.eventSourcesBeforeConstructor.Add(eventSource); + return; + } + } + } + + this.EnableEvents(eventSource, this.logLevel, EventKeywords.All); + } + + base.OnEventSourceCreated(eventSource); + } + + /// + /// This method records the events from event sources to the logging system. + /// + /// Data of the EventSource event. + protected override void OnEventWritten(EventWrittenEventArgs eventData) + { + if (this.loggerFactory == null) + { + return; + } + + var logger = this.loggers.GetOrAdd(eventData.EventSource.Name, name => this.loggerFactory.CreateLogger(ToLoggerName(name))); + logger.Log(MapLevel(eventData.Level), new EventId(eventData.EventId, eventData.EventName), new EventSourceEvent(eventData), null, this.formatMessage); + } + + private static string ToLoggerName(string name) + { + return name.Replace('-', '.'); + } + + private static LogLevel MapLevel(EventLevel level) + { + switch (level) + { + case EventLevel.Critical: + return LogLevel.Critical; + case EventLevel.Error: + return LogLevel.Error; + case EventLevel.Informational: + return LogLevel.Information; + case EventLevel.Verbose: + return LogLevel.Debug; + case EventLevel.Warning: + return LogLevel.Warning; + case EventLevel.LogAlways: + return LogLevel.Information; + default: + return LogLevel.None; + } + } + + private static string FormatMessage(EventSourceEvent eventSourceEvent, Exception exception) + { + return EventSourceEventFormatting.Format(eventSourceEvent.EventData); + } + + private readonly struct EventSourceEvent : IReadOnlyList> + { + public EventSourceEvent(EventWrittenEventArgs eventData) + { + this.EventData = eventData; + } + + public EventWrittenEventArgs EventData { get; } + + public int Count => this.EventData.PayloadNames.Count; + + public KeyValuePair this[int index] => new KeyValuePair(this.EventData.PayloadNames[index], this.EventData.Payload[index]); + + public IEnumerator> GetEnumerator() + { + for (int i = 0; i < this.Count; i++) + { + yield return new KeyValuePair(this.EventData.PayloadNames[i], this.EventData.Payload[i]); + } + } + + IEnumerator IEnumerable.GetEnumerator() + { + return this.GetEnumerator(); + } + } + } +} diff --git a/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsLoggingHostedService.cs b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsLoggingHostedService.cs new file mode 100644 index 00000000000..8c3f558877d --- /dev/null +++ b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsLoggingHostedService.cs @@ -0,0 +1,54 @@ +// +// Copyright The OpenTelemetry Authors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +// + +using System; +using System.Threading; +using System.Threading.Tasks; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Hosting; +using Microsoft.Extensions.Logging; +using OpenTelemetry.Internal; + +namespace OpenTelemetry.Extensions.Hosting.Implementation +{ + internal class SelfDiagnosticsLoggingHostedService : IHostedService + { + private readonly IServiceProvider serviceProvider; + private IDisposable forwarder; + + public SelfDiagnosticsLoggingHostedService(IServiceProvider serviceProvider) + { + this.serviceProvider = serviceProvider; + } + + public Task StartAsync(CancellationToken cancellationToken) + { + // The sole purpose of this HostedService is to + // start forwarding the self-diagnostics events + // to the logger factory + this.forwarder = new SelfDiagnosticsEventLogForwarder(System.Diagnostics.Tracing.EventLevel.LogAlways, this.serviceProvider.GetService()); + + return Task.CompletedTask; + } + + public Task StopAsync(CancellationToken cancellationToken) + { + this.forwarder?.Dispose(); + + return Task.CompletedTask; + } + } +} diff --git a/src/OpenTelemetry.Extensions.Hosting/OpenTelemetryServicesExtensions.cs b/src/OpenTelemetry.Extensions.Hosting/OpenTelemetryServicesExtensions.cs index 982bd013bfb..eeae0984a33 100644 --- a/src/OpenTelemetry.Extensions.Hosting/OpenTelemetryServicesExtensions.cs +++ b/src/OpenTelemetry.Extensions.Hosting/OpenTelemetryServicesExtensions.cs @@ -55,6 +55,47 @@ public static IServiceCollection AddOpenTelemetryTracing(this IServiceCollection return services.AddOpenTelemetryTracing(sp => builder.Build(sp)); } + /// + /// Adds OpenTelemetry TracerProvider to the specified . + /// + /// The to add services to. + /// The action to configure TracerProviderBuilder. + /// The so that additional calls can be chained. + public static IServiceCollection AddOpenTelemetryTracing(this IServiceCollection services, Action configure) + { + if (configure is null) + { + throw new ArgumentNullException(nameof(configure)); + } + + var builder = Sdk.CreateTracerProviderBuilder(); + services.AddOpenTelemetryTracing((sp) => + { + configure(sp, builder); + return builder.Build(); + }); + return services; + } + + /// + /// Writes OpenTelemetry self diagnostics events to the logging system. + /// + /// + /// This needs to be called before in order to capture startup errors. + /// /// The to add services to. + /// The so that additional calls can be chained. + public static IServiceCollection AddOpenTelemetrySelfDiagnosticsLogging(this IServiceCollection services) + { + if (services is null) + { + throw new ArgumentNullException(nameof(services)); + } + + services.AddHostedService(); + + return services; + } + /// /// Adds OpenTelemetry TracerProvider to the specified . /// From 94f23735e80f0aa541602b1d92070ec211441b97 Mon Sep 17 00:00:00 2001 From: "Eric J. Smith" Date: Thu, 18 Mar 2021 16:40:51 -0500 Subject: [PATCH 02/11] Fix build error --- .../OpenTelemetryServicesExtensions.cs | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/src/OpenTelemetry.Extensions.Hosting/OpenTelemetryServicesExtensions.cs b/src/OpenTelemetry.Extensions.Hosting/OpenTelemetryServicesExtensions.cs index eeae0984a33..ae269cd00eb 100644 --- a/src/OpenTelemetry.Extensions.Hosting/OpenTelemetryServicesExtensions.cs +++ b/src/OpenTelemetry.Extensions.Hosting/OpenTelemetryServicesExtensions.cs @@ -17,6 +17,7 @@ using System; using Microsoft.Extensions.DependencyInjection.Extensions; using Microsoft.Extensions.Hosting; +using OpenTelemetry; using OpenTelemetry.Extensions.Hosting.Implementation; using OpenTelemetry.Trace; @@ -81,8 +82,9 @@ public static IServiceCollection AddOpenTelemetryTracing(this IServiceCollection /// Writes OpenTelemetry self diagnostics events to the logging system. /// /// - /// This needs to be called before in order to capture startup errors. - /// /// The to add services to. + /// This needs to be called before in order to capture startup errors. + /// + /// The to add services to. /// The so that additional calls can be chained. public static IServiceCollection AddOpenTelemetrySelfDiagnosticsLogging(this IServiceCollection services) { From 916ca35ac079beceed99855592936d1c62b9abef Mon Sep 17 00:00:00 2001 From: "Eric J. Smith" Date: Mon, 22 Mar 2021 10:53:10 -0500 Subject: [PATCH 03/11] Add StringBuilderPool --- ...atting.cs => EventSourceEventFormatter.cs} | 63 +++++++++++-------- .../SelfDiagnosticsEventLogForwarder.cs | 2 +- .../OpenTelemetry.Extensions.Hosting.csproj | 1 + .../Internal/StringBuilderPool.cs | 56 +++++++++++++++++ 4 files changed, 96 insertions(+), 26 deletions(-) rename src/OpenTelemetry.Extensions.Hosting/Implementation/{EventSourceEventFormatting.cs => EventSourceEventFormatter.cs} (54%) create mode 100644 src/OpenTelemetry/Internal/StringBuilderPool.cs diff --git a/src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatting.cs b/src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatter.cs similarity index 54% rename from src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatting.cs rename to src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatter.cs index c472c8c0397..315d642695c 100644 --- a/src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatting.cs +++ b/src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatter.cs @@ -18,52 +18,57 @@ using System.Diagnostics.Tracing; using System.Globalization; using System.Linq; -using System.Text; namespace OpenTelemetry.Internal { - internal static class EventSourceEventFormatting + internal static class EventSourceEventFormatter { - private static readonly StringBuilder Builder = new StringBuilder(); + private static readonly object[] EmptyPayload = Array.Empty(); public static string Format(EventWrittenEventArgs eventData) { - var payloadArray = eventData.Payload?.ToArray() ?? Array.Empty(); + var payloadCollection = eventData.Payload.ToArray() ?? EmptyPayload; - ProcessPayloadArray(payloadArray); + ProcessPayloadArray(payloadCollection); if (eventData.Message != null) { try { - return string.Format(CultureInfo.InvariantCulture, eventData.Message, payloadArray); + return string.Format(CultureInfo.InvariantCulture, eventData.Message, payloadCollection); } catch (FormatException) { } } - var stringBuilder = Builder; - stringBuilder.Clear(); + var stringBuilder = StringBuilderPool.Allocate(); - stringBuilder.Append(eventData.EventName); - - if (!string.IsNullOrWhiteSpace(eventData.Message)) + try { - stringBuilder.AppendLine(); - stringBuilder.Append(nameof(eventData.Message)).Append(" = ").Append(eventData.Message); - } + stringBuilder.Append(eventData.EventName); - if (eventData.PayloadNames != null) - { - for (int i = 0; i < eventData.PayloadNames.Count; i++) + if (!string.IsNullOrWhiteSpace(eventData.Message)) { stringBuilder.AppendLine(); - stringBuilder.Append(eventData.PayloadNames[i]).Append(" = ").Append(payloadArray[i]); + stringBuilder.Append(nameof(eventData.Message)).Append(" = ").Append(eventData.Message); } - } - return stringBuilder.ToString(); + if (eventData.PayloadNames != null) + { + for (int i = 0; i < eventData.PayloadNames.Count; i++) + { + stringBuilder.AppendLine(); + stringBuilder.Append(eventData.PayloadNames[i]).Append(" = ").Append(payloadCollection[i]); + } + } + + return stringBuilder.ToString(); + } + finally + { + StringBuilderPool.Release(stringBuilder); + } } private static void ProcessPayloadArray(object[] payloadArray) @@ -78,13 +83,21 @@ private static object FormatValue(object o) { if (o is byte[] bytes) { - var stringBuilder = new StringBuilder(); - foreach (byte b in bytes) + var stringBuilder = StringBuilderPool.Allocate(); + + try { - stringBuilder.AppendFormat(CultureInfo.InvariantCulture, "{0:X2}", b); - } + foreach (byte b in bytes) + { + stringBuilder.AppendFormat(CultureInfo.InvariantCulture, "{0:X2}", b); + } - return stringBuilder.ToString(); + return stringBuilder.ToString(); + } + finally + { + StringBuilderPool.Release(stringBuilder); + } } return o; diff --git a/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs index 4d2fb57a28c..e4aa257b7cb 100644 --- a/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs +++ b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs @@ -125,7 +125,7 @@ private static LogLevel MapLevel(EventLevel level) private static string FormatMessage(EventSourceEvent eventSourceEvent, Exception exception) { - return EventSourceEventFormatting.Format(eventSourceEvent.EventData); + return EventSourceEventFormatter.Format(eventSourceEvent.EventData); } private readonly struct EventSourceEvent : IReadOnlyList> diff --git a/src/OpenTelemetry.Extensions.Hosting/OpenTelemetry.Extensions.Hosting.csproj b/src/OpenTelemetry.Extensions.Hosting/OpenTelemetry.Extensions.Hosting.csproj index 27fcf6fef9f..9c40cdb9c8d 100644 --- a/src/OpenTelemetry.Extensions.Hosting/OpenTelemetry.Extensions.Hosting.csproj +++ b/src/OpenTelemetry.Extensions.Hosting/OpenTelemetry.Extensions.Hosting.csproj @@ -10,6 +10,7 @@ + diff --git a/src/OpenTelemetry/Internal/StringBuilderPool.cs b/src/OpenTelemetry/Internal/StringBuilderPool.cs new file mode 100644 index 00000000000..6cf778426d8 --- /dev/null +++ b/src/OpenTelemetry/Internal/StringBuilderPool.cs @@ -0,0 +1,56 @@ +// +// Copyright The OpenTelemetry Authors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +// + +using System.Collections.Concurrent; +using System.Text; + +namespace OpenTelemetry.Internal +{ + internal class StringBuilderPool + { + private static readonly ConcurrentStack StringBuilderStack; + + static StringBuilderPool() + { + StringBuilderStack = new ConcurrentStack(); + } + + public StringBuilderPool() + { + } + + public static StringBuilder Allocate() + { + if (StringBuilderStack.TryPop(out var stringBuilder)) + { + return stringBuilder; + } + + return new StringBuilder(1024); + } + + public static void Release(StringBuilder builder) + { + if (builder == null) + { + return; + } + + builder.Clear(); + StringBuilderStack.Push(builder); + } + } +} From 7210445c2baf9006b65108011843fab17665a11c Mon Sep 17 00:00:00 2001 From: "Eric J. Smith" Date: Mon, 22 Mar 2021 11:03:46 -0500 Subject: [PATCH 04/11] Fix file header --- .../Implementation/EventSourceEventFormatter.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatter.cs b/src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatter.cs index 315d642695c..5ba04e4f737 100644 --- a/src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatter.cs +++ b/src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatter.cs @@ -1,4 +1,4 @@ -// +// // Copyright The OpenTelemetry Authors // // Licensed under the Apache License, Version 2.0 (the "License"); From aaccb0d240e2e4606ec4acc5ac15f6cf7b0704f1 Mon Sep 17 00:00:00 2001 From: "Eric J. Smith" Date: Tue, 23 Mar 2021 14:30:02 -0500 Subject: [PATCH 05/11] Add more performant StringBuilder pool. Add log forwarder tests. --- build/Common.nonprod.props | 1 + .../EventSourceEventFormatter.cs | 8 +- .../Internal/StringBuilderPool.cs | 68 ++++++++++++---- ...nTelemetry.Extensions.Hosting.Tests.csproj | 2 + .../SelfDiagnosticsEventLogForwarderTest.cs | 77 +++++++++++++++++++ .../Internal/StringBuilderPoolTest.cs | 41 ++++++++++ .../Shared/TestActivityProcessor.cs | 12 ++- 7 files changed, 190 insertions(+), 19 deletions(-) create mode 100644 test/OpenTelemetry.Extensions.Hosting.Tests/SelfDiagnosticsEventLogForwarderTest.cs create mode 100644 test/OpenTelemetry.Tests/Internal/StringBuilderPoolTest.cs diff --git a/build/Common.nonprod.props b/build/Common.nonprod.props index 57593f6ca76..6de7e00d15e 100644 --- a/build/Common.nonprod.props +++ b/build/Common.nonprod.props @@ -43,6 +43,7 @@ [5.0.0] [2.4.3,3.0) [2.4.1,3.0) + [10.0.2,11.0) diff --git a/src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatter.cs b/src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatter.cs index 5ba04e4f737..553a8795762 100644 --- a/src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatter.cs +++ b/src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatter.cs @@ -42,7 +42,7 @@ public static string Format(EventWrittenEventArgs eventData) } } - var stringBuilder = StringBuilderPool.Allocate(); + var stringBuilder = StringBuilderPool.Instance.Get(); try { @@ -67,7 +67,7 @@ public static string Format(EventWrittenEventArgs eventData) } finally { - StringBuilderPool.Release(stringBuilder); + StringBuilderPool.Instance.Return(stringBuilder); } } @@ -83,7 +83,7 @@ private static object FormatValue(object o) { if (o is byte[] bytes) { - var stringBuilder = StringBuilderPool.Allocate(); + var stringBuilder = StringBuilderPool.Instance.Get(); try { @@ -96,7 +96,7 @@ private static object FormatValue(object o) } finally { - StringBuilderPool.Release(stringBuilder); + StringBuilderPool.Instance.Return(stringBuilder); } } diff --git a/src/OpenTelemetry/Internal/StringBuilderPool.cs b/src/OpenTelemetry/Internal/StringBuilderPool.cs index 6cf778426d8..29cc802fbb3 100644 --- a/src/OpenTelemetry/Internal/StringBuilderPool.cs +++ b/src/OpenTelemetry/Internal/StringBuilderPool.cs @@ -14,43 +14,83 @@ // limitations under the License. // -using System.Collections.Concurrent; +using System; +using System.Diagnostics; using System.Text; +using System.Threading; namespace OpenTelemetry.Internal { + // Based on Microsoft.Extensions.ObjectPool + // https://github.com/dotnet/aspnetcore/blob/main/src/ObjectPool/src/DefaultObjectPool.cs internal class StringBuilderPool { - private static readonly ConcurrentStack StringBuilderStack; + internal static StringBuilderPool Instance = new StringBuilderPool(); - static StringBuilderPool() + private protected readonly ObjectWrapper[] items; + private protected StringBuilder firstItem; + + public StringBuilderPool() + : this(Environment.ProcessorCount * 2) { - StringBuilderStack = new ConcurrentStack(); } - public StringBuilderPool() + public StringBuilderPool(int maximumRetained) { + // -1 due to _firstItem + this.items = new ObjectWrapper[maximumRetained - 1]; } - public static StringBuilder Allocate() + public int MaximumRetainedCapacity { get; set; } = 4 * 1024; + + public int InitialCapacity { get; set; } = 100; + + public StringBuilder Get() { - if (StringBuilderStack.TryPop(out var stringBuilder)) + var item = this.firstItem; + if (item == null || Interlocked.CompareExchange(ref this.firstItem, null, item) != item) { - return stringBuilder; + var items = this.items; + for (var i = 0; i < items.Length; i++) + { + item = items[i].Element; + if (item != null && Interlocked.CompareExchange(ref items[i].Element, null, item) == item) + { + return item; + } + } + + item = new StringBuilder(this.InitialCapacity); } - return new StringBuilder(1024); + return item; } - public static void Release(StringBuilder builder) + public bool Return(StringBuilder item) { - if (builder == null) + if (item.Capacity > this.MaximumRetainedCapacity) { - return; + // Too big. Discard this one. + return false; } - builder.Clear(); - StringBuilderStack.Push(builder); + item.Clear(); + + if (this.firstItem != null || Interlocked.CompareExchange(ref this.firstItem, item, null) != null) + { + var items = this.items; + for (var i = 0; i < items.Length && Interlocked.CompareExchange(ref items[i].Element, item, null) != null; ++i) + { + } + } + + return true; + } + + [DebuggerDisplay("{Element}")] + private protected struct ObjectWrapper + { + public StringBuilder Element; } } } diff --git a/test/OpenTelemetry.Extensions.Hosting.Tests/OpenTelemetry.Extensions.Hosting.Tests.csproj b/test/OpenTelemetry.Extensions.Hosting.Tests/OpenTelemetry.Extensions.Hosting.Tests.csproj index 06e5ae590b5..16340914d7f 100644 --- a/test/OpenTelemetry.Extensions.Hosting.Tests/OpenTelemetry.Extensions.Hosting.Tests.csproj +++ b/test/OpenTelemetry.Extensions.Hosting.Tests/OpenTelemetry.Extensions.Hosting.Tests.csproj @@ -9,11 +9,13 @@ + + all diff --git a/test/OpenTelemetry.Extensions.Hosting.Tests/SelfDiagnosticsEventLogForwarderTest.cs b/test/OpenTelemetry.Extensions.Hosting.Tests/SelfDiagnosticsEventLogForwarderTest.cs new file mode 100644 index 00000000000..411481a1e16 --- /dev/null +++ b/test/OpenTelemetry.Extensions.Hosting.Tests/SelfDiagnosticsEventLogForwarderTest.cs @@ -0,0 +1,77 @@ +// +// Copyright The OpenTelemetry Authors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +// + +using System.Linq; +using System.Threading.Tasks; +using Foundatio.Xunit; +using Microsoft.Extensions.DependencyInjection; +using Microsoft.Extensions.Hosting; +using Microsoft.Extensions.Logging; +using OpenTelemetry.Extensions.Hosting.Implementation; +using OpenTelemetry.Tests; +using OpenTelemetry.Trace; +using Xunit; + +namespace OpenTelemetry.Extensions.Hosting.Tests +{ + public class SelfDiagnosticsEventLogForwarderTest + { + [Fact] + public async Task AddOpenTelemetryTracerProvider_HostBuilt_OpenTelemetrySdk_RegisteredAsSingleton() + { + const string TestSourceName = "TestSource"; + + using TestActivityProcessor testActivityProcessor = new TestActivityProcessor( + onStart: a => { }, + onEnd: a => { }, + onFlush: () => { throw new System.Exception(); }); + + var loggerFactory = new TestLoggerFactory + { + MinimumLevel = LogLevel.Trace, + }; + + var builder = new HostBuilder().ConfigureServices(services => + { + services.AddSingleton(loggerFactory); + services.AddOpenTelemetrySelfDiagnosticsLogging(); + services.AddOpenTelemetryTracing(b => b + .SetSampler(new AlwaysOnSampler()) + .AddSource(TestSourceName) + .AddProcessor(testActivityProcessor)); + }); + + var host = builder.Build(); + var hostedServices = host.Services.GetServices().ToList(); + + Assert.Equal(2, hostedServices.Count); + Assert.True(hostedServices.First().GetType() == typeof(SelfDiagnosticsLoggingHostedService)); + Assert.True(hostedServices.Last().GetType() == typeof(TelemetryHostedService)); + + await host.StartAsync(); + + var tracerProvider = host.Services.GetRequiredService(); + Assert.NotNull(tracerProvider); + + tracerProvider.GetTracer(TestSourceName).StartRootSpan("Test Activity"); + tracerProvider.ForceFlush(); + + Assert.NotEmpty(loggerFactory.LogEntries); + Assert.Contains(loggerFactory.LogEntries, l => l.CategoryName == "OpenTelemetry.Sdk" && l.Message.Contains("Activity started") && l.Message.Contains("Test Activity")); + Assert.Contains(loggerFactory.LogEntries, l => l.CategoryName == "OpenTelemetry.Sdk" && l.Message.Contains("ForceFlush") && l.Message.Contains("Exception")); + } + } +} diff --git a/test/OpenTelemetry.Tests/Internal/StringBuilderPoolTest.cs b/test/OpenTelemetry.Tests/Internal/StringBuilderPoolTest.cs new file mode 100644 index 00000000000..5d2ad706875 --- /dev/null +++ b/test/OpenTelemetry.Tests/Internal/StringBuilderPoolTest.cs @@ -0,0 +1,41 @@ +// +// Copyright The OpenTelemetry Authors +// +// Licensed under the Apache License, Version 2.0 (the "License"); +// you may not use this file except in compliance with the License. +// You may obtain a copy of the License at +// +// http://www.apache.org/licenses/LICENSE-2.0 +// +// Unless required by applicable law or agreed to in writing, software +// distributed under the License is distributed on an "AS IS" BASIS, +// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +// See the License for the specific language governing permissions and +// limitations under the License. +// + +using System; +using OpenTelemetry.Internal; +using Xunit; + +namespace OpenTelemetry.Tests.Internal +{ + public class StringBuilderPoolTest + { + [Fact] + public void GetAndReturnSameInstance() + { + // Arrange + var pool = new StringBuilderPool(); + + var obj1 = pool.Get(); + pool.Return(obj1); + + // Act + var obj2 = pool.Get(); + + // Assert + Assert.Same(obj1, obj2); + } + } +} diff --git a/test/OpenTelemetry.Tests/Shared/TestActivityProcessor.cs b/test/OpenTelemetry.Tests/Shared/TestActivityProcessor.cs index 0ec90b07b75..050132b9f42 100644 --- a/test/OpenTelemetry.Tests/Shared/TestActivityProcessor.cs +++ b/test/OpenTelemetry.Tests/Shared/TestActivityProcessor.cs @@ -23,15 +23,19 @@ internal class TestActivityProcessor : BaseProcessor { public Action StartAction; public Action EndAction; + public Action FlushAction; + public Action ShutdownAction; public TestActivityProcessor() { } - public TestActivityProcessor(Action onStart, Action onEnd) + public TestActivityProcessor(Action onStart, Action onEnd, Action onFlush = null, Action onShutdown = null) { this.StartAction = onStart; this.EndAction = onEnd; + this.FlushAction = onFlush; + this.ShutdownAction = onShutdown; } public bool ShutdownCalled { get; private set; } = false; @@ -53,12 +57,18 @@ public override void OnEnd(Activity span) protected override bool OnForceFlush(int timeoutMilliseconds) { this.ForceFlushCalled = true; + + this.FlushAction?.Invoke(); + return true; } protected override bool OnShutdown(int timeoutMilliseconds) { this.ShutdownCalled = true; + + this.ShutdownAction?.Invoke(); + return true; } From e9afa14d7263ae85bc540ed24a9a94ad28a18fb0 Mon Sep 17 00:00:00 2001 From: "Eric J. Smith" Date: Fri, 26 Mar 2021 06:21:50 -0500 Subject: [PATCH 06/11] Change EventLevels based on logging configuration --- .../SelfDiagnosticsEventLogForwarder.cs | 176 +++++++++++++++--- .../SelfDiagnosticsLoggingHostedService.cs | 3 +- .../SelfDiagnosticsEventLogForwarderTest.cs | 68 ++++++- 3 files changed, 212 insertions(+), 35 deletions(-) diff --git a/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs index e4aa257b7cb..43818cd5d9f 100644 --- a/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs +++ b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs @@ -20,6 +20,7 @@ using System.Collections.Generic; using System.Diagnostics.Tracing; using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Options; namespace OpenTelemetry.Internal { @@ -31,52 +32,33 @@ internal class SelfDiagnosticsEventLogForwarder : EventListener { private const string EventSourceNamePrefix = "OpenTelemetry-"; private readonly object lockObj = new object(); - private readonly EventLevel logLevel; - private readonly List eventSourcesBeforeConstructor = new List(); + private readonly EventLevel? defaultMinEventLevel; + private readonly List eventSources = new List(); private readonly ILoggerFactory loggerFactory; - private readonly ConcurrentDictionary loggers = new ConcurrentDictionary(); + private readonly IOptionsMonitor loggerFilterOptions; + private readonly ConcurrentDictionary loggers = new ConcurrentDictionary(); private readonly Func formatMessage = FormatMessage; - internal SelfDiagnosticsEventLogForwarder(EventLevel logLevel, ILoggerFactory loggerFactory) + internal SelfDiagnosticsEventLogForwarder(ILoggerFactory loggerFactory, IOptionsMonitor loggerFilterOptions, EventLevel? defaultMinEventLevel = null) { - this.logLevel = logLevel; this.loggerFactory = loggerFactory; + this.loggerFilterOptions = loggerFilterOptions; + this.defaultMinEventLevel = defaultMinEventLevel; - List eventSources; - lock (this.lockObj) - { - eventSources = this.eventSourcesBeforeConstructor; - this.eventSourcesBeforeConstructor = null; - } - - foreach (var eventSource in eventSources) - { - this.EnableEvents(eventSource, this.logLevel, EventKeywords.All); - } + loggerFilterOptions.OnChange(o => this.SetEventSourceLevels()); } protected override void OnEventSourceCreated(EventSource eventSource) { if (eventSource.Name.StartsWith(EventSourceNamePrefix, StringComparison.Ordinal)) { - // If there are EventSource classes already initialized as of now, this method would be called from - // the base class constructor before the first line of code in SelfDiagnosticsEventListener constructor. - // In this case logLevel is always its default value, "LogAlways". - // Thus we should save the event source and enable them later, when code runs in constructor. - if (this.eventSourcesBeforeConstructor != null) + lock (this.lockObj) { - lock (this.lockObj) - { - if (this.eventSourcesBeforeConstructor != null) - { - this.eventSourcesBeforeConstructor.Add(eventSource); - return; - } - } + this.eventSources.Add(eventSource); } - this.EnableEvents(eventSource, this.logLevel, EventKeywords.All); + this.SetEventSourceLevel(eventSource); } base.OnEventSourceCreated(eventSource); @@ -93,7 +75,11 @@ protected override void OnEventWritten(EventWrittenEventArgs eventData) return; } - var logger = this.loggers.GetOrAdd(eventData.EventSource.Name, name => this.loggerFactory.CreateLogger(ToLoggerName(name))); + if (!this.loggers.TryGetValue(eventData.EventSource, out var logger)) + { + logger = this.loggers.GetOrAdd(eventData.EventSource, eventSource => this.loggerFactory.CreateLogger(ToLoggerName(eventSource.Name))); + } + logger.Log(MapLevel(eventData.Level), new EventId(eventData.EventId, eventData.EventName), new EventSourceEvent(eventData), null, this.formatMessage); } @@ -123,11 +109,139 @@ private static LogLevel MapLevel(EventLevel level) } } + private static EventLevel? MapLevel(LogLevel? level) + { + if (!level.HasValue) + { + return null; + } + + switch (level) + { + case LogLevel.Critical: + return EventLevel.Critical; + case LogLevel.Error: + return EventLevel.Error; + case LogLevel.Information: + return EventLevel.Informational; + case LogLevel.Debug: + return EventLevel.Verbose; + case LogLevel.Trace: + return EventLevel.LogAlways; + case LogLevel.Warning: + return EventLevel.Warning; + default: + return null; + } + } + private static string FormatMessage(EventSourceEvent eventSourceEvent, Exception exception) { return EventSourceEventFormatter.Format(eventSourceEvent.EventData); } + private EventLevel? GetEventLevel(string category) + { + var options = this.loggerFilterOptions?.CurrentValue; + if (options == null) + { + return this.defaultMinEventLevel; + } + + EventLevel? minLevel = MapLevel(options.MinLevel); + + LoggerFilterRule current = null; + foreach (LoggerFilterRule rule in options.Rules) + { + if (this.IsBetterRule(rule, current, category)) + { + current = rule; + } + } + + if (current != null) + { + minLevel = MapLevel(current.LogLevel); + } + + return minLevel; + } + + private bool IsBetterRule(LoggerFilterRule rule, LoggerFilterRule current, string category) + { + string categoryName = rule.CategoryName; + if (categoryName != null) + { + const char WildcardChar = '*'; + + int wildcardIndex = categoryName.IndexOf(WildcardChar); + if (wildcardIndex != -1 && + categoryName.IndexOf(WildcardChar, wildcardIndex + 1) != -1) + { + // can't have more than one wildcard + return false; + } + + ReadOnlySpan prefix, suffix; + if (wildcardIndex == -1) + { + prefix = categoryName.AsSpan(); + suffix = default; + } + else + { + prefix = categoryName.AsSpan(0, wildcardIndex); + suffix = categoryName.AsSpan(wildcardIndex + 1); + } + + if (!category.AsSpan().StartsWith(prefix, StringComparison.OrdinalIgnoreCase) || + !category.AsSpan().EndsWith(suffix, StringComparison.OrdinalIgnoreCase)) + { + return false; + } + } + + if (current?.CategoryName != null) + { + if (rule.CategoryName == null) + { + return false; + } + + if (current.CategoryName.Length > rule.CategoryName.Length) + { + return false; + } + } + + return true; + } + + private void SetEventSourceLevels() + { + lock (this.lockObj) + { + foreach (var eventSource in this.eventSources) + { + this.SetEventSourceLevel(eventSource); + } + } + } + + private void SetEventSourceLevel(EventSource eventSource) + { + EventLevel? eventLevel = this.GetEventLevel(ToLoggerName(eventSource.Name)); + + if (eventLevel.HasValue) + { + this.EnableEvents(eventSource, eventLevel.Value); + } + else + { + this.DisableEvents(eventSource); + } + } + private readonly struct EventSourceEvent : IReadOnlyList> { public EventSourceEvent(EventWrittenEventArgs eventData) diff --git a/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsLoggingHostedService.cs b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsLoggingHostedService.cs index 8c3f558877d..585225b9165 100644 --- a/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsLoggingHostedService.cs +++ b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsLoggingHostedService.cs @@ -20,6 +20,7 @@ using Microsoft.Extensions.DependencyInjection; using Microsoft.Extensions.Hosting; using Microsoft.Extensions.Logging; +using Microsoft.Extensions.Options; using OpenTelemetry.Internal; namespace OpenTelemetry.Extensions.Hosting.Implementation @@ -39,7 +40,7 @@ public Task StartAsync(CancellationToken cancellationToken) // The sole purpose of this HostedService is to // start forwarding the self-diagnostics events // to the logger factory - this.forwarder = new SelfDiagnosticsEventLogForwarder(System.Diagnostics.Tracing.EventLevel.LogAlways, this.serviceProvider.GetService()); + this.forwarder = new SelfDiagnosticsEventLogForwarder(this.serviceProvider.GetService(), this.serviceProvider.GetService>(), System.Diagnostics.Tracing.EventLevel.Warning); return Task.CompletedTask; } diff --git a/test/OpenTelemetry.Extensions.Hosting.Tests/SelfDiagnosticsEventLogForwarderTest.cs b/test/OpenTelemetry.Extensions.Hosting.Tests/SelfDiagnosticsEventLogForwarderTest.cs index 411481a1e16..91ab3b56909 100644 --- a/test/OpenTelemetry.Extensions.Hosting.Tests/SelfDiagnosticsEventLogForwarderTest.cs +++ b/test/OpenTelemetry.Extensions.Hosting.Tests/SelfDiagnosticsEventLogForwarderTest.cs @@ -14,9 +14,12 @@ // limitations under the License. // +using System.Collections.Generic; using System.Linq; using System.Threading.Tasks; using Foundatio.Xunit; +using Microsoft.Extensions.Configuration; +using Microsoft.Extensions.Configuration.Memory; using Microsoft.Extensions.DependencyInjection; using Microsoft.Extensions.Hosting; using Microsoft.Extensions.Logging; @@ -30,7 +33,7 @@ namespace OpenTelemetry.Extensions.Hosting.Tests public class SelfDiagnosticsEventLogForwarderTest { [Fact] - public async Task AddOpenTelemetryTracerProvider_HostBuilt_OpenTelemetrySdk_RegisteredAsSingleton() + public async Task AddOpenTelemetrySelfDiagnosticsLogging_WillCaptureTraceEvents() { const string TestSourceName = "TestSource"; @@ -44,7 +47,14 @@ public async Task AddOpenTelemetryTracerProvider_HostBuilt_OpenTelemetrySdk_Regi MinimumLevel = LogLevel.Trace, }; - var builder = new HostBuilder().ConfigureServices(services => + var configData = new Dictionary + { + { "Logging:LogLevel:Default", "Information" }, + { "Logging:LogLevel:OpenTelemetry", "Trace" }, + }; + + var config = new ConfigurationBuilder().AddInMemoryCollection(configData).Build(); + var builder = new HostBuilder().ConfigureLogging(b => b.AddConfiguration(config)).ConfigureServices(services => { services.AddSingleton(loggerFactory); services.AddOpenTelemetrySelfDiagnosticsLogging(); @@ -66,12 +76,64 @@ public async Task AddOpenTelemetryTracerProvider_HostBuilt_OpenTelemetrySdk_Regi var tracerProvider = host.Services.GetRequiredService(); Assert.NotNull(tracerProvider); - tracerProvider.GetTracer(TestSourceName).StartRootSpan("Test Activity"); + tracerProvider.GetTracer(TestSourceName).StartRootSpan("Test Activity").End(); tracerProvider.ForceFlush(); Assert.NotEmpty(loggerFactory.LogEntries); Assert.Contains(loggerFactory.LogEntries, l => l.CategoryName == "OpenTelemetry.Sdk" && l.Message.Contains("Activity started") && l.Message.Contains("Test Activity")); Assert.Contains(loggerFactory.LogEntries, l => l.CategoryName == "OpenTelemetry.Sdk" && l.Message.Contains("ForceFlush") && l.Message.Contains("Exception")); } + + [Fact] + public async Task AddOpenTelemetrySelfDiagnosticsLogging_WillCaptureErrorEvents() + { + const string TestSourceName = "TestSource"; + + using TestActivityProcessor testActivityProcessor = new TestActivityProcessor( + onStart: a => { }, + onEnd: a => { }, + onFlush: () => { throw new System.Exception(); }); + + var loggerFactory = new TestLoggerFactory + { + MinimumLevel = LogLevel.Trace, + }; + + var configData = new Dictionary + { + { "Logging:LogLevel:Default", "Information" }, + { "Logging:LogLevel:OpenTelemetry", "Error" }, + }; + + var config = new ConfigurationBuilder().AddInMemoryCollection(configData).Build(); + var builder = new HostBuilder().ConfigureLogging(b => b.AddConfiguration(config)).ConfigureServices(services => + { + services.AddSingleton(loggerFactory); + services.AddOpenTelemetrySelfDiagnosticsLogging(); + services.AddOpenTelemetryTracing(b => b + .SetSampler(new AlwaysOnSampler()) + .AddSource(TestSourceName) + .AddProcessor(testActivityProcessor)); + }); + + var host = builder.Build(); + var hostedServices = host.Services.GetServices().ToList(); + + Assert.Equal(2, hostedServices.Count); + Assert.True(hostedServices.First().GetType() == typeof(SelfDiagnosticsLoggingHostedService)); + Assert.True(hostedServices.Last().GetType() == typeof(TelemetryHostedService)); + + await host.StartAsync(); + + var tracerProvider = host.Services.GetRequiredService(); + Assert.NotNull(tracerProvider); + + tracerProvider.GetTracer(TestSourceName).StartRootSpan("Test Activity").End(); + tracerProvider.ForceFlush(); + + Assert.NotEmpty(loggerFactory.LogEntries); + Assert.DoesNotContain(loggerFactory.LogEntries, l => l.CategoryName == "OpenTelemetry.Sdk" && l.Message.Contains("Activity started") && l.Message.Contains("Test Activity")); + Assert.Contains(loggerFactory.LogEntries, l => l.CategoryName == "OpenTelemetry.Sdk" && l.Message.Contains("ForceFlush") && l.Message.Contains("Exception")); + } } } From c82a223f699744fb81c01e615e295867c23fc1c0 Mon Sep 17 00:00:00 2001 From: "Eric J. Smith" Date: Thu, 8 Apr 2021 22:48:15 -0500 Subject: [PATCH 07/11] Inject dependencies instead of using service location --- .../SelfDiagnosticsLoggingHostedService.cs | 12 +++++++----- 1 file changed, 7 insertions(+), 5 deletions(-) diff --git a/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsLoggingHostedService.cs b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsLoggingHostedService.cs index 585225b9165..b2b9ec8a15d 100644 --- a/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsLoggingHostedService.cs +++ b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsLoggingHostedService.cs @@ -15,9 +15,9 @@ // using System; +using System.Diagnostics.Tracing; using System.Threading; using System.Threading.Tasks; -using Microsoft.Extensions.DependencyInjection; using Microsoft.Extensions.Hosting; using Microsoft.Extensions.Logging; using Microsoft.Extensions.Options; @@ -27,12 +27,14 @@ namespace OpenTelemetry.Extensions.Hosting.Implementation { internal class SelfDiagnosticsLoggingHostedService : IHostedService { - private readonly IServiceProvider serviceProvider; + private readonly ILoggerFactory loggerFactory; + private readonly IOptionsMonitor loggerFilterOptions; private IDisposable forwarder; - public SelfDiagnosticsLoggingHostedService(IServiceProvider serviceProvider) + public SelfDiagnosticsLoggingHostedService(ILoggerFactory loggerFactory, IOptionsMonitor loggerFilterOptions) { - this.serviceProvider = serviceProvider; + this.loggerFactory = loggerFactory; + this.loggerFilterOptions = loggerFilterOptions; } public Task StartAsync(CancellationToken cancellationToken) @@ -40,7 +42,7 @@ public Task StartAsync(CancellationToken cancellationToken) // The sole purpose of this HostedService is to // start forwarding the self-diagnostics events // to the logger factory - this.forwarder = new SelfDiagnosticsEventLogForwarder(this.serviceProvider.GetService(), this.serviceProvider.GetService>(), System.Diagnostics.Tracing.EventLevel.Warning); + this.forwarder = new SelfDiagnosticsEventLogForwarder(this.loggerFactory, this.loggerFilterOptions, EventLevel.Warning); return Task.CompletedTask; } From b6a73470831f9610f5d2ff3d2930bb1c2b2065fa Mon Sep 17 00:00:00 2001 From: "Eric J. Smith" Date: Thu, 8 Apr 2021 23:35:22 -0500 Subject: [PATCH 08/11] Move logging configuration into the trace builder --- examples/AspNetCore/Startup.cs | 8 +-- .../netstandard2.0/PublicAPI.Unshipped.txt | 2 +- .../SelfDiagnosticsEventLogForwarder.cs | 50 +++++++------------ .../SelfDiagnosticsLoggingHostedService.cs | 8 +-- .../OpenTelemetryServicesExtensions.cs | 47 +---------------- .../Trace/TracerProviderBuilderExtensions.cs | 17 +++++++ .../SelfDiagnosticsEventLogForwarderTest.cs | 4 +- 7 files changed, 47 insertions(+), 89 deletions(-) diff --git a/examples/AspNetCore/Startup.cs b/examples/AspNetCore/Startup.cs index cd5e8188065..8a4aed1e89f 100644 --- a/examples/AspNetCore/Startup.cs +++ b/examples/AspNetCore/Startup.cs @@ -55,16 +55,13 @@ public void ConfigureServices(IServiceCollection services) } }); - // Writes OpenTelemetry self diagnostics events to the logging system - // needs to happen before AddOpenTelemetryTracing in order to capture startup issues - services.AddOpenTelemetrySelfDiagnosticsLogging(); - // Switch between Zipkin/Jaeger by setting UseExporter in appsettings.json. var exporter = this.Configuration.GetValue("UseExporter").ToLowerInvariant(); switch (exporter) { case "jaeger": services.AddOpenTelemetryTracing((builder) => builder + .AddSelfDiagnosticsLogging() .SetResourceBuilder(ResourceBuilder.CreateDefault().AddService(this.Configuration.GetValue("Jaeger:ServiceName"))) .AddAspNetCoreInstrumentation() .AddHttpClientInstrumentation() @@ -74,6 +71,7 @@ public void ConfigureServices(IServiceCollection services) break; case "zipkin": services.AddOpenTelemetryTracing((builder) => builder + .AddSelfDiagnosticsLogging() .AddAspNetCoreInstrumentation() .AddHttpClientInstrumentation() .AddZipkinExporter()); @@ -87,6 +85,7 @@ public void ConfigureServices(IServiceCollection services) AppContext.SetSwitch("System.Net.Http.SocketsHttpHandler.Http2UnencryptedSupport", true); services.AddOpenTelemetryTracing((builder) => builder + .AddSelfDiagnosticsLogging() .SetResourceBuilder(ResourceBuilder.CreateDefault().AddService(this.Configuration.GetValue("Otlp:ServiceName"))) .AddAspNetCoreInstrumentation() .AddHttpClientInstrumentation() @@ -97,6 +96,7 @@ public void ConfigureServices(IServiceCollection services) break; default: services.AddOpenTelemetryTracing((builder) => builder + .AddSelfDiagnosticsLogging() .AddAspNetCoreInstrumentation() .AddHttpClientInstrumentation() .AddConsoleExporter()); diff --git a/src/OpenTelemetry.Extensions.Hosting/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt b/src/OpenTelemetry.Extensions.Hosting/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt index 287fa8513c9..b0e45a92a8b 100644 --- a/src/OpenTelemetry.Extensions.Hosting/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt +++ b/src/OpenTelemetry.Extensions.Hosting/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt @@ -1,10 +1,10 @@ Microsoft.Extensions.DependencyInjection.OpenTelemetryServicesExtensions OpenTelemetry.Trace.TracerProviderBuilderExtensions -static Microsoft.Extensions.DependencyInjection.OpenTelemetryServicesExtensions.AddOpenTelemetrySelfDiagnosticsLogging(this Microsoft.Extensions.DependencyInjection.IServiceCollection services) -> Microsoft.Extensions.DependencyInjection.IServiceCollection static Microsoft.Extensions.DependencyInjection.OpenTelemetryServicesExtensions.AddOpenTelemetryTracing(this Microsoft.Extensions.DependencyInjection.IServiceCollection services) -> Microsoft.Extensions.DependencyInjection.IServiceCollection static Microsoft.Extensions.DependencyInjection.OpenTelemetryServicesExtensions.AddOpenTelemetryTracing(this Microsoft.Extensions.DependencyInjection.IServiceCollection services, System.Action configure) -> Microsoft.Extensions.DependencyInjection.IServiceCollection static OpenTelemetry.Trace.TracerProviderBuilderExtensions.AddInstrumentation(this OpenTelemetry.Trace.TracerProviderBuilder tracerProviderBuilder) -> OpenTelemetry.Trace.TracerProviderBuilder static OpenTelemetry.Trace.TracerProviderBuilderExtensions.AddProcessor(this OpenTelemetry.Trace.TracerProviderBuilder tracerProviderBuilder) -> OpenTelemetry.Trace.TracerProviderBuilder +static OpenTelemetry.Trace.TracerProviderBuilderExtensions.AddSelfDiagnosticsLogging(this OpenTelemetry.Trace.TracerProviderBuilder tracerProviderBuilder) -> OpenTelemetry.Trace.TracerProviderBuilder static OpenTelemetry.Trace.TracerProviderBuilderExtensions.Build(this OpenTelemetry.Trace.TracerProviderBuilder tracerProviderBuilder, System.IServiceProvider serviceProvider) -> OpenTelemetry.Trace.TracerProvider static OpenTelemetry.Trace.TracerProviderBuilderExtensions.Configure(this OpenTelemetry.Trace.TracerProviderBuilder tracerProviderBuilder, System.Action configure) -> OpenTelemetry.Trace.TracerProviderBuilder static OpenTelemetry.Trace.TracerProviderBuilderExtensions.SetSampler(this OpenTelemetry.Trace.TracerProviderBuilder tracerProviderBuilder) -> OpenTelemetry.Trace.TracerProviderBuilder diff --git a/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs index 43818cd5d9f..cfd1652e03f 100644 --- a/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs +++ b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs @@ -90,23 +90,16 @@ private static string ToLoggerName(string name) private static LogLevel MapLevel(EventLevel level) { - switch (level) + return level switch { - case EventLevel.Critical: - return LogLevel.Critical; - case EventLevel.Error: - return LogLevel.Error; - case EventLevel.Informational: - return LogLevel.Information; - case EventLevel.Verbose: - return LogLevel.Debug; - case EventLevel.Warning: - return LogLevel.Warning; - case EventLevel.LogAlways: - return LogLevel.Information; - default: - return LogLevel.None; - } + EventLevel.Critical => LogLevel.Critical, + EventLevel.Error => LogLevel.Error, + EventLevel.Informational => LogLevel.Information, + EventLevel.Verbose => LogLevel.Debug, + EventLevel.Warning => LogLevel.Warning, + EventLevel.LogAlways => LogLevel.Information, + _ => LogLevel.None, + }; } private static EventLevel? MapLevel(LogLevel? level) @@ -116,23 +109,16 @@ private static LogLevel MapLevel(EventLevel level) return null; } - switch (level) + return level switch { - case LogLevel.Critical: - return EventLevel.Critical; - case LogLevel.Error: - return EventLevel.Error; - case LogLevel.Information: - return EventLevel.Informational; - case LogLevel.Debug: - return EventLevel.Verbose; - case LogLevel.Trace: - return EventLevel.LogAlways; - case LogLevel.Warning: - return EventLevel.Warning; - default: - return null; - } + LogLevel.Critical => EventLevel.Critical, + LogLevel.Error => EventLevel.Error, + LogLevel.Information => EventLevel.Informational, + LogLevel.Debug => EventLevel.Verbose, + LogLevel.Trace => EventLevel.LogAlways, + LogLevel.Warning => EventLevel.Warning, + _ => null, + }; } private static string FormatMessage(EventSourceEvent eventSourceEvent, Exception exception) diff --git a/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsLoggingHostedService.cs b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsLoggingHostedService.cs index b2b9ec8a15d..f18a642200b 100644 --- a/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsLoggingHostedService.cs +++ b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsLoggingHostedService.cs @@ -29,21 +29,21 @@ internal class SelfDiagnosticsLoggingHostedService : IHostedService { private readonly ILoggerFactory loggerFactory; private readonly IOptionsMonitor loggerFilterOptions; - private IDisposable forwarder; + private readonly IDisposable forwarder; public SelfDiagnosticsLoggingHostedService(ILoggerFactory loggerFactory, IOptionsMonitor loggerFilterOptions) { this.loggerFactory = loggerFactory; this.loggerFilterOptions = loggerFilterOptions; - } - public Task StartAsync(CancellationToken cancellationToken) - { // The sole purpose of this HostedService is to // start forwarding the self-diagnostics events // to the logger factory this.forwarder = new SelfDiagnosticsEventLogForwarder(this.loggerFactory, this.loggerFilterOptions, EventLevel.Warning); + } + public Task StartAsync(CancellationToken cancellationToken) + { return Task.CompletedTask; } diff --git a/src/OpenTelemetry.Extensions.Hosting/OpenTelemetryServicesExtensions.cs b/src/OpenTelemetry.Extensions.Hosting/OpenTelemetryServicesExtensions.cs index ae269cd00eb..807d0412b42 100644 --- a/src/OpenTelemetry.Extensions.Hosting/OpenTelemetryServicesExtensions.cs +++ b/src/OpenTelemetry.Extensions.Hosting/OpenTelemetryServicesExtensions.cs @@ -15,9 +15,6 @@ // using System; -using Microsoft.Extensions.DependencyInjection.Extensions; -using Microsoft.Extensions.Hosting; -using OpenTelemetry; using OpenTelemetry.Extensions.Hosting.Implementation; using OpenTelemetry.Trace; @@ -56,48 +53,6 @@ public static IServiceCollection AddOpenTelemetryTracing(this IServiceCollection return services.AddOpenTelemetryTracing(sp => builder.Build(sp)); } - /// - /// Adds OpenTelemetry TracerProvider to the specified . - /// - /// The to add services to. - /// The action to configure TracerProviderBuilder. - /// The so that additional calls can be chained. - public static IServiceCollection AddOpenTelemetryTracing(this IServiceCollection services, Action configure) - { - if (configure is null) - { - throw new ArgumentNullException(nameof(configure)); - } - - var builder = Sdk.CreateTracerProviderBuilder(); - services.AddOpenTelemetryTracing((sp) => - { - configure(sp, builder); - return builder.Build(); - }); - return services; - } - - /// - /// Writes OpenTelemetry self diagnostics events to the logging system. - /// - /// - /// This needs to be called before in order to capture startup errors. - /// - /// The to add services to. - /// The so that additional calls can be chained. - public static IServiceCollection AddOpenTelemetrySelfDiagnosticsLogging(this IServiceCollection services) - { - if (services is null) - { - throw new ArgumentNullException(nameof(services)); - } - - services.AddHostedService(); - - return services; - } - /// /// Adds OpenTelemetry TracerProvider to the specified . /// @@ -118,7 +73,7 @@ private static IServiceCollection AddOpenTelemetryTracing(this IServiceCollectio try { - services.TryAddEnumerable(ServiceDescriptor.Singleton()); + services.AddHostedService(); return services.AddSingleton(s => createTracerProvider(s)); } catch (Exception ex) diff --git a/src/OpenTelemetry.Extensions.Hosting/Trace/TracerProviderBuilderExtensions.cs b/src/OpenTelemetry.Extensions.Hosting/Trace/TracerProviderBuilderExtensions.cs index 16ecfbb43b9..fdc70314e8f 100644 --- a/src/OpenTelemetry.Extensions.Hosting/Trace/TracerProviderBuilderExtensions.cs +++ b/src/OpenTelemetry.Extensions.Hosting/Trace/TracerProviderBuilderExtensions.cs @@ -16,6 +16,8 @@ using System; using System.Diagnostics; +using Microsoft.Extensions.DependencyInjection; +using OpenTelemetry.Extensions.Hosting.Implementation; namespace OpenTelemetry.Trace { @@ -41,6 +43,21 @@ public static TracerProviderBuilder AddInstrumentation(this TracerProviderBui return tracerProviderBuilder; } + /// + /// Writes OpenTelemetry self diagnostics events to the logging system. + /// + /// . + /// The supplied for chaining. + public static TracerProviderBuilder AddSelfDiagnosticsLogging(this TracerProviderBuilder tracerProviderBuilder) + { + if (tracerProviderBuilder is TracerProviderBuilderHosting tracerProviderBuilderHosting) + { + tracerProviderBuilderHosting.Services.AddHostedService(); + } + + return tracerProviderBuilder; + } + /// /// Adds a processor to the provider. /// diff --git a/test/OpenTelemetry.Extensions.Hosting.Tests/SelfDiagnosticsEventLogForwarderTest.cs b/test/OpenTelemetry.Extensions.Hosting.Tests/SelfDiagnosticsEventLogForwarderTest.cs index 91ab3b56909..3664f8c8f33 100644 --- a/test/OpenTelemetry.Extensions.Hosting.Tests/SelfDiagnosticsEventLogForwarderTest.cs +++ b/test/OpenTelemetry.Extensions.Hosting.Tests/SelfDiagnosticsEventLogForwarderTest.cs @@ -57,8 +57,8 @@ public async Task AddOpenTelemetrySelfDiagnosticsLogging_WillCaptureTraceEvents( var builder = new HostBuilder().ConfigureLogging(b => b.AddConfiguration(config)).ConfigureServices(services => { services.AddSingleton(loggerFactory); - services.AddOpenTelemetrySelfDiagnosticsLogging(); services.AddOpenTelemetryTracing(b => b + .AddSelfDiagnosticsLogging() .SetSampler(new AlwaysOnSampler()) .AddSource(TestSourceName) .AddProcessor(testActivityProcessor)); @@ -109,8 +109,8 @@ public async Task AddOpenTelemetrySelfDiagnosticsLogging_WillCaptureErrorEvents( var builder = new HostBuilder().ConfigureLogging(b => b.AddConfiguration(config)).ConfigureServices(services => { services.AddSingleton(loggerFactory); - services.AddOpenTelemetrySelfDiagnosticsLogging(); services.AddOpenTelemetryTracing(b => b + .AddSelfDiagnosticsLogging() .SetSampler(new AlwaysOnSampler()) .AddSource(TestSourceName) .AddProcessor(testActivityProcessor)); From 30b4390ad3429d92b3947b0d54deb3a07b328d45 Mon Sep 17 00:00:00 2001 From: "Eric J. Smith" Date: Thu, 8 Apr 2021 23:53:36 -0500 Subject: [PATCH 09/11] Disable forwarding on dispose --- .../SelfDiagnosticsEventLogForwarder.cs | 19 ++++++- .../SelfDiagnosticsLoggingHostedService.cs | 9 ++-- .../SelfDiagnosticsEventLogForwarderTest.cs | 52 +------------------ 3 files changed, 25 insertions(+), 55 deletions(-) diff --git a/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs index cfd1652e03f..3f095eaae61 100644 --- a/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs +++ b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs @@ -49,6 +49,12 @@ internal SelfDiagnosticsEventLogForwarder(ILoggerFactory loggerFactory, IOptions loggerFilterOptions.OnChange(o => this.SetEventSourceLevels()); } + public override void Dispose() + { + this.StopForwarding(); + base.Dispose(); + } + protected override void OnEventSourceCreated(EventSource eventSource) { if (eventSource.Name.StartsWith(EventSourceNamePrefix, StringComparison.Ordinal)) @@ -214,9 +220,20 @@ private void SetEventSourceLevels() } } + private void StopForwarding() + { + lock (this.lockObj) + { + foreach (var eventSource in this.eventSources) + { + this.DisableEvents(eventSource); + } + } + } + private void SetEventSourceLevel(EventSource eventSource) { - EventLevel? eventLevel = this.GetEventLevel(ToLoggerName(eventSource.Name)); + var eventLevel = this.GetEventLevel(ToLoggerName(eventSource.Name)); if (eventLevel.HasValue) { diff --git a/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsLoggingHostedService.cs b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsLoggingHostedService.cs index f18a642200b..40e7f5f86d3 100644 --- a/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsLoggingHostedService.cs +++ b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsLoggingHostedService.cs @@ -25,7 +25,7 @@ namespace OpenTelemetry.Extensions.Hosting.Implementation { - internal class SelfDiagnosticsLoggingHostedService : IHostedService + internal class SelfDiagnosticsLoggingHostedService : IHostedService, IDisposable { private readonly ILoggerFactory loggerFactory; private readonly IOptionsMonitor loggerFilterOptions; @@ -42,6 +42,11 @@ public SelfDiagnosticsLoggingHostedService(ILoggerFactory loggerFactory, IOption this.forwarder = new SelfDiagnosticsEventLogForwarder(this.loggerFactory, this.loggerFilterOptions, EventLevel.Warning); } + public void Dispose() + { + this.forwarder?.Dispose(); + } + public Task StartAsync(CancellationToken cancellationToken) { return Task.CompletedTask; @@ -49,8 +54,6 @@ public Task StartAsync(CancellationToken cancellationToken) public Task StopAsync(CancellationToken cancellationToken) { - this.forwarder?.Dispose(); - return Task.CompletedTask; } } diff --git a/test/OpenTelemetry.Extensions.Hosting.Tests/SelfDiagnosticsEventLogForwarderTest.cs b/test/OpenTelemetry.Extensions.Hosting.Tests/SelfDiagnosticsEventLogForwarderTest.cs index 3664f8c8f33..bb7603f5c7f 100644 --- a/test/OpenTelemetry.Extensions.Hosting.Tests/SelfDiagnosticsEventLogForwarderTest.cs +++ b/test/OpenTelemetry.Extensions.Hosting.Tests/SelfDiagnosticsEventLogForwarderTest.cs @@ -82,58 +82,8 @@ public async Task AddOpenTelemetrySelfDiagnosticsLogging_WillCaptureTraceEvents( Assert.NotEmpty(loggerFactory.LogEntries); Assert.Contains(loggerFactory.LogEntries, l => l.CategoryName == "OpenTelemetry.Sdk" && l.Message.Contains("Activity started") && l.Message.Contains("Test Activity")); Assert.Contains(loggerFactory.LogEntries, l => l.CategoryName == "OpenTelemetry.Sdk" && l.Message.Contains("ForceFlush") && l.Message.Contains("Exception")); - } - - [Fact] - public async Task AddOpenTelemetrySelfDiagnosticsLogging_WillCaptureErrorEvents() - { - const string TestSourceName = "TestSource"; - - using TestActivityProcessor testActivityProcessor = new TestActivityProcessor( - onStart: a => { }, - onEnd: a => { }, - onFlush: () => { throw new System.Exception(); }); - - var loggerFactory = new TestLoggerFactory - { - MinimumLevel = LogLevel.Trace, - }; - - var configData = new Dictionary - { - { "Logging:LogLevel:Default", "Information" }, - { "Logging:LogLevel:OpenTelemetry", "Error" }, - }; - - var config = new ConfigurationBuilder().AddInMemoryCollection(configData).Build(); - var builder = new HostBuilder().ConfigureLogging(b => b.AddConfiguration(config)).ConfigureServices(services => - { - services.AddSingleton(loggerFactory); - services.AddOpenTelemetryTracing(b => b - .AddSelfDiagnosticsLogging() - .SetSampler(new AlwaysOnSampler()) - .AddSource(TestSourceName) - .AddProcessor(testActivityProcessor)); - }); - - var host = builder.Build(); - var hostedServices = host.Services.GetServices().ToList(); - - Assert.Equal(2, hostedServices.Count); - Assert.True(hostedServices.First().GetType() == typeof(SelfDiagnosticsLoggingHostedService)); - Assert.True(hostedServices.Last().GetType() == typeof(TelemetryHostedService)); - - await host.StartAsync(); - - var tracerProvider = host.Services.GetRequiredService(); - Assert.NotNull(tracerProvider); - - tracerProvider.GetTracer(TestSourceName).StartRootSpan("Test Activity").End(); - tracerProvider.ForceFlush(); - Assert.NotEmpty(loggerFactory.LogEntries); - Assert.DoesNotContain(loggerFactory.LogEntries, l => l.CategoryName == "OpenTelemetry.Sdk" && l.Message.Contains("Activity started") && l.Message.Contains("Test Activity")); - Assert.Contains(loggerFactory.LogEntries, l => l.CategoryName == "OpenTelemetry.Sdk" && l.Message.Contains("ForceFlush") && l.Message.Contains("Exception")); + host.Dispose(); } } } From 71ad1f5615ac9412d2122189b6d780d1b3bd218a Mon Sep 17 00:00:00 2001 From: "Eric J. Smith" Date: Sat, 15 May 2021 13:53:17 -0500 Subject: [PATCH 10/11] Set event source levels on existing sources during setup --- .../Implementation/SelfDiagnosticsEventLogForwarder.cs | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs index 3f095eaae61..7e43c7f17d2 100644 --- a/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs +++ b/src/OpenTelemetry.Extensions.Hosting/Implementation/SelfDiagnosticsEventLogForwarder.cs @@ -46,6 +46,10 @@ internal SelfDiagnosticsEventLogForwarder(ILoggerFactory loggerFactory, IOptions this.loggerFilterOptions = loggerFilterOptions; this.defaultMinEventLevel = defaultMinEventLevel; + // set initial levels on existing event sources + this.SetEventSourceLevels(); + + // listen to changes to the log levels loggerFilterOptions.OnChange(o => this.SetEventSourceLevels()); } From 2955cf9c95afb880ce6f3d157a775a5f2c05d218 Mon Sep 17 00:00:00 2001 From: "Eric J. Smith" Date: Tue, 27 Jul 2021 10:54:45 -0500 Subject: [PATCH 11/11] Check for null eventData when formatting messages --- .../Implementation/EventSourceEventFormatter.cs | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatter.cs b/src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatter.cs index 553a8795762..24fe2a6d41c 100644 --- a/src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatter.cs +++ b/src/OpenTelemetry.Extensions.Hosting/Implementation/EventSourceEventFormatter.cs @@ -27,7 +27,12 @@ internal static class EventSourceEventFormatter public static string Format(EventWrittenEventArgs eventData) { - var payloadCollection = eventData.Payload.ToArray() ?? EmptyPayload; + if (eventData == null) + { + return string.Empty; + } + + var payloadCollection = eventData.Payload?.ToArray() ?? EmptyPayload; ProcessPayloadArray(payloadCollection);