From 76e6393a8cd9d6856226bd4d3b8650f1c8ed60e3 Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Mon, 19 Apr 2021 10:32:57 -0700 Subject: [PATCH 01/13] Added the ability to buffer log scopes so they can be processed in batches. --- .../BatchLogRecordExportProcessor.cs | 7 +++ src/OpenTelemetry/Logs/LogRecord.cs | 48 +++++++++++++++++-- src/OpenTelemetry/Logs/OpenTelemetryLogger.cs | 2 + 3 files changed, 54 insertions(+), 3 deletions(-) diff --git a/src/OpenTelemetry/BatchLogRecordExportProcessor.cs b/src/OpenTelemetry/BatchLogRecordExportProcessor.cs index 96cc35bc84f..c94abd6a973 100644 --- a/src/OpenTelemetry/BatchLogRecordExportProcessor.cs +++ b/src/OpenTelemetry/BatchLogRecordExportProcessor.cs @@ -35,6 +35,13 @@ public BatchLogRecordExportProcessor( maxExportBatchSize) { } + + public override void OnEnd(LogRecord data) + { + data.BufferLogScopes(); + + base.OnEnd(data); + } } } #endif diff --git a/src/OpenTelemetry/Logs/LogRecord.cs b/src/OpenTelemetry/Logs/LogRecord.cs index 780f943ec0d..454bac6f890 100644 --- a/src/OpenTelemetry/Logs/LogRecord.cs +++ b/src/OpenTelemetry/Logs/LogRecord.cs @@ -27,7 +27,7 @@ namespace OpenTelemetry.Logs /// public sealed class LogRecord { - private readonly IExternalScopeProvider scopeProvider; + private List bufferedScopes; internal LogRecord( IExternalScopeProvider scopeProvider, @@ -40,7 +40,7 @@ internal LogRecord( Exception exception, IReadOnlyList> stateValues) { - this.scopeProvider = scopeProvider; + this.ScopeProvider = scopeProvider; var activity = Activity.Current; if (activity != null) @@ -85,17 +85,59 @@ internal LogRecord( public Exception Exception { get; } + internal IExternalScopeProvider ScopeProvider { get; set; } + /// /// Executes callback for each currently active scope objects in order /// of creation. All callbacks are guaranteed to be called inline from /// this method. /// + /// + /// Note: Scopes are only available during the lifecycle of the log + /// message being written. If you need to capture scopes to be used + /// later (for example in batching scenarios), call to safely capture the values (incurs + /// allocation). + /// /// State. /// The callback to be executed for every scope object. /// The state object to be passed into the callback. public void ForEachScope(Action callback, TState state) { - this.scopeProvider?.ForEachScope(callback, state); + if (this.bufferedScopes != null) + { + foreach (object scope in this.bufferedScopes) + { + callback(scope, state); + } + } + else + { + this.ScopeProvider?.ForEachScope(callback, state); + } + } + + /// + /// Buffers the scopes attached to the log into a list so that they can + /// be safely processed after the log message lifecycle has ended. + /// + public void BufferLogScopes() + { + if (this.ScopeProvider == null || this.bufferedScopes != null) + { + return; + } + + List scopes = new List(); + + this.ForEachScope(AddScopeToList, scopes); + + this.bufferedScopes = scopes; + + static void AddScopeToList(object scope, List state) + { + state.Add(scope); + } } } } diff --git a/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs b/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs index f1dcea4f697..69ef50c9ddd 100644 --- a/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs +++ b/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs @@ -60,6 +60,8 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except options.ParseStateValues ? this.ParseState(state) : null); processor.OnEnd(record); + + record.ScopeProvider = null; } } From b546064429f4127844588551f85938be0ac3431c Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Mon, 19 Apr 2021 20:24:14 -0700 Subject: [PATCH 02/13] Switched the ForEachScope API to return KeyValuePair items instead of object. --- src/OpenTelemetry/Logs/LogRecord.cs | 36 +++++++++++++++++++++++++---- 1 file changed, 31 insertions(+), 5 deletions(-) diff --git a/src/OpenTelemetry/Logs/LogRecord.cs b/src/OpenTelemetry/Logs/LogRecord.cs index 454bac6f890..74406d18efd 100644 --- a/src/OpenTelemetry/Logs/LogRecord.cs +++ b/src/OpenTelemetry/Logs/LogRecord.cs @@ -102,18 +102,44 @@ internal LogRecord( /// State. /// The callback to be executed for every scope object. /// The state object to be passed into the callback. - public void ForEachScope(Action callback, TState state) + public void ForEachScope(Action, TState> callback, TState state) { if (this.bufferedScopes != null) { - foreach (object scope in this.bufferedScopes) + for (int scopeIndex = 0; scopeIndex < this.bufferedScopes.Count; scopeIndex++) { - callback(scope, state); + ForEachScope(this.bufferedScopes[scopeIndex], (scopeIndex, callback, state)); } } else { - this.ScopeProvider?.ForEachScope(callback, state); + int scopeIndex = 0; + this.ScopeProvider?.ForEachScope(ForEachScope, (scopeIndex++, callback, state)); + } + + static void ForEachScope(object scope, (int scopeIndex, Action, TState> callback, TState userState) state) + { + if (scope is IReadOnlyList> stateList) + { + for (int i = 0; i < stateList.Count; i++) + { + state.callback(state.scopeIndex, stateList[i], state.userState); + } + } + else if (state is IEnumerable> stateValues) + { + foreach (KeyValuePair stateValue in stateValues) + { + state.callback(state.scopeIndex, stateValue, state.userState); + } + } + else + { + state.callback( + state.scopeIndex, + new KeyValuePair(string.Empty, state), + state.userState); + } } } @@ -130,7 +156,7 @@ public void BufferLogScopes() List scopes = new List(); - this.ForEachScope(AddScopeToList, scopes); + this.ScopeProvider?.ForEachScope(AddScopeToList, scopes); this.bufferedScopes = scopes; From fe6633b36a3cbc2d4035bedb2e94405699259e3b Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Tue, 20 Apr 2021 09:32:29 -0700 Subject: [PATCH 03/13] Simplified the ForEachScope signature. --- src/OpenTelemetry/Logs/LogRecord.cs | 16 +++++++--------- 1 file changed, 7 insertions(+), 9 deletions(-) diff --git a/src/OpenTelemetry/Logs/LogRecord.cs b/src/OpenTelemetry/Logs/LogRecord.cs index 74406d18efd..afc853bbaac 100644 --- a/src/OpenTelemetry/Logs/LogRecord.cs +++ b/src/OpenTelemetry/Logs/LogRecord.cs @@ -102,41 +102,39 @@ internal LogRecord( /// State. /// The callback to be executed for every scope object. /// The state object to be passed into the callback. - public void ForEachScope(Action, TState> callback, TState state) + public void ForEachScope(Action, TState> callback, TState state) { if (this.bufferedScopes != null) { - for (int scopeIndex = 0; scopeIndex < this.bufferedScopes.Count; scopeIndex++) + foreach (object scope in this.bufferedScopes) { - ForEachScope(this.bufferedScopes[scopeIndex], (scopeIndex, callback, state)); + ForEachScope(scope, (callback, state)); } } else { - int scopeIndex = 0; - this.ScopeProvider?.ForEachScope(ForEachScope, (scopeIndex++, callback, state)); + this.ScopeProvider?.ForEachScope(ForEachScope, (callback, state)); } - static void ForEachScope(object scope, (int scopeIndex, Action, TState> callback, TState userState) state) + static void ForEachScope(object scope, (Action, TState> callback, TState userState) state) { if (scope is IReadOnlyList> stateList) { for (int i = 0; i < stateList.Count; i++) { - state.callback(state.scopeIndex, stateList[i], state.userState); + state.callback(stateList[i], state.userState); } } else if (state is IEnumerable> stateValues) { foreach (KeyValuePair stateValue in stateValues) { - state.callback(state.scopeIndex, stateValue, state.userState); + state.callback(stateValue, state.userState); } } else { state.callback( - state.scopeIndex, new KeyValuePair(string.Empty, state), state.userState); } From 32859ef01f5f3e37480755aa0214bdb333abd570 Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Sun, 2 May 2021 23:02:15 -0700 Subject: [PATCH 04/13] Scope depth tracking, scope item enumerator. --- docs/logs/extending-the-sdk/MyExporter.cs | 11 +- .../Controllers/WeatherForecastController.cs | 23 +++- examples/AspNetCore/Program.cs | 20 ++++ examples/AspNetCore/appsettings.json | 1 + .../ConsoleLogRecordExporter.cs | 17 ++- .../.publicApi/net461/PublicAPI.Unshipped.txt | 17 ++- .../netstandard2.0/PublicAPI.Unshipped.txt | 17 ++- src/OpenTelemetry/Logs/LogRecord.cs | 74 +++++++----- src/OpenTelemetry/Logs/LogRecordScope.cs | 106 ++++++++++++++++++ .../Logs/LogRecordScopeCallback.cs | 30 +++++ src/OpenTelemetry/OpenTelemetry.csproj | 2 + test/Benchmarks/Logs/LogScopeBenchmarks.cs | 80 +++++++++++++ .../OpenTelemetry.Tests/Logs/LogRecordTest.cs | 95 ++++++++++++++-- 13 files changed, 448 insertions(+), 45 deletions(-) create mode 100644 src/OpenTelemetry/Logs/LogRecordScope.cs create mode 100644 src/OpenTelemetry/Logs/LogRecordScopeCallback.cs create mode 100644 test/Benchmarks/Logs/LogScopeBenchmarks.cs diff --git a/docs/logs/extending-the-sdk/MyExporter.cs b/docs/logs/extending-the-sdk/MyExporter.cs index d69009c3df6..541148f5d1f 100644 --- a/docs/logs/extending-the-sdk/MyExporter.cs +++ b/docs/logs/extending-the-sdk/MyExporter.cs @@ -46,8 +46,15 @@ public override ExportResult Export(in Batch batch) record.ForEachScope(ProcessScope, sb); - static void ProcessScope(object scope, StringBuilder builder) - => builder.Append($"{scope}"); + static void ProcessScope(LogRecordScope scope, StringBuilder builder) + { + if (scope.Depth > 0) + { + builder.Append(','); + } + + builder.Append($"{scope.Scope}"); + } sb.Append($")"); } diff --git a/examples/AspNetCore/Controllers/WeatherForecastController.cs b/examples/AspNetCore/Controllers/WeatherForecastController.cs index 33090f6de7a..9c35f470c9c 100644 --- a/examples/AspNetCore/Controllers/WeatherForecastController.cs +++ b/examples/AspNetCore/Controllers/WeatherForecastController.cs @@ -20,6 +20,7 @@ using System.Net.Http; using Examples.AspNetCore.Models; using Microsoft.AspNetCore.Mvc; +using Microsoft.Extensions.Logging; namespace Examples.AspNetCore.Controllers { @@ -32,23 +33,39 @@ public class WeatherForecastController : ControllerBase "Freezing", "Bracing", "Chilly", "Cool", "Mild", "Warm", "Balmy", "Hot", "Sweltering", "Scorching", }; - private static HttpClient httpClient = new HttpClient(); + private static readonly HttpClient HttpClient = new HttpClient(); + + private readonly ILogger logger; + + public WeatherForecastController(ILogger logger) + { + this.logger = logger ?? throw new ArgumentNullException(nameof(logger)); + } [HttpGet] public IEnumerable Get() { + using var scope = this.logger.BeginScope("{Id}", Guid.NewGuid().ToString("N")); + // Making an http call here to serve as an example of // how dependency calls will be captured and treated // automatically as child of incoming request. - var res = httpClient.GetStringAsync("http://google.com").Result; + var res = HttpClient.GetStringAsync("http://google.com").Result; var rng = new Random(); - return Enumerable.Range(1, 5).Select(index => new WeatherForecast + var forecast = Enumerable.Range(1, 5).Select(index => new WeatherForecast { Date = DateTime.Now.AddDays(index), TemperatureC = rng.Next(-20, 55), Summary = Summaries[rng.Next(Summaries.Length)], }) .ToArray(); + + this.logger.LogInformation( + "WeatherForecasts generated {count}: {forecasts}", + forecast.Length, + forecast); + + return forecast; } } } diff --git a/examples/AspNetCore/Program.cs b/examples/AspNetCore/Program.cs index dbcce6603b2..fa6965e5c90 100644 --- a/examples/AspNetCore/Program.cs +++ b/examples/AspNetCore/Program.cs @@ -15,7 +15,10 @@ // using Microsoft.AspNetCore.Hosting; +using Microsoft.Extensions.Configuration; using Microsoft.Extensions.Hosting; +using Microsoft.Extensions.Logging; +using OpenTelemetry.Logs; namespace Examples.AspNetCore { @@ -31,6 +34,23 @@ public static IHostBuilder CreateHostBuilder(string[] args) => .ConfigureWebHostDefaults(webBuilder => { webBuilder.UseStartup(); + }) + .ConfigureLogging((context, builder) => + { + builder.ClearProviders(); + builder.AddConsole(); + + var useLogging = context.Configuration.GetValue("UseLogging"); + if (useLogging) + { + builder.AddOpenTelemetry(options => + { + options.IncludeScopes = true; + options.ParseStateValues = true; + options.IncludeFormattedMessage = true; + options.AddConsoleExporter(); + }); + } }); } } diff --git a/examples/AspNetCore/appsettings.json b/examples/AspNetCore/appsettings.json index d9e5cf957cc..edd66d9db45 100644 --- a/examples/AspNetCore/appsettings.json +++ b/examples/AspNetCore/appsettings.json @@ -8,6 +8,7 @@ }, "AllowedHosts": "*", "UseExporter": "console", + "UseLogging": true, "Jaeger": { "ServiceName": "jaeger-test", "AgentHost": "localhost", diff --git a/src/OpenTelemetry.Exporter.Console/ConsoleLogRecordExporter.cs b/src/OpenTelemetry.Exporter.Console/ConsoleLogRecordExporter.cs index b519bdb3b0f..1a6e8d991d3 100644 --- a/src/OpenTelemetry.Exporter.Console/ConsoleLogRecordExporter.cs +++ b/src/OpenTelemetry.Exporter.Console/ConsoleLogRecordExporter.cs @@ -16,6 +16,7 @@ #if NET461 || NETSTANDARD2_0 using System; +using System.Collections.Generic; using OpenTelemetry.Logs; using OpenTelemetry.Resources; @@ -64,10 +65,20 @@ public override ExportResult Export(in Batch batch) this.WriteLine($"{"LogRecord.Exception:".PadRight(RightPaddingLength)}{logRecord.Exception?.Message}"); } - logRecord.ForEachScope(ProcessScope, this); + logRecord.ForEachScope(ProcessScopeItem, this); - static void ProcessScope(object scope, ConsoleLogRecordExporter exporter) - => exporter.WriteLine($"{"LogRecord.Scope:".PadRight(RightPaddingLength)}{scope}"); + static void ProcessScopeItem(LogRecordScope scope, ConsoleLogRecordExporter exporter) + { + if (scope.Depth == 0) + { + exporter.WriteLine("LogRecord.ScopeValues (Key:Value):"); + } + + foreach (KeyValuePair scopeItem in scope) + { + exporter.WriteLine($"[Scope.{scope.Depth}]:{scopeItem.Key.PadRight(RightPaddingLength)}{scopeItem.Value}"); + } + } var resource = this.ParentProvider.GetResource(); if (resource != Resource.Empty) diff --git a/src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt b/src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt index aae8523dcf5..881902d07ac 100644 --- a/src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt +++ b/src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt @@ -1,6 +1,20 @@ -OpenTelemetry.Logs.LogRecord.ForEachScope(System.Action callback, TState state) -> void +OpenTelemetry.Logs.LogRecord.BufferLogScopes() -> void +OpenTelemetry.Logs.LogRecord.ForEachScope(OpenTelemetry.Logs.LogRecordScopeCallback callback, TState state) -> void OpenTelemetry.Logs.LogRecord.FormattedMessage.get -> string OpenTelemetry.Logs.LogRecord.StateValues.get -> System.Collections.Generic.IReadOnlyList> +OpenTelemetry.Logs.LogRecordScope +OpenTelemetry.Logs.LogRecordScope.Depth.get -> int +OpenTelemetry.Logs.LogRecordScope.Enumerator +OpenTelemetry.Logs.LogRecordScope.Enumerator.Current.get -> System.Collections.Generic.KeyValuePair +OpenTelemetry.Logs.LogRecordScope.Enumerator.Dispose() -> void +OpenTelemetry.Logs.LogRecordScope.Enumerator.Enumerator() -> void +OpenTelemetry.Logs.LogRecordScope.Enumerator.Enumerator(object scope) -> void +OpenTelemetry.Logs.LogRecordScope.Enumerator.MoveNext() -> bool +OpenTelemetry.Logs.LogRecordScope.Enumerator.Reset() -> void +OpenTelemetry.Logs.LogRecordScope.GetEnumerator() -> OpenTelemetry.Logs.LogRecordScope.Enumerator +OpenTelemetry.Logs.LogRecordScope.LogRecordScope() -> void +OpenTelemetry.Logs.LogRecordScope.Scope.get -> object +OpenTelemetry.Logs.LogRecordScopeCallback OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeFormattedMessage.get -> bool OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeFormattedMessage.set -> void OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeScopes.get -> bool @@ -16,6 +30,7 @@ OpenTelemetry.Trace.TracerProviderBuilderBase OpenTelemetry.Trace.TracerProviderBuilderBase.AddInstrumentation(string instrumentationName, string instrumentationVersion, System.Func instrumentationFactory) -> OpenTelemetry.Trace.TracerProviderBuilder OpenTelemetry.Trace.TracerProviderBuilderBase.Build() -> OpenTelemetry.Trace.TracerProvider OpenTelemetry.Trace.TracerProviderBuilderBase.TracerProviderBuilderBase() -> void +override OpenTelemetry.BatchLogRecordExportProcessor.OnEnd(OpenTelemetry.Logs.LogRecord data) -> void override OpenTelemetry.Trace.TracerProviderBuilderBase.AddInstrumentation(System.Func instrumentationFactory) -> OpenTelemetry.Trace.TracerProviderBuilder override OpenTelemetry.Trace.TracerProviderBuilderBase.AddSource(params string[] names) -> OpenTelemetry.Trace.TracerProviderBuilder override OpenTelemetry.Logs.OpenTelemetryLoggerProvider.Dispose(bool disposing) -> void diff --git a/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt b/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt index aae8523dcf5..881902d07ac 100644 --- a/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt +++ b/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt @@ -1,6 +1,20 @@ -OpenTelemetry.Logs.LogRecord.ForEachScope(System.Action callback, TState state) -> void +OpenTelemetry.Logs.LogRecord.BufferLogScopes() -> void +OpenTelemetry.Logs.LogRecord.ForEachScope(OpenTelemetry.Logs.LogRecordScopeCallback callback, TState state) -> void OpenTelemetry.Logs.LogRecord.FormattedMessage.get -> string OpenTelemetry.Logs.LogRecord.StateValues.get -> System.Collections.Generic.IReadOnlyList> +OpenTelemetry.Logs.LogRecordScope +OpenTelemetry.Logs.LogRecordScope.Depth.get -> int +OpenTelemetry.Logs.LogRecordScope.Enumerator +OpenTelemetry.Logs.LogRecordScope.Enumerator.Current.get -> System.Collections.Generic.KeyValuePair +OpenTelemetry.Logs.LogRecordScope.Enumerator.Dispose() -> void +OpenTelemetry.Logs.LogRecordScope.Enumerator.Enumerator() -> void +OpenTelemetry.Logs.LogRecordScope.Enumerator.Enumerator(object scope) -> void +OpenTelemetry.Logs.LogRecordScope.Enumerator.MoveNext() -> bool +OpenTelemetry.Logs.LogRecordScope.Enumerator.Reset() -> void +OpenTelemetry.Logs.LogRecordScope.GetEnumerator() -> OpenTelemetry.Logs.LogRecordScope.Enumerator +OpenTelemetry.Logs.LogRecordScope.LogRecordScope() -> void +OpenTelemetry.Logs.LogRecordScope.Scope.get -> object +OpenTelemetry.Logs.LogRecordScopeCallback OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeFormattedMessage.get -> bool OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeFormattedMessage.set -> void OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeScopes.get -> bool @@ -16,6 +30,7 @@ OpenTelemetry.Trace.TracerProviderBuilderBase OpenTelemetry.Trace.TracerProviderBuilderBase.AddInstrumentation(string instrumentationName, string instrumentationVersion, System.Func instrumentationFactory) -> OpenTelemetry.Trace.TracerProviderBuilder OpenTelemetry.Trace.TracerProviderBuilderBase.Build() -> OpenTelemetry.Trace.TracerProvider OpenTelemetry.Trace.TracerProviderBuilderBase.TracerProviderBuilderBase() -> void +override OpenTelemetry.BatchLogRecordExportProcessor.OnEnd(OpenTelemetry.Logs.LogRecord data) -> void override OpenTelemetry.Trace.TracerProviderBuilderBase.AddInstrumentation(System.Func instrumentationFactory) -> OpenTelemetry.Trace.TracerProviderBuilder override OpenTelemetry.Trace.TracerProviderBuilderBase.AddSource(params string[] names) -> OpenTelemetry.Trace.TracerProviderBuilder override OpenTelemetry.Logs.OpenTelemetryLoggerProvider.Dispose(bool disposing) -> void diff --git a/src/OpenTelemetry/Logs/LogRecord.cs b/src/OpenTelemetry/Logs/LogRecord.cs index afc853bbaac..ae24ec5b540 100644 --- a/src/OpenTelemetry/Logs/LogRecord.cs +++ b/src/OpenTelemetry/Logs/LogRecord.cs @@ -18,12 +18,13 @@ using System; using System.Collections.Generic; using System.Diagnostics; +using System.Runtime.CompilerServices; using Microsoft.Extensions.Logging; namespace OpenTelemetry.Logs { /// - /// Log record base class. + /// Stores details about a log message. /// public sealed class LogRecord { @@ -79,8 +80,18 @@ internal LogRecord( public string FormattedMessage { get; } + /// + /// Gets the raw state attached to the log. Set to when is enabled. + /// public object State { get; } + /// + /// Gets the parsed state values attached to the log. Set when is enabled + /// otherwise . + /// public IReadOnlyList> StateValues { get; } public Exception Exception { get; } @@ -102,42 +113,24 @@ internal LogRecord( /// State. /// The callback to be executed for every scope object. /// The state object to be passed into the callback. - public void ForEachScope(Action, TState> callback, TState state) + public unsafe void ForEachScope(LogRecordScopeCallback callback, TState state) { if (this.bufferedScopes != null) { + ScopeForEachState forEachState = new ScopeForEachState(callback, state, 0); + IntPtr statePointer = new IntPtr(Unsafe.AsPointer(ref forEachState)); + foreach (object scope in this.bufferedScopes) { - ForEachScope(scope, (callback, state)); + ScopeForEachState.ForEachScope(scope, statePointer); } } - else + else if (this.ScopeProvider != null) { - this.ScopeProvider?.ForEachScope(ForEachScope, (callback, state)); - } + ScopeForEachState forEachState = new ScopeForEachState(callback, state, 0); + IntPtr statePointer = new IntPtr(Unsafe.AsPointer(ref forEachState)); - static void ForEachScope(object scope, (Action, TState> callback, TState userState) state) - { - if (scope is IReadOnlyList> stateList) - { - for (int i = 0; i < stateList.Count; i++) - { - state.callback(stateList[i], state.userState); - } - } - else if (state is IEnumerable> stateValues) - { - foreach (KeyValuePair stateValue in stateValues) - { - state.callback(stateValue, state.userState); - } - } - else - { - state.callback( - new KeyValuePair(string.Empty, state), - state.userState); - } + this.ScopeProvider.ForEachScope(ScopeForEachState.ForEachScope, statePointer); } } @@ -163,6 +156,31 @@ static void AddScopeToList(object scope, List state) state.Add(scope); } } + + private unsafe struct ScopeForEachState + { + public static readonly Action ForEachScope = (object scope, IntPtr statePointer) => + { + ref ScopeForEachState state = ref Unsafe.AsRef>((void*)statePointer); + + LogRecordScope logRecordScope = new LogRecordScope(scope, state.Depth++); + + state.Callback(logRecordScope, state.UserState); + }; + + public readonly LogRecordScopeCallback Callback; + + public readonly TState UserState; + + public int Depth; + + public ScopeForEachState(LogRecordScopeCallback callback, TState state, int depth) + { + this.Callback = callback; + this.UserState = state; + this.Depth = depth; + } + } } } #endif diff --git a/src/OpenTelemetry/Logs/LogRecordScope.cs b/src/OpenTelemetry/Logs/LogRecordScope.cs new file mode 100644 index 00000000000..dc70fcc003d --- /dev/null +++ b/src/OpenTelemetry/Logs/LogRecordScope.cs @@ -0,0 +1,106 @@ +// +// 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. +// + +#if NET461 || NETSTANDARD2_0 +using System; +using System.Collections; +using System.Collections.Generic; + +namespace OpenTelemetry.Logs +{ + /// + /// Stores details about a scope attached to a log message. + /// + public readonly ref struct LogRecordScope + { + internal LogRecordScope(object scope, int depth) + { + this.Scope = scope; + this.Depth = depth; + } + + /// + /// Gets the raw scope value. + /// + public object Scope { get; } + + /// + /// Gets the depth of the current scope in the stack of active scopes. + /// + public int Depth { get; } + + /// + /// Gets an for looping over the inner values + /// of the scope. + /// + /// . + public Enumerator GetEnumerator() => new Enumerator(this.Scope); + + /// + /// LogRecordScope enumerator. + /// + public struct Enumerator : IEnumerator> + { + private readonly IReadOnlyList> scope; + private int position; + + public Enumerator(object scope) + { + if (scope is IReadOnlyList> scopeList) + { + this.scope = scopeList; + } + else if (scope is IEnumerable> scopeEnumerable) + { + this.scope = new List>(scopeEnumerable); + } + else + { + this.scope = new List> + { + new KeyValuePair(string.Empty, scope), + }; + } + + this.position = 0; + this.Current = default; + } + + public KeyValuePair Current { get; private set; } + + object IEnumerator.Current => this.Current; + + public bool MoveNext() + { + if (this.position < this.scope.Count) + { + this.Current = this.scope[this.position++]; + return true; + } + + return false; + } + + public void Dispose() + { + } + + public void Reset() + => throw new NotSupportedException(); + } + } +} +#endif diff --git a/src/OpenTelemetry/Logs/LogRecordScopeCallback.cs b/src/OpenTelemetry/Logs/LogRecordScopeCallback.cs new file mode 100644 index 00000000000..38adee399dd --- /dev/null +++ b/src/OpenTelemetry/Logs/LogRecordScopeCallback.cs @@ -0,0 +1,30 @@ +// +// 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. +// + +#if NET461 || NETSTANDARD2_0 +namespace OpenTelemetry.Logs +{ + /// + /// Callback delegate for the method. + /// + /// State type. + /// . + /// State. + public delegate void LogRecordScopeCallback(LogRecordScope scope, TState state); +} +#endif diff --git a/src/OpenTelemetry/OpenTelemetry.csproj b/src/OpenTelemetry/OpenTelemetry.csproj index 7db4596ba98..6136f2165e9 100644 --- a/src/OpenTelemetry/OpenTelemetry.csproj +++ b/src/OpenTelemetry/OpenTelemetry.csproj @@ -7,11 +7,13 @@ --> $(NoWarn),1591,CS0618 core- + true + diff --git a/test/Benchmarks/Logs/LogScopeBenchmarks.cs b/test/Benchmarks/Logs/LogScopeBenchmarks.cs new file mode 100644 index 00000000000..a1e26713e1f --- /dev/null +++ b/test/Benchmarks/Logs/LogScopeBenchmarks.cs @@ -0,0 +1,80 @@ +// +// 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. +// + +#if NETCOREAPP3_1 +using System; +using System.Collections.Generic; +using System.Collections.ObjectModel; +using BenchmarkDotNet.Attributes; +using Microsoft.Extensions.Logging; +using OpenTelemetry.Logs; + +namespace Benchmarks.Logs +{ + [MemoryDiagnoser] + public class LogScopeBenchmarks + { + private readonly LoggerExternalScopeProvider scopeProvider = new LoggerExternalScopeProvider(); + + private readonly LogRecordScopeCallback callback = (LogRecordScope scope, object state) => + { + foreach (KeyValuePair scopeItem in scope) + { + } + }; + + private readonly LogRecord logRecord; + + public LogScopeBenchmarks() + { + this.scopeProvider.Push(new ReadOnlyCollection>( + new List> + { + new KeyValuePair("item1", "value1"), + new KeyValuePair("item2", "value2"), + })); + this.scopeProvider.Push(new ReadOnlyCollection>( + new List> + { + new KeyValuePair("item3", "value3"), + })); + this.scopeProvider.Push(new ReadOnlyCollection>( + new List> + { + new KeyValuePair("item4", "value4"), + new KeyValuePair("item5", "value5"), + })); + + this.logRecord = new LogRecord( + this.scopeProvider, + DateTime.UtcNow, + "Benchmark", + LogLevel.Information, + 0, + "Message", + null, + null, + null); + } + + [Benchmark] + public void ForEachScope() + { + this.logRecord.ForEachScope(this.callback, null); + } + } +} +#endif diff --git a/test/OpenTelemetry.Tests/Logs/LogRecordTest.cs b/test/OpenTelemetry.Tests/Logs/LogRecordTest.cs index c35a6a5a3b7..541a13c0fae 100644 --- a/test/OpenTelemetry.Tests/Logs/LogRecordTest.cs +++ b/test/OpenTelemetry.Tests/Logs/LogRecordTest.cs @@ -32,7 +32,7 @@ namespace OpenTelemetry.Tests.Logs { - public class LogRecordTest : IDisposable + public sealed class LogRecordTest : IDisposable { private readonly ILogger logger; private readonly List exportedItems = new List(); @@ -48,7 +48,7 @@ public class LogRecordTest : IDisposable public LogRecordTest() { this.exporter = new InMemoryExporter(this.exportedItems); - this.processor = new SimpleLogRecordExportProcessor(this.exporter); + this.processor = new TestLogRecordProcessor(this.exporter); #if NETCOREAPP2_1 var serviceCollection = new ServiceCollection().AddLogging(builder => #else @@ -348,7 +348,7 @@ public void IncludeScopesTest() var logRecord = this.exportedItems[0]; List scopes = new List(); - logRecord.ForEachScope((scope, state) => scopes.Add(scope), null); + logRecord.ForEachScope((scope, state) => scopes.Add(scope.Scope), null); Assert.Empty(scopes); this.options.IncludeScopes = true; @@ -357,21 +357,87 @@ public void IncludeScopesTest() this.logger.LogInformation("OpenTelemetry!"); logRecord = this.exportedItems[1]; - logRecord.ForEachScope((scope, state) => scopes.Add(scope), null); + int actualMaxDepth = -1; + logRecord.ForEachScope( + (scope, state) => + { + actualMaxDepth = scope.Depth; + scopes.Add(scope.Scope); + foreach (KeyValuePair item in scope) + { + Assert.Equal(string.Empty, item.Key); + Assert.Equal("string_scope", item.Value); + } + }, + null); Assert.Single(scopes); + Assert.Equal(0, actualMaxDepth); Assert.Equal("string_scope", scopes[0]); scopes.Clear(); - using var scope2 = this.logger.BeginScope(2021); + List> expectedScope2 = new List> + { + new KeyValuePair("item1", "value1"), + new KeyValuePair("item2", "value2"), + }; + using var scope2 = this.logger.BeginScope(expectedScope2); this.logger.LogInformation("OpenTelemetry!"); logRecord = this.exportedItems[2]; - logRecord.ForEachScope((scope, state) => scopes.Add(scope), null); + actualMaxDepth = -1; + logRecord.ForEachScope( + (scope, state) => + { + actualMaxDepth = scope.Depth; + scopes.Add(scope.Scope); + if (scope.Depth == 1) + { + foreach (KeyValuePair item in scope) + { + Assert.Contains(item, expectedScope2); + } + } + }, + null); Assert.Equal(2, scopes.Count); + Assert.Equal(1, actualMaxDepth); + Assert.Equal("string_scope", scopes[0]); + Assert.Same(expectedScope2, scopes[1]); + + scopes.Clear(); + + KeyValuePair[] expectedScope3 = new KeyValuePair[] + { + new KeyValuePair("item3", "value3"), + new KeyValuePair("item4", "value4"), + }; + using var scope3 = this.logger.BeginScope(expectedScope3); + + this.logger.LogInformation("OpenTelemetry!"); + logRecord = this.exportedItems[3]; + + actualMaxDepth = -1; + logRecord.ForEachScope( + (scope, state) => + { + actualMaxDepth = scope.Depth; + scopes.Add(scope.Scope); + if (scope.Depth == 2) + { + foreach (KeyValuePair item in scope) + { + Assert.Contains(item, expectedScope3); + } + } + }, + null); + Assert.Equal(3, scopes.Count); + Assert.Equal(2, actualMaxDepth); Assert.Equal("string_scope", scopes[0]); - Assert.Equal(2021, scopes[1]); + Assert.Same(expectedScope2, scopes[1]); + Assert.Same(expectedScope3, scopes[2]); } finally { @@ -596,6 +662,21 @@ private class CustomState { public string Property { get; set; } } + + private class TestLogRecordProcessor : SimpleExportProcessor + { + public TestLogRecordProcessor(BaseExporter exporter) + : base(exporter) + { + } + + public override void OnEnd(LogRecord data) + { + data.BufferLogScopes(); + + base.OnEnd(data); + } + } } } #endif From 2ad4297ec5dd053c4b0506bf993087318d240858 Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Sun, 2 May 2021 23:47:11 -0700 Subject: [PATCH 05/13] CHANGELOG update. --- src/OpenTelemetry/CHANGELOG.md | 6 ++++++ 1 file changed, 6 insertions(+) diff --git a/src/OpenTelemetry/CHANGELOG.md b/src/OpenTelemetry/CHANGELOG.md index e24138fd7bd..5ef305ab55d 100644 --- a/src/OpenTelemetry/CHANGELOG.md +++ b/src/OpenTelemetry/CHANGELOG.md @@ -9,6 +9,12 @@ please check the latest changes ## Unreleased +* Added `LogRecord.BufferLogScopes` to capture log scopes for out-of-band + processing. To make parsing scopes easier the `LogRecord.ForEachScope` + signature has been changed to pass instances of `LogRecordScope` (a new type + which includes an `IEnumerator>`) + ([#2026](https://github.com/open-telemetry/opentelemetry-dotnet/pull/2026)) + ## 1.1.0-beta2 Released 2021-Apr-23 From 863e60acf12a971d1f2e2afadb8fdad908fba927 Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Mon, 3 May 2021 12:10:56 -0700 Subject: [PATCH 06/13] Code review. --- docs/logs/extending-the-sdk/MyExporter.cs | 2 +- .../ConsoleLogRecordExporter.cs | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/docs/logs/extending-the-sdk/MyExporter.cs b/docs/logs/extending-the-sdk/MyExporter.cs index 541148f5d1f..8e76cb77518 100644 --- a/docs/logs/extending-the-sdk/MyExporter.cs +++ b/docs/logs/extending-the-sdk/MyExporter.cs @@ -50,7 +50,7 @@ static void ProcessScope(LogRecordScope scope, StringBuilder builder) { if (scope.Depth > 0) { - builder.Append(','); + builder.Append(", "); } builder.Append($"{scope.Scope}"); diff --git a/src/OpenTelemetry.Exporter.Console/ConsoleLogRecordExporter.cs b/src/OpenTelemetry.Exporter.Console/ConsoleLogRecordExporter.cs index 1a6e8d991d3..b2119553130 100644 --- a/src/OpenTelemetry.Exporter.Console/ConsoleLogRecordExporter.cs +++ b/src/OpenTelemetry.Exporter.Console/ConsoleLogRecordExporter.cs @@ -65,9 +65,9 @@ public override ExportResult Export(in Batch batch) this.WriteLine($"{"LogRecord.Exception:".PadRight(RightPaddingLength)}{logRecord.Exception?.Message}"); } - logRecord.ForEachScope(ProcessScopeItem, this); + logRecord.ForEachScope(ProcessScope, this); - static void ProcessScopeItem(LogRecordScope scope, ConsoleLogRecordExporter exporter) + static void ProcessScope(LogRecordScope scope, ConsoleLogRecordExporter exporter) { if (scope.Depth == 0) { From f94acd96af7a87928cf0adda9227bc23d9564b74 Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Mon, 3 May 2021 12:57:32 -0700 Subject: [PATCH 07/13] Fixed delegate allocation in BufferLogScopes. --- src/OpenTelemetry/Logs/LogRecord.cs | 12 ++++++------ 1 file changed, 6 insertions(+), 6 deletions(-) diff --git a/src/OpenTelemetry/Logs/LogRecord.cs b/src/OpenTelemetry/Logs/LogRecord.cs index ae24ec5b540..9cab52c1af6 100644 --- a/src/OpenTelemetry/Logs/LogRecord.cs +++ b/src/OpenTelemetry/Logs/LogRecord.cs @@ -28,6 +28,11 @@ namespace OpenTelemetry.Logs /// public sealed class LogRecord { + private static readonly Action> AddScopeToBufferedList = (object scope, List state) => + { + state.Add(scope); + }; + private List bufferedScopes; internal LogRecord( @@ -147,14 +152,9 @@ public void BufferLogScopes() List scopes = new List(); - this.ScopeProvider?.ForEachScope(AddScopeToList, scopes); + this.ScopeProvider?.ForEachScope(AddScopeToBufferedList, scopes); this.bufferedScopes = scopes; - - static void AddScopeToList(object scope, List state) - { - state.Add(scope); - } } private unsafe struct ScopeForEachState From d6788091c31240e720f582a39c1e872a11cb741d Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Tue, 4 May 2021 23:16:08 -0700 Subject: [PATCH 08/13] Removed Depth tracking. --- docs/logs/extending-the-sdk/MyExporter.cs | 6 +++-- .../ConsoleLogRecordExporter.cs | 10 ++++--- .../.publicApi/net461/PublicAPI.Unshipped.txt | 1 - .../netstandard2.0/PublicAPI.Unshipped.txt | 1 - src/OpenTelemetry/Logs/LogRecord.cs | 27 +++++++------------ src/OpenTelemetry/Logs/LogRecordScope.cs | 8 +----- src/OpenTelemetry/OpenTelemetry.csproj | 1 - .../OpenTelemetry.Tests/Logs/LogRecordTest.cs | 20 +++++++------- 8 files changed, 30 insertions(+), 44 deletions(-) diff --git a/docs/logs/extending-the-sdk/MyExporter.cs b/docs/logs/extending-the-sdk/MyExporter.cs index 8e76cb77518..839f123ec1a 100644 --- a/docs/logs/extending-the-sdk/MyExporter.cs +++ b/docs/logs/extending-the-sdk/MyExporter.cs @@ -44,11 +44,13 @@ public override ExportResult Export(in Batch batch) sb.Append($"{record}("); + int depth = 0; + record.ForEachScope(ProcessScope, sb); - static void ProcessScope(LogRecordScope scope, StringBuilder builder) + void ProcessScope(LogRecordScope scope, StringBuilder builder) { - if (scope.Depth > 0) + if (depth++ > 0) { builder.Append(", "); } diff --git a/src/OpenTelemetry.Exporter.Console/ConsoleLogRecordExporter.cs b/src/OpenTelemetry.Exporter.Console/ConsoleLogRecordExporter.cs index b2119553130..5ccace8cacb 100644 --- a/src/OpenTelemetry.Exporter.Console/ConsoleLogRecordExporter.cs +++ b/src/OpenTelemetry.Exporter.Console/ConsoleLogRecordExporter.cs @@ -65,19 +65,23 @@ public override ExportResult Export(in Batch batch) this.WriteLine($"{"LogRecord.Exception:".PadRight(RightPaddingLength)}{logRecord.Exception?.Message}"); } + int scopeDepth = 0; + logRecord.ForEachScope(ProcessScope, this); - static void ProcessScope(LogRecordScope scope, ConsoleLogRecordExporter exporter) + void ProcessScope(LogRecordScope scope, ConsoleLogRecordExporter exporter) { - if (scope.Depth == 0) + if (scopeDepth == 0) { exporter.WriteLine("LogRecord.ScopeValues (Key:Value):"); } foreach (KeyValuePair scopeItem in scope) { - exporter.WriteLine($"[Scope.{scope.Depth}]:{scopeItem.Key.PadRight(RightPaddingLength)}{scopeItem.Value}"); + exporter.WriteLine($"[Scope.{scopeDepth}]:{scopeItem.Key.PadRight(RightPaddingLength)}{scopeItem.Value}"); } + + scopeDepth++; } var resource = this.ParentProvider.GetResource(); diff --git a/src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt b/src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt index 881902d07ac..227f291dcfd 100644 --- a/src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt +++ b/src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt @@ -3,7 +3,6 @@ OpenTelemetry.Logs.LogRecord.ForEachScope(OpenTelemetry.Logs.LogRecordSc OpenTelemetry.Logs.LogRecord.FormattedMessage.get -> string OpenTelemetry.Logs.LogRecord.StateValues.get -> System.Collections.Generic.IReadOnlyList> OpenTelemetry.Logs.LogRecordScope -OpenTelemetry.Logs.LogRecordScope.Depth.get -> int OpenTelemetry.Logs.LogRecordScope.Enumerator OpenTelemetry.Logs.LogRecordScope.Enumerator.Current.get -> System.Collections.Generic.KeyValuePair OpenTelemetry.Logs.LogRecordScope.Enumerator.Dispose() -> void diff --git a/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt b/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt index 881902d07ac..227f291dcfd 100644 --- a/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt +++ b/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt @@ -3,7 +3,6 @@ OpenTelemetry.Logs.LogRecord.ForEachScope(OpenTelemetry.Logs.LogRecordSc OpenTelemetry.Logs.LogRecord.FormattedMessage.get -> string OpenTelemetry.Logs.LogRecord.StateValues.get -> System.Collections.Generic.IReadOnlyList> OpenTelemetry.Logs.LogRecordScope -OpenTelemetry.Logs.LogRecordScope.Depth.get -> int OpenTelemetry.Logs.LogRecordScope.Enumerator OpenTelemetry.Logs.LogRecordScope.Enumerator.Current.get -> System.Collections.Generic.KeyValuePair OpenTelemetry.Logs.LogRecordScope.Enumerator.Dispose() -> void diff --git a/src/OpenTelemetry/Logs/LogRecord.cs b/src/OpenTelemetry/Logs/LogRecord.cs index 9cab52c1af6..620337c41ec 100644 --- a/src/OpenTelemetry/Logs/LogRecord.cs +++ b/src/OpenTelemetry/Logs/LogRecord.cs @@ -118,24 +118,20 @@ internal LogRecord( /// State. /// The callback to be executed for every scope object. /// The state object to be passed into the callback. - public unsafe void ForEachScope(LogRecordScopeCallback callback, TState state) + public void ForEachScope(LogRecordScopeCallback callback, TState state) { + var forEachScopeState = new ScopeForEachState(callback, state); + if (this.bufferedScopes != null) { - ScopeForEachState forEachState = new ScopeForEachState(callback, state, 0); - IntPtr statePointer = new IntPtr(Unsafe.AsPointer(ref forEachState)); - foreach (object scope in this.bufferedScopes) { - ScopeForEachState.ForEachScope(scope, statePointer); + ScopeForEachState.ForEachScope(scope, forEachScopeState); } } else if (this.ScopeProvider != null) { - ScopeForEachState forEachState = new ScopeForEachState(callback, state, 0); - IntPtr statePointer = new IntPtr(Unsafe.AsPointer(ref forEachState)); - - this.ScopeProvider.ForEachScope(ScopeForEachState.ForEachScope, statePointer); + this.ScopeProvider.ForEachScope(ScopeForEachState.ForEachScope, forEachScopeState); } } @@ -157,13 +153,11 @@ public void BufferLogScopes() this.bufferedScopes = scopes; } - private unsafe struct ScopeForEachState + private readonly struct ScopeForEachState { - public static readonly Action ForEachScope = (object scope, IntPtr statePointer) => + public static readonly Action> ForEachScope = (object scope, ScopeForEachState state) => { - ref ScopeForEachState state = ref Unsafe.AsRef>((void*)statePointer); - - LogRecordScope logRecordScope = new LogRecordScope(scope, state.Depth++); + LogRecordScope logRecordScope = new LogRecordScope(scope); state.Callback(logRecordScope, state.UserState); }; @@ -172,13 +166,10 @@ private unsafe struct ScopeForEachState public readonly TState UserState; - public int Depth; - - public ScopeForEachState(LogRecordScopeCallback callback, TState state, int depth) + public ScopeForEachState(LogRecordScopeCallback callback, TState state) { this.Callback = callback; this.UserState = state; - this.Depth = depth; } } } diff --git a/src/OpenTelemetry/Logs/LogRecordScope.cs b/src/OpenTelemetry/Logs/LogRecordScope.cs index dc70fcc003d..de642ded7f0 100644 --- a/src/OpenTelemetry/Logs/LogRecordScope.cs +++ b/src/OpenTelemetry/Logs/LogRecordScope.cs @@ -26,10 +26,9 @@ namespace OpenTelemetry.Logs /// public readonly ref struct LogRecordScope { - internal LogRecordScope(object scope, int depth) + internal LogRecordScope(object scope) { this.Scope = scope; - this.Depth = depth; } /// @@ -37,11 +36,6 @@ internal LogRecordScope(object scope, int depth) /// public object Scope { get; } - /// - /// Gets the depth of the current scope in the stack of active scopes. - /// - public int Depth { get; } - /// /// Gets an for looping over the inner values /// of the scope. diff --git a/src/OpenTelemetry/OpenTelemetry.csproj b/src/OpenTelemetry/OpenTelemetry.csproj index 6136f2165e9..8276e226cd1 100644 --- a/src/OpenTelemetry/OpenTelemetry.csproj +++ b/src/OpenTelemetry/OpenTelemetry.csproj @@ -7,7 +7,6 @@ --> $(NoWarn),1591,CS0618 core- - true diff --git a/test/OpenTelemetry.Tests/Logs/LogRecordTest.cs b/test/OpenTelemetry.Tests/Logs/LogRecordTest.cs index 541a13c0fae..6b108e8b780 100644 --- a/test/OpenTelemetry.Tests/Logs/LogRecordTest.cs +++ b/test/OpenTelemetry.Tests/Logs/LogRecordTest.cs @@ -357,11 +357,11 @@ public void IncludeScopesTest() this.logger.LogInformation("OpenTelemetry!"); logRecord = this.exportedItems[1]; - int actualMaxDepth = -1; + int reachedDepth = -1; logRecord.ForEachScope( (scope, state) => { - actualMaxDepth = scope.Depth; + reachedDepth++; scopes.Add(scope.Scope); foreach (KeyValuePair item in scope) { @@ -371,7 +371,7 @@ public void IncludeScopesTest() }, null); Assert.Single(scopes); - Assert.Equal(0, actualMaxDepth); + Assert.Equal(0, reachedDepth); Assert.Equal("string_scope", scopes[0]); scopes.Clear(); @@ -386,13 +386,12 @@ public void IncludeScopesTest() this.logger.LogInformation("OpenTelemetry!"); logRecord = this.exportedItems[2]; - actualMaxDepth = -1; + reachedDepth = -1; logRecord.ForEachScope( (scope, state) => { - actualMaxDepth = scope.Depth; scopes.Add(scope.Scope); - if (scope.Depth == 1) + if (reachedDepth++ == 1) { foreach (KeyValuePair item in scope) { @@ -402,7 +401,7 @@ public void IncludeScopesTest() }, null); Assert.Equal(2, scopes.Count); - Assert.Equal(1, actualMaxDepth); + Assert.Equal(1, reachedDepth); Assert.Equal("string_scope", scopes[0]); Assert.Same(expectedScope2, scopes[1]); @@ -418,13 +417,12 @@ public void IncludeScopesTest() this.logger.LogInformation("OpenTelemetry!"); logRecord = this.exportedItems[3]; - actualMaxDepth = -1; + reachedDepth = -1; logRecord.ForEachScope( (scope, state) => { - actualMaxDepth = scope.Depth; scopes.Add(scope.Scope); - if (scope.Depth == 2) + if (reachedDepth++ == 2) { foreach (KeyValuePair item in scope) { @@ -434,7 +432,7 @@ public void IncludeScopesTest() }, null); Assert.Equal(3, scopes.Count); - Assert.Equal(2, actualMaxDepth); + Assert.Equal(2, reachedDepth); Assert.Equal("string_scope", scopes[0]); Assert.Same(expectedScope2, scopes[1]); Assert.Same(expectedScope3, scopes[2]); From b4127128f6c26bebbd211b97a19f4ab0913f0dfb Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Tue, 4 May 2021 23:18:39 -0700 Subject: [PATCH 09/13] Made BufferLogScopes internal. --- docs/logs/extending-the-sdk/MyExporter.cs | 2 +- src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt | 1 - .../.publicApi/netstandard2.0/PublicAPI.Unshipped.txt | 1 - src/OpenTelemetry/Logs/LogRecord.cs | 2 +- 4 files changed, 2 insertions(+), 4 deletions(-) diff --git a/docs/logs/extending-the-sdk/MyExporter.cs b/docs/logs/extending-the-sdk/MyExporter.cs index 839f123ec1a..f51b8217769 100644 --- a/docs/logs/extending-the-sdk/MyExporter.cs +++ b/docs/logs/extending-the-sdk/MyExporter.cs @@ -58,7 +58,7 @@ void ProcessScope(LogRecordScope scope, StringBuilder builder) builder.Append($"{scope.Scope}"); } - sb.Append($")"); + sb.Append(')'); } Console.WriteLine($"{this.name}.Export([{sb.ToString()}])"); diff --git a/src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt b/src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt index 227f291dcfd..263190df718 100644 --- a/src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt +++ b/src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt @@ -1,4 +1,3 @@ -OpenTelemetry.Logs.LogRecord.BufferLogScopes() -> void OpenTelemetry.Logs.LogRecord.ForEachScope(OpenTelemetry.Logs.LogRecordScopeCallback callback, TState state) -> void OpenTelemetry.Logs.LogRecord.FormattedMessage.get -> string OpenTelemetry.Logs.LogRecord.StateValues.get -> System.Collections.Generic.IReadOnlyList> diff --git a/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt b/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt index 227f291dcfd..263190df718 100644 --- a/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt +++ b/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt @@ -1,4 +1,3 @@ -OpenTelemetry.Logs.LogRecord.BufferLogScopes() -> void OpenTelemetry.Logs.LogRecord.ForEachScope(OpenTelemetry.Logs.LogRecordScopeCallback callback, TState state) -> void OpenTelemetry.Logs.LogRecord.FormattedMessage.get -> string OpenTelemetry.Logs.LogRecord.StateValues.get -> System.Collections.Generic.IReadOnlyList> diff --git a/src/OpenTelemetry/Logs/LogRecord.cs b/src/OpenTelemetry/Logs/LogRecord.cs index 620337c41ec..d560d2d461b 100644 --- a/src/OpenTelemetry/Logs/LogRecord.cs +++ b/src/OpenTelemetry/Logs/LogRecord.cs @@ -139,7 +139,7 @@ public void ForEachScope(LogRecordScopeCallback callback, TState /// Buffers the scopes attached to the log into a list so that they can /// be safely processed after the log message lifecycle has ended. /// - public void BufferLogScopes() + internal void BufferLogScopes() { if (this.ScopeProvider == null || this.bufferedScopes != null) { From 3b9fd7c7b660c4fbc4e9c2c6662a3db209f65b1f Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Tue, 4 May 2021 23:22:06 -0700 Subject: [PATCH 10/13] Removed ref from project file. --- src/OpenTelemetry/OpenTelemetry.csproj | 1 - 1 file changed, 1 deletion(-) diff --git a/src/OpenTelemetry/OpenTelemetry.csproj b/src/OpenTelemetry/OpenTelemetry.csproj index 8276e226cd1..7db4596ba98 100644 --- a/src/OpenTelemetry/OpenTelemetry.csproj +++ b/src/OpenTelemetry/OpenTelemetry.csproj @@ -12,7 +12,6 @@ - From 9c040d4242023bc1e242762bf5fb13f3b48056a8 Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Tue, 4 May 2021 23:35:36 -0700 Subject: [PATCH 11/13] Removed LogRecordScopeCallback. --- .../.publicApi/net461/PublicAPI.Unshipped.txt | 3 +- .../netstandard2.0/PublicAPI.Unshipped.txt | 3 +- src/OpenTelemetry/Logs/LogRecord.cs | 6 ++-- src/OpenTelemetry/Logs/LogRecordScope.cs | 2 +- .../Logs/LogRecordScopeCallback.cs | 30 ------------------- test/Benchmarks/Logs/LogScopeBenchmarks.cs | 2 +- 6 files changed, 7 insertions(+), 39 deletions(-) delete mode 100644 src/OpenTelemetry/Logs/LogRecordScopeCallback.cs diff --git a/src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt b/src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt index 263190df718..b717f387a52 100644 --- a/src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt +++ b/src/OpenTelemetry/.publicApi/net461/PublicAPI.Unshipped.txt @@ -1,4 +1,4 @@ -OpenTelemetry.Logs.LogRecord.ForEachScope(OpenTelemetry.Logs.LogRecordScopeCallback callback, TState state) -> void +OpenTelemetry.Logs.LogRecord.ForEachScope(System.Action callback, TState state) -> void OpenTelemetry.Logs.LogRecord.FormattedMessage.get -> string OpenTelemetry.Logs.LogRecord.StateValues.get -> System.Collections.Generic.IReadOnlyList> OpenTelemetry.Logs.LogRecordScope @@ -12,7 +12,6 @@ OpenTelemetry.Logs.LogRecordScope.Enumerator.Reset() -> void OpenTelemetry.Logs.LogRecordScope.GetEnumerator() -> OpenTelemetry.Logs.LogRecordScope.Enumerator OpenTelemetry.Logs.LogRecordScope.LogRecordScope() -> void OpenTelemetry.Logs.LogRecordScope.Scope.get -> object -OpenTelemetry.Logs.LogRecordScopeCallback OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeFormattedMessage.get -> bool OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeFormattedMessage.set -> void OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeScopes.get -> bool diff --git a/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt b/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt index 263190df718..b717f387a52 100644 --- a/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt +++ b/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt @@ -1,4 +1,4 @@ -OpenTelemetry.Logs.LogRecord.ForEachScope(OpenTelemetry.Logs.LogRecordScopeCallback callback, TState state) -> void +OpenTelemetry.Logs.LogRecord.ForEachScope(System.Action callback, TState state) -> void OpenTelemetry.Logs.LogRecord.FormattedMessage.get -> string OpenTelemetry.Logs.LogRecord.StateValues.get -> System.Collections.Generic.IReadOnlyList> OpenTelemetry.Logs.LogRecordScope @@ -12,7 +12,6 @@ OpenTelemetry.Logs.LogRecordScope.Enumerator.Reset() -> void OpenTelemetry.Logs.LogRecordScope.GetEnumerator() -> OpenTelemetry.Logs.LogRecordScope.Enumerator OpenTelemetry.Logs.LogRecordScope.LogRecordScope() -> void OpenTelemetry.Logs.LogRecordScope.Scope.get -> object -OpenTelemetry.Logs.LogRecordScopeCallback OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeFormattedMessage.get -> bool OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeFormattedMessage.set -> void OpenTelemetry.Logs.OpenTelemetryLoggerOptions.IncludeScopes.get -> bool diff --git a/src/OpenTelemetry/Logs/LogRecord.cs b/src/OpenTelemetry/Logs/LogRecord.cs index d560d2d461b..5efb6947a41 100644 --- a/src/OpenTelemetry/Logs/LogRecord.cs +++ b/src/OpenTelemetry/Logs/LogRecord.cs @@ -118,7 +118,7 @@ internal LogRecord( /// State. /// The callback to be executed for every scope object. /// The state object to be passed into the callback. - public void ForEachScope(LogRecordScopeCallback callback, TState state) + public void ForEachScope(Action callback, TState state) { var forEachScopeState = new ScopeForEachState(callback, state); @@ -162,11 +162,11 @@ private readonly struct ScopeForEachState state.Callback(logRecordScope, state.UserState); }; - public readonly LogRecordScopeCallback Callback; + public readonly Action Callback; public readonly TState UserState; - public ScopeForEachState(LogRecordScopeCallback callback, TState state) + public ScopeForEachState(Action callback, TState state) { this.Callback = callback; this.UserState = state; diff --git a/src/OpenTelemetry/Logs/LogRecordScope.cs b/src/OpenTelemetry/Logs/LogRecordScope.cs index de642ded7f0..5c99dbdd791 100644 --- a/src/OpenTelemetry/Logs/LogRecordScope.cs +++ b/src/OpenTelemetry/Logs/LogRecordScope.cs @@ -24,7 +24,7 @@ namespace OpenTelemetry.Logs /// /// Stores details about a scope attached to a log message. /// - public readonly ref struct LogRecordScope + public readonly struct LogRecordScope { internal LogRecordScope(object scope) { diff --git a/src/OpenTelemetry/Logs/LogRecordScopeCallback.cs b/src/OpenTelemetry/Logs/LogRecordScopeCallback.cs deleted file mode 100644 index 38adee399dd..00000000000 --- a/src/OpenTelemetry/Logs/LogRecordScopeCallback.cs +++ /dev/null @@ -1,30 +0,0 @@ -// -// 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. -// - -#if NET461 || NETSTANDARD2_0 -namespace OpenTelemetry.Logs -{ - /// - /// Callback delegate for the method. - /// - /// State type. - /// . - /// State. - public delegate void LogRecordScopeCallback(LogRecordScope scope, TState state); -} -#endif diff --git a/test/Benchmarks/Logs/LogScopeBenchmarks.cs b/test/Benchmarks/Logs/LogScopeBenchmarks.cs index a1e26713e1f..5906cb03a76 100644 --- a/test/Benchmarks/Logs/LogScopeBenchmarks.cs +++ b/test/Benchmarks/Logs/LogScopeBenchmarks.cs @@ -29,7 +29,7 @@ public class LogScopeBenchmarks { private readonly LoggerExternalScopeProvider scopeProvider = new LoggerExternalScopeProvider(); - private readonly LogRecordScopeCallback callback = (LogRecordScope scope, object state) => + private readonly Action callback = (LogRecordScope scope, object state) => { foreach (KeyValuePair scopeItem in scope) { From 35af5dc22b89ce5cd80589214ed09ca882fb30e3 Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Tue, 4 May 2021 23:41:00 -0700 Subject: [PATCH 12/13] Cleanup. --- docs/logs/extending-the-sdk/MyExporter.cs | 4 ++-- .../ConsoleLogRecordExporter.cs | 6 ++---- 2 files changed, 4 insertions(+), 6 deletions(-) diff --git a/docs/logs/extending-the-sdk/MyExporter.cs b/docs/logs/extending-the-sdk/MyExporter.cs index f51b8217769..a2ada04b8c7 100644 --- a/docs/logs/extending-the-sdk/MyExporter.cs +++ b/docs/logs/extending-the-sdk/MyExporter.cs @@ -44,13 +44,13 @@ public override ExportResult Export(in Batch batch) sb.Append($"{record}("); - int depth = 0; + int scopeDepth = -1; record.ForEachScope(ProcessScope, sb); void ProcessScope(LogRecordScope scope, StringBuilder builder) { - if (depth++ > 0) + if (++scopeDepth > 0) { builder.Append(", "); } diff --git a/src/OpenTelemetry.Exporter.Console/ConsoleLogRecordExporter.cs b/src/OpenTelemetry.Exporter.Console/ConsoleLogRecordExporter.cs index 5ccace8cacb..2b9b6faaad8 100644 --- a/src/OpenTelemetry.Exporter.Console/ConsoleLogRecordExporter.cs +++ b/src/OpenTelemetry.Exporter.Console/ConsoleLogRecordExporter.cs @@ -65,13 +65,13 @@ public override ExportResult Export(in Batch batch) this.WriteLine($"{"LogRecord.Exception:".PadRight(RightPaddingLength)}{logRecord.Exception?.Message}"); } - int scopeDepth = 0; + int scopeDepth = -1; logRecord.ForEachScope(ProcessScope, this); void ProcessScope(LogRecordScope scope, ConsoleLogRecordExporter exporter) { - if (scopeDepth == 0) + if (++scopeDepth == 0) { exporter.WriteLine("LogRecord.ScopeValues (Key:Value):"); } @@ -80,8 +80,6 @@ void ProcessScope(LogRecordScope scope, ConsoleLogRecordExporter exporter) { exporter.WriteLine($"[Scope.{scopeDepth}]:{scopeItem.Key.PadRight(RightPaddingLength)}{scopeItem.Value}"); } - - scopeDepth++; } var resource = this.ParentProvider.GetResource(); From 7e31424a3b0677f60942e9d87658ee1e01ca92f5 Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Tue, 4 May 2021 23:46:10 -0700 Subject: [PATCH 13/13] CHANGELOG tweaks. --- src/OpenTelemetry/CHANGELOG.md | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/src/OpenTelemetry/CHANGELOG.md b/src/OpenTelemetry/CHANGELOG.md index 5ef305ab55d..bfd80b5510b 100644 --- a/src/OpenTelemetry/CHANGELOG.md +++ b/src/OpenTelemetry/CHANGELOG.md @@ -9,10 +9,11 @@ please check the latest changes ## Unreleased -* Added `LogRecord.BufferLogScopes` to capture log scopes for out-of-band - processing. To make parsing scopes easier the `LogRecord.ForEachScope` - signature has been changed to pass instances of `LogRecordScope` (a new type - which includes an `IEnumerator>`) +* Fixed an issue causing inconsistent log scopes when using + `BatchLogRecordExportProcessor`. To make parsing scopes easier the + `LogRecord.ForEachScope` signature has been changed to receive instances of + `LogRecordScope` (a new type which implements + `IEnumerator>` for accessing scope items) ([#2026](https://github.com/open-telemetry/opentelemetry-dotnet/pull/2026)) ## 1.1.0-beta2