From 3841023e47e6fbe5515fbc2bae567dc4b4809aeb Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Sat, 18 Jun 2022 10:33:09 -0700 Subject: [PATCH 01/15] Add log record pooling. --- .../InMemoryExporterLoggingExtensions.cs | 12 +- .../.publicApi/net462/PublicAPI.Unshipped.txt | 4 +- .../.publicApi/net6.0/PublicAPI.Unshipped.txt | 4 +- .../netstandard2.0/PublicAPI.Unshipped.txt | 4 +- .../netstandard2.1/PublicAPI.Unshipped.txt | 4 +- src/OpenTelemetry/Batch.cs | 41 ++- src/OpenTelemetry/BatchExportProcessor.cs | 15 +- src/OpenTelemetry/CompositeProcessor.cs | 20 +- .../Logs/BatchLogRecordExportProcessor.cs | 9 +- src/OpenTelemetry/Logs/LogRecord.cs | 46 ++- src/OpenTelemetry/Logs/OpenTelemetryLogger.cs | 53 +++- .../Logs/OpenTelemetryLoggerProvider.cs | 33 ++- src/OpenTelemetry/Logs/Pool/ILogRecordPool.cs | 27 ++ src/OpenTelemetry/Logs/Pool/LogRecordPool.cs | 39 +++ .../Logs/Pool/LogRecordSharedPool.cs | 180 ++++++++++++ .../Logs/Pool/LogRecordThreadStaticPool.cs | 55 ++++ test/Benchmarks/Logs/LogScopeBenchmarks.cs | 2 + .../Logs/LogRecordSharedPoolTests.cs | 278 ++++++++++++++++++ .../Logs/LogRecordThreadStaticPoolTests.cs | 90 ++++++ .../Logs/OpenTelemetryLoggerProviderTests.cs | 60 ++++ 20 files changed, 928 insertions(+), 48 deletions(-) create mode 100644 src/OpenTelemetry/Logs/Pool/ILogRecordPool.cs create mode 100644 src/OpenTelemetry/Logs/Pool/LogRecordPool.cs create mode 100644 src/OpenTelemetry/Logs/Pool/LogRecordSharedPool.cs create mode 100644 src/OpenTelemetry/Logs/Pool/LogRecordThreadStaticPool.cs create mode 100644 test/OpenTelemetry.Tests/Logs/LogRecordSharedPoolTests.cs create mode 100644 test/OpenTelemetry.Tests/Logs/LogRecordThreadStaticPoolTests.cs diff --git a/src/OpenTelemetry.Exporter.InMemory/InMemoryExporterLoggingExtensions.cs b/src/OpenTelemetry.Exporter.InMemory/InMemoryExporterLoggingExtensions.cs index ca67d4f3be5..d20d9967a04 100644 --- a/src/OpenTelemetry.Exporter.InMemory/InMemoryExporterLoggingExtensions.cs +++ b/src/OpenTelemetry.Exporter.InMemory/InMemoryExporterLoggingExtensions.cs @@ -42,9 +42,17 @@ private static ExportResult ExportLogRecord(in Batch batch, ICollecti foreach (var log in batch) { - log.BufferLogScopes(); + log.Buffer(); - exportedItems.Add(log); + LogRecord copy = new() + { + Data = log.Data, + State = log.State, + StateValues = log.StateValues == null ? null : new List>(log.StateValues), + BufferedScopes = log.BufferedScopes == null ? null : new List(log.BufferedScopes), + }; + + exportedItems.Add(copy); } return ExportResult.Success; diff --git a/src/OpenTelemetry/.publicApi/net462/PublicAPI.Unshipped.txt b/src/OpenTelemetry/.publicApi/net462/PublicAPI.Unshipped.txt index 3f5fd985f93..a0be84b92af 100644 --- a/src/OpenTelemetry/.publicApi/net462/PublicAPI.Unshipped.txt +++ b/src/OpenTelemetry/.publicApi/net462/PublicAPI.Unshipped.txt @@ -7,6 +7,8 @@ OpenTelemetry.Logs.LogRecord.Timestamp.set -> void OpenTelemetry.Logs.LogRecord.TraceFlags.set -> void OpenTelemetry.Logs.LogRecord.TraceId.set -> void OpenTelemetry.Logs.LogRecord.TraceState.set -> void +OpenTelemetry.Logs.LogRecordPool OpenTelemetry.Logs.OpenTelemetryLoggerProvider.ForceFlush(int timeoutMilliseconds = -1) -> bool OpenTelemetry.Logs.OpenTelemetryLoggerProvider.OpenTelemetryLoggerProvider() -> void -OpenTelemetry.Logs.OpenTelemetryLoggerProvider.OpenTelemetryLoggerProvider(System.Action! configure) -> void \ No newline at end of file +OpenTelemetry.Logs.OpenTelemetryLoggerProvider.OpenTelemetryLoggerProvider(System.Action! configure) -> void +static OpenTelemetry.Logs.LogRecordPool.Resize(int capacity) -> void \ No newline at end of file diff --git a/src/OpenTelemetry/.publicApi/net6.0/PublicAPI.Unshipped.txt b/src/OpenTelemetry/.publicApi/net6.0/PublicAPI.Unshipped.txt index 3f5fd985f93..a0be84b92af 100644 --- a/src/OpenTelemetry/.publicApi/net6.0/PublicAPI.Unshipped.txt +++ b/src/OpenTelemetry/.publicApi/net6.0/PublicAPI.Unshipped.txt @@ -7,6 +7,8 @@ OpenTelemetry.Logs.LogRecord.Timestamp.set -> void OpenTelemetry.Logs.LogRecord.TraceFlags.set -> void OpenTelemetry.Logs.LogRecord.TraceId.set -> void OpenTelemetry.Logs.LogRecord.TraceState.set -> void +OpenTelemetry.Logs.LogRecordPool OpenTelemetry.Logs.OpenTelemetryLoggerProvider.ForceFlush(int timeoutMilliseconds = -1) -> bool OpenTelemetry.Logs.OpenTelemetryLoggerProvider.OpenTelemetryLoggerProvider() -> void -OpenTelemetry.Logs.OpenTelemetryLoggerProvider.OpenTelemetryLoggerProvider(System.Action! configure) -> void \ No newline at end of file +OpenTelemetry.Logs.OpenTelemetryLoggerProvider.OpenTelemetryLoggerProvider(System.Action! configure) -> void +static OpenTelemetry.Logs.LogRecordPool.Resize(int capacity) -> void \ No newline at end of file diff --git a/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt b/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt index 3f5fd985f93..a0be84b92af 100644 --- a/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt +++ b/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt @@ -7,6 +7,8 @@ OpenTelemetry.Logs.LogRecord.Timestamp.set -> void OpenTelemetry.Logs.LogRecord.TraceFlags.set -> void OpenTelemetry.Logs.LogRecord.TraceId.set -> void OpenTelemetry.Logs.LogRecord.TraceState.set -> void +OpenTelemetry.Logs.LogRecordPool OpenTelemetry.Logs.OpenTelemetryLoggerProvider.ForceFlush(int timeoutMilliseconds = -1) -> bool OpenTelemetry.Logs.OpenTelemetryLoggerProvider.OpenTelemetryLoggerProvider() -> void -OpenTelemetry.Logs.OpenTelemetryLoggerProvider.OpenTelemetryLoggerProvider(System.Action! configure) -> void \ No newline at end of file +OpenTelemetry.Logs.OpenTelemetryLoggerProvider.OpenTelemetryLoggerProvider(System.Action! configure) -> void +static OpenTelemetry.Logs.LogRecordPool.Resize(int capacity) -> void \ No newline at end of file diff --git a/src/OpenTelemetry/.publicApi/netstandard2.1/PublicAPI.Unshipped.txt b/src/OpenTelemetry/.publicApi/netstandard2.1/PublicAPI.Unshipped.txt index 3f5fd985f93..a0be84b92af 100644 --- a/src/OpenTelemetry/.publicApi/netstandard2.1/PublicAPI.Unshipped.txt +++ b/src/OpenTelemetry/.publicApi/netstandard2.1/PublicAPI.Unshipped.txt @@ -7,6 +7,8 @@ OpenTelemetry.Logs.LogRecord.Timestamp.set -> void OpenTelemetry.Logs.LogRecord.TraceFlags.set -> void OpenTelemetry.Logs.LogRecord.TraceId.set -> void OpenTelemetry.Logs.LogRecord.TraceState.set -> void +OpenTelemetry.Logs.LogRecordPool OpenTelemetry.Logs.OpenTelemetryLoggerProvider.ForceFlush(int timeoutMilliseconds = -1) -> bool OpenTelemetry.Logs.OpenTelemetryLoggerProvider.OpenTelemetryLoggerProvider() -> void -OpenTelemetry.Logs.OpenTelemetryLoggerProvider.OpenTelemetryLoggerProvider(System.Action! configure) -> void \ No newline at end of file +OpenTelemetry.Logs.OpenTelemetryLoggerProvider.OpenTelemetryLoggerProvider(System.Action! configure) -> void +static OpenTelemetry.Logs.LogRecordPool.Resize(int capacity) -> void \ No newline at end of file diff --git a/src/OpenTelemetry/Batch.cs b/src/OpenTelemetry/Batch.cs index b518e8c5d05..9f04f9ec567 100644 --- a/src/OpenTelemetry/Batch.cs +++ b/src/OpenTelemetry/Batch.cs @@ -22,6 +22,7 @@ using System.Diagnostics; using System.Diagnostics.CodeAnalysis; using OpenTelemetry.Internal; +using OpenTelemetry.Logs; namespace OpenTelemetry { @@ -90,7 +91,11 @@ public void Dispose() // Drain anything left in the batch. while (this.circularBuffer.RemovedCount < this.targetCount) { - this.circularBuffer.Read(); + T item = this.circularBuffer.Read(); + if (typeof(T) == typeof(LogRecord)) + { + LogRecordSharedPool.Current.Return((LogRecord)(object)item); + } } } } @@ -140,6 +145,29 @@ public struct Enumerator : IEnumerator return false; }; + private static readonly BatchEnumeratorMoveNextFunc MoveNextCircularBufferLogRecord = (ref Enumerator enumerator) => + { + var circularBuffer = enumerator.circularBuffer; + + var currentItem = enumerator.Current; + if (currentItem != null) + { + if (typeof(T) == typeof(LogRecord)) + { + LogRecordSharedPool.Current.Return((LogRecord)(object)currentItem); + } + } + + if (circularBuffer!.RemovedCount < enumerator.targetCount) + { + enumerator.current = circularBuffer.Read(); + return true; + } + + enumerator.current = null; + return false; + }; + private static readonly BatchEnumeratorMoveNextFunc MoveNextArray = (ref Enumerator enumerator) => { var items = enumerator.items; @@ -179,7 +207,7 @@ internal Enumerator(CircularBuffer circularBuffer, long targetCount) this.circularBuffer = circularBuffer; this.targetCount = targetCount; this.itemIndex = 0; - this.moveNextFunc = MoveNextCircularBuffer; + this.moveNextFunc = typeof(T) == typeof(LogRecord) ? MoveNextCircularBufferLogRecord : MoveNextCircularBuffer; } internal Enumerator(T[] items, long targetCount) @@ -201,6 +229,15 @@ internal Enumerator(T[] items, long targetCount) /// public void Dispose() { + if (typeof(T) == typeof(LogRecord)) + { + var currentItem = this.current; + if (currentItem != null) + { + LogRecordSharedPool.Current.Return((LogRecord)(object)currentItem); + this.current = null; + } + } } /// diff --git a/src/OpenTelemetry/BatchExportProcessor.cs b/src/OpenTelemetry/BatchExportProcessor.cs index d42c9464325..5fdc2c8893f 100644 --- a/src/OpenTelemetry/BatchExportProcessor.cs +++ b/src/OpenTelemetry/BatchExportProcessor.cs @@ -18,6 +18,7 @@ using System; using System.Diagnostics; +using System.Runtime.CompilerServices; using System.Threading; using OpenTelemetry.Internal; @@ -95,8 +96,8 @@ protected BatchExportProcessor( /// internal long ProcessedCount => this.circularBuffer.RemovedCount; - /// - protected override void OnExport(T data) + [MethodImpl(MethodImplOptions.AggressiveInlining)] + internal bool TryExport(T data) { if (this.circularBuffer.TryAdd(data, maxSpinCount: 50000)) { @@ -111,11 +112,19 @@ protected override void OnExport(T data) } } - return; // enqueue succeeded + return true; // enqueue succeeded } // either the queue is full or exceeded the spin limit, drop the item on the floor Interlocked.Increment(ref this.droppedCount); + + return false; + } + + /// + protected override void OnExport(T data) + { + this.TryExport(data); } /// diff --git a/src/OpenTelemetry/CompositeProcessor.cs b/src/OpenTelemetry/CompositeProcessor.cs index a9546ab179a..38a2babf9c9 100644 --- a/src/OpenTelemetry/CompositeProcessor.cs +++ b/src/OpenTelemetry/CompositeProcessor.cs @@ -26,7 +26,7 @@ namespace OpenTelemetry { public class CompositeProcessor : BaseProcessor { - private readonly DoublyLinkedListNode head; + internal readonly DoublyLinkedListNode Head; private DoublyLinkedListNode tail; private bool disposed; @@ -40,8 +40,8 @@ public CompositeProcessor(IEnumerable> processors) throw new ArgumentException($"'{iter}' is null or empty", nameof(iter)); } - this.head = new DoublyLinkedListNode(iter.Current); - this.tail = this.head; + this.Head = new DoublyLinkedListNode(iter.Current); + this.tail = this.Head; while (iter.MoveNext()) { @@ -66,7 +66,7 @@ public CompositeProcessor AddProcessor(BaseProcessor processor) /// public override void OnEnd(T data) { - for (var cur = this.head; cur != null; cur = cur.Next) + for (var cur = this.Head; cur != null; cur = cur.Next) { cur.Value.OnEnd(data); } @@ -75,7 +75,7 @@ public override void OnEnd(T data) /// public override void OnStart(T data) { - for (var cur = this.head; cur != null; cur = cur.Next) + for (var cur = this.Head; cur != null; cur = cur.Next) { cur.Value.OnStart(data); } @@ -85,7 +85,7 @@ internal override void SetParentProvider(BaseProvider parentProvider) { base.SetParentProvider(parentProvider); - for (var cur = this.head; cur != null; cur = cur.Next) + for (var cur = this.Head; cur != null; cur = cur.Next) { cur.Value.SetParentProvider(parentProvider); } @@ -99,7 +99,7 @@ protected override bool OnForceFlush(int timeoutMilliseconds) ? null : Stopwatch.StartNew(); - for (var cur = this.head; cur != null; cur = cur.Next) + for (var cur = this.Head; cur != null; cur = cur.Next) { if (sw == null) { @@ -125,7 +125,7 @@ protected override bool OnShutdown(int timeoutMilliseconds) ? null : Stopwatch.StartNew(); - for (var cur = this.head; cur != null; cur = cur.Next) + for (var cur = this.Head; cur != null; cur = cur.Next) { if (sw == null) { @@ -150,7 +150,7 @@ protected override void Dispose(bool disposing) { if (disposing) { - for (var cur = this.head; cur != null; cur = cur.Next) + for (var cur = this.Head; cur != null; cur = cur.Next) { try { @@ -169,7 +169,7 @@ protected override void Dispose(bool disposing) base.Dispose(disposing); } - private class DoublyLinkedListNode + internal sealed class DoublyLinkedListNode { public readonly BaseProcessor Value; diff --git a/src/OpenTelemetry/Logs/BatchLogRecordExportProcessor.cs b/src/OpenTelemetry/Logs/BatchLogRecordExportProcessor.cs index 8eb8cebe579..4b77537dd2c 100644 --- a/src/OpenTelemetry/Logs/BatchLogRecordExportProcessor.cs +++ b/src/OpenTelemetry/Logs/BatchLogRecordExportProcessor.cs @@ -57,9 +57,14 @@ public override void OnEnd(LogRecord data) // happen here. Debug.Assert(data != null, "LogRecord was null."); - data!.BufferLogScopes(); + data!.Buffer(); - base.OnEnd(data); + LogRecordSharedPool.Current.TrackReference(data); + + if (!this.TryExport(data)) + { + LogRecordSharedPool.Current.Return(data); + } } } } diff --git a/src/OpenTelemetry/Logs/LogRecord.cs b/src/OpenTelemetry/Logs/LogRecord.cs index 98c937e7244..41c263af1a6 100644 --- a/src/OpenTelemetry/Logs/LogRecord.cs +++ b/src/OpenTelemetry/Logs/LogRecord.cs @@ -30,15 +30,21 @@ namespace OpenTelemetry.Logs public sealed class LogRecord { internal LogRecordData Data; + internal List>? AttributeStorage; + internal List? BufferedScopes; + internal int PoolReferenceCount = int.MaxValue; private static readonly Action> AddScopeToBufferedList = (object? scope, List state) => { state.Add(scope); }; - private List? bufferedScopes; + internal LogRecord() + { + } // Note: Some users are calling this with reflection. Try not to change the signature to be nice. + [Obsolete("Call LogRecordPool.Rent instead.")] internal LogRecord( IExternalScopeProvider? scopeProvider, DateTime timestamp, @@ -191,9 +197,9 @@ public void ForEachScope(Action callback, TState var forEachScopeState = new ScopeForEachState(callback, state); - if (this.bufferedScopes != null) + if (this.BufferedScopes != null) { - foreach (object? scope in this.bufferedScopes) + foreach (object? scope in this.BufferedScopes) { ScopeForEachState.ForEachScope(scope, forEachScopeState); } @@ -213,22 +219,46 @@ internal ref LogRecordData GetDataRef() return ref this.Data; } + internal void Buffer() + { + this.BufferLogStateValues(); + this.BufferLogScopes(); + } + + /// + /// Buffers the state values attached to the log into a list so that + /// they can be safely processed after the log message lifecycle has + /// ended. + /// + private void BufferLogStateValues() + { + var stateValues = this.StateValues; + if (stateValues == null || stateValues == this.AttributeStorage) + { + return; + } + + var attributeStorage = this.AttributeStorage ??= new List>(stateValues.Count); + attributeStorage.AddRange(stateValues); + this.StateValues = attributeStorage; + } + /// /// Buffers the scopes attached to the log into a list so that they can /// be safely processed after the log message lifecycle has ended. /// - internal void BufferLogScopes() + private void BufferLogScopes() { - if (this.ScopeProvider == null || this.bufferedScopes != null) + if (this.ScopeProvider == null) { return; } - List scopes = new List(); + List scopes = this.BufferedScopes ??= new List(16); - this.ScopeProvider?.ForEachScope(AddScopeToBufferedList, scopes); + this.ScopeProvider.ForEachScope(AddScopeToBufferedList, scopes); - this.bufferedScopes = scopes; + this.ScopeProvider = null; } private readonly struct ScopeForEachState diff --git a/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs b/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs index 8a128682d93..14069725066 100644 --- a/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs +++ b/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs @@ -18,6 +18,7 @@ using System; using System.Collections.Generic; +using System.Diagnostics; using System.Runtime.CompilerServices; using Microsoft.Extensions.Logging; using OpenTelemetry.Internal; @@ -52,20 +53,32 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except var processor = provider.Processor; if (processor != null) { - var record = new LogRecord( - provider.IncludeScopes ? this.ScopeProvider : null, - DateTime.UtcNow, - this.categoryName, - logLevel, - eventId, - provider.IncludeFormattedMessage ? formatter?.Invoke(state, exception) : null, - provider.ParseStateValues ? null : state, - exception, - provider.ParseStateValues ? this.ParseState(state) : null); + var pool = provider.LogRecordPool; + + var record = pool.Rent(); + + record.ScopeProvider = provider.IncludeScopes ? this.ScopeProvider : null; + record.State = provider.ParseStateValues ? null : state; + record.StateValues = provider.ParseStateValues ? this.ParseState(record, state) : null; + + ref LogRecordData data = ref record.Data; + + data.TimestampBacking = DateTime.UtcNow; + data.CategoryName = this.categoryName; + data.LogLevel = logLevel; + data.EventId = eventId; + data.Message = provider.IncludeFormattedMessage ? formatter?.Invoke(state, exception) : null; + data.Exception = exception; + + LogRecordData.SetActivityContext(ref data, Activity.Current); processor.OnEnd(record); record.ScopeProvider = null; + + // Attempt to return the LogRecord to the pool. This will no-op + // if a batch exporter has added a reference. + pool.Return(record); } } @@ -77,7 +90,7 @@ public bool IsEnabled(LogLevel logLevel) public IDisposable BeginScope(TState state) => this.ScopeProvider?.Push(state) ?? NullScope.Instance; - private IReadOnlyList> ParseState(TState state) + private IReadOnlyList> ParseState(LogRecord logRecord, TState state) { if (state is IReadOnlyList> stateList) { @@ -85,14 +98,22 @@ public bool IsEnabled(LogLevel logLevel) } else if (state is IEnumerable> stateValues) { - return new List>(stateValues); + var attributeStorage = logRecord.AttributeStorage; + if (attributeStorage == null) + { + return logRecord.AttributeStorage = new List>(stateValues); + } + else + { + attributeStorage.AddRange(stateValues); + return attributeStorage; + } } else { - return new List> - { - new KeyValuePair(string.Empty, state), - }; + var attributeStorage = logRecord.AttributeStorage ??= new List>(8); + attributeStorage.Add(new KeyValuePair(string.Empty, state)); + return attributeStorage; } } diff --git a/src/OpenTelemetry/Logs/OpenTelemetryLoggerProvider.cs b/src/OpenTelemetry/Logs/OpenTelemetryLoggerProvider.cs index c057445c84b..221dbd11651 100644 --- a/src/OpenTelemetry/Logs/OpenTelemetryLoggerProvider.cs +++ b/src/OpenTelemetry/Logs/OpenTelemetryLoggerProvider.cs @@ -38,6 +38,7 @@ public class OpenTelemetryLoggerProvider : BaseProvider, ILoggerProvider, ISuppo internal BaseProcessor? Processor; internal Resource Resource; private readonly Hashtable loggers = new(); + private ILogRecordPool? threadStaticPool = LogRecordThreadStaticPool.Instance; private bool disposed; static OpenTelemetryLoggerProvider() @@ -52,7 +53,7 @@ static OpenTelemetryLoggerProvider() /// /// . public OpenTelemetryLoggerProvider(IOptionsMonitor options) - : this(options?.CurrentValue!) + : this(options?.CurrentValue ?? throw new ArgumentNullException(nameof(options))) { } @@ -91,6 +92,8 @@ internal OpenTelemetryLoggerProvider(OpenTelemetryLoggerOptions options) internal IExternalScopeProvider? ScopeProvider { get; private set; } + internal ILogRecordPool LogRecordPool => this.threadStaticPool ?? LogRecordSharedPool.Current; + /// void ISupportExternalScope.SetScopeProvider(IExternalScopeProvider scopeProvider) { @@ -160,6 +163,11 @@ internal OpenTelemetryLoggerProvider AddProcessor(BaseProcessor proce processor.SetParentProvider(this); + if (this.threadStaticPool != null && this.ContainsBatchProcessor(processor)) + { + this.threadStaticPool = null; + } + if (this.Processor == null) { this.Processor = processor; @@ -182,6 +190,29 @@ internal OpenTelemetryLoggerProvider AddProcessor(BaseProcessor proce return this; } + internal bool ContainsBatchProcessor(BaseProcessor processor) + { + if (processor is BatchExportProcessor) + { + return true; + } + else if (processor is CompositeProcessor compositeProcessor) + { + var current = compositeProcessor.Head; + while (current != null) + { + if (this.ContainsBatchProcessor(current.Value)) + { + return true; + } + + current = current.Next; + } + } + + return false; + } + /// protected override void Dispose(bool disposing) { diff --git a/src/OpenTelemetry/Logs/Pool/ILogRecordPool.cs b/src/OpenTelemetry/Logs/Pool/ILogRecordPool.cs new file mode 100644 index 00000000000..14d12cc6e36 --- /dev/null +++ b/src/OpenTelemetry/Logs/Pool/ILogRecordPool.cs @@ -0,0 +1,27 @@ +// +// 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. +// + +#nullable enable + +namespace OpenTelemetry.Logs +{ + internal interface ILogRecordPool + { + LogRecord Rent(); + + void Return(LogRecord logRecord); + } +} diff --git a/src/OpenTelemetry/Logs/Pool/LogRecordPool.cs b/src/OpenTelemetry/Logs/Pool/LogRecordPool.cs new file mode 100644 index 00000000000..c6a337b3b0a --- /dev/null +++ b/src/OpenTelemetry/Logs/Pool/LogRecordPool.cs @@ -0,0 +1,39 @@ +// +// 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. +// + +#nullable enable + +using OpenTelemetry.Internal; + +namespace OpenTelemetry.Logs +{ + /// + /// Manages a pool of instances. + /// + public static class LogRecordPool + { + /// + /// Resize the pool. + /// + /// The maximum number of s to store in the pool. + public static void Resize(int capacity) + { + Guard.ThrowIfOutOfRange(capacity, min: 1); + + LogRecordSharedPool.Current = new(capacity); + } + } +} diff --git a/src/OpenTelemetry/Logs/Pool/LogRecordSharedPool.cs b/src/OpenTelemetry/Logs/Pool/LogRecordSharedPool.cs new file mode 100644 index 00000000000..14285b8aab4 --- /dev/null +++ b/src/OpenTelemetry/Logs/Pool/LogRecordSharedPool.cs @@ -0,0 +1,180 @@ +// +// 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. +// + +#nullable enable + +using System.Diagnostics.CodeAnalysis; +using System.Runtime.CompilerServices; +using System.Threading; + +namespace OpenTelemetry.Logs +{ + internal sealed class LogRecordSharedPool : ILogRecordPool + { + internal const int DefaultMaxPoolSize = 2048; + internal const int DefaultMaxNumberOfAttributes = 64; + internal const int DefaultMaxNumberOfScopes = 16; + + internal static LogRecordSharedPool Current = new(DefaultMaxPoolSize); + + internal readonly int Capacity; + private readonly LogRecord?[] pool; + private long rentIndex; + private long returnIndex; + + internal LogRecordSharedPool(int capacity) + { + this.Capacity = capacity; + this.pool = new LogRecord?[capacity]; + } + + internal int Count => (int)(Volatile.Read(ref this.returnIndex) - Volatile.Read(ref this.rentIndex)); + + public LogRecord Rent() + { + while (true) + { + var rentSnapshot = Volatile.Read(ref this.rentIndex); + var returnSnapshot = Volatile.Read(ref this.returnIndex); + + if (rentSnapshot >= returnSnapshot) + { + break; // buffer is empty + } + + if (Interlocked.CompareExchange(ref this.rentIndex, rentSnapshot + 1, rentSnapshot) == rentSnapshot) + { + var logRecord = Interlocked.Exchange(ref this.pool[rentSnapshot % this.Capacity], null); + if (logRecord == null && !this.TryRentCoreRare(rentSnapshot, out logRecord)) + { + continue; + } + + logRecord.PoolReferenceCount = 1; + return logRecord; + } + } + + return new LogRecord() + { + PoolReferenceCount = 1, + }; + } + + public void Return(LogRecord logRecord) + { + if (Interlocked.Decrement(ref logRecord.PoolReferenceCount) != 0) + { + return; + } + + Clear(logRecord); + + while (true) + { + var rentSnapshot = Volatile.Read(ref this.rentIndex); + var returnSnapshot = Volatile.Read(ref this.returnIndex); + + if (returnSnapshot - rentSnapshot >= this.Capacity) + { + return; // buffer is full + } + + if (Interlocked.CompareExchange(ref this.returnIndex, returnSnapshot + 1, returnSnapshot) == returnSnapshot) + { + // If many threads are hammering rent/return it is possible + // for two threads to write to the same index. In that case + // only one of the logRecords will make it back into the + // pool. Anything lost in the race will collected by the GC + // and the pool will issue new instances as needed + this.pool[returnSnapshot % this.Capacity] = logRecord; + return; + } + } + } + + [MethodImpl(MethodImplOptions.AggressiveInlining)] + public void TrackReference(LogRecord logRecord) + { + Interlocked.Increment(ref logRecord.PoolReferenceCount); + } + + internal static void Clear(LogRecord logRecord) + { + var attributeStorage = logRecord.AttributeStorage; + if (attributeStorage != null) + { + if (attributeStorage.Count > DefaultMaxNumberOfAttributes) + { + // Don't allow the pool to grow unconstained. + logRecord.AttributeStorage = null; + } + else + { + /* List.Clear sets the size to 0 but it maintains the + underlying array. */ + attributeStorage.Clear(); + } + } + + var bufferedScopes = logRecord.BufferedScopes; + if (bufferedScopes != null) + { + if (bufferedScopes.Count > DefaultMaxNumberOfScopes) + { + // Don't allow the pool to grow unconstained. + logRecord.BufferedScopes = null; + } + else + { + /* List.Clear sets the size to 0 but it maintains the + underlying array. */ + bufferedScopes.Clear(); + } + } + } + + private bool TryRentCoreRare(long rentSnapshot, [NotNullWhen(true)] out LogRecord? logRecord) + { + SpinWait wait = default; + while (true) + { + if (wait.NextSpinWillYield) + { + // Super rare case. If many threads are hammering + // rent/return it is possible a read was issued an index and + // then yielded while other threads caused the pointers to + // wrap around. When the yielded thread wakes up its read + // index could have been stolen by another thread. To + // prevent deadlock, bail out of read after spinning. This + // will cause either a successful rent from another index, + // or a new record to be created + logRecord = null; + return false; + } + + wait.SpinOnce(); + + logRecord = Interlocked.Exchange(ref this.pool[rentSnapshot % this.Capacity], null); + if (logRecord != null) + { + // Rare case where the write was still working when the read came in + return true; + } + } + } + } +} diff --git a/src/OpenTelemetry/Logs/Pool/LogRecordThreadStaticPool.cs b/src/OpenTelemetry/Logs/Pool/LogRecordThreadStaticPool.cs new file mode 100644 index 00000000000..90a2c3759ae --- /dev/null +++ b/src/OpenTelemetry/Logs/Pool/LogRecordThreadStaticPool.cs @@ -0,0 +1,55 @@ +// +// 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. +// + +#nullable enable + +using System; + +namespace OpenTelemetry.Logs +{ + internal sealed class LogRecordThreadStaticPool : ILogRecordPool + { + [ThreadStatic] + internal static LogRecord? Storage; + + private LogRecordThreadStaticPool() + { + } + + public static LogRecordThreadStaticPool Instance { get; } = new(); + + public LogRecord Rent() + { + var logRecord = Storage; + if (logRecord != null) + { + Storage = null; + return logRecord; + } + + return new(); + } + + public void Return(LogRecord logRecord) + { + if (Storage == null) + { + LogRecordSharedPool.Clear(logRecord); + Storage = logRecord; + } + } + } +} diff --git a/test/Benchmarks/Logs/LogScopeBenchmarks.cs b/test/Benchmarks/Logs/LogScopeBenchmarks.cs index 7c21f970e9a..9cc2347d6e3 100644 --- a/test/Benchmarks/Logs/LogScopeBenchmarks.cs +++ b/test/Benchmarks/Logs/LogScopeBenchmarks.cs @@ -56,6 +56,7 @@ public LogScopeBenchmarks() new KeyValuePair("item5", "value5"), })); +#pragma warning disable CS0618 // Type or member is obsolete this.logRecord = new LogRecord( this.scopeProvider, DateTime.UtcNow, @@ -66,6 +67,7 @@ public LogScopeBenchmarks() null, null, null); +#pragma warning restore CS0618 // Type or member is obsolete } [Benchmark] diff --git a/test/OpenTelemetry.Tests/Logs/LogRecordSharedPoolTests.cs b/test/OpenTelemetry.Tests/Logs/LogRecordSharedPoolTests.cs new file mode 100644 index 00000000000..8e686870587 --- /dev/null +++ b/test/OpenTelemetry.Tests/Logs/LogRecordSharedPoolTests.cs @@ -0,0 +1,278 @@ +// +// 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. +// + +#nullable enable + +using System; +using System.Collections.Generic; +using System.Threading.Tasks; +using Xunit; + +namespace OpenTelemetry.Logs.Tests +{ + public sealed class LogRecordSharedPoolTests + { + [Fact] + public void ResizeTests() + { + LogRecordPool.Resize(LogRecordSharedPool.DefaultMaxPoolSize); + Assert.NotNull(LogRecordSharedPool.Current); + Assert.Equal(LogRecordSharedPool.DefaultMaxPoolSize, LogRecordSharedPool.Current.Capacity); + + Assert.Throws(() => LogRecordPool.Resize(0)); + + var beforePool = LogRecordSharedPool.Current; + + LogRecordPool.Resize(1); + + Assert.NotNull(LogRecordSharedPool.Current); + Assert.Equal(1, LogRecordSharedPool.Current.Capacity); + Assert.NotEqual(beforePool, LogRecordSharedPool.Current); + } + + [Fact] + public void RentReturnTests() + { + LogRecordPool.Resize(2); + + var pool = LogRecordSharedPool.Current; + + var logRecord1 = pool.Rent(); + Assert.NotNull(logRecord1); + + var logRecord2 = pool.Rent(); + Assert.NotNull(logRecord1); + + pool.Return(logRecord1); + + Assert.Equal(1, pool.Count); + + // Note: This is ignored because logRecord manually created has PoolReferenceCount = int.MaxValue. + LogRecord manualRecord = new(); + Assert.Equal(int.MaxValue, manualRecord.PoolReferenceCount); + pool.Return(manualRecord); + + Assert.Equal(1, pool.Count); + + pool.Return(logRecord2); + + Assert.Equal(2, pool.Count); + + logRecord1 = pool.Rent(); + Assert.NotNull(logRecord1); + Assert.Equal(1, pool.Count); + + logRecord2 = pool.Rent(); + Assert.NotNull(logRecord2); + Assert.Equal(0, pool.Count); + + var logRecord3 = pool.Rent(); + var logRecord4 = pool.Rent(); + Assert.NotNull(logRecord3); + Assert.NotNull(logRecord4); + + pool.Return(logRecord1); + pool.Return(logRecord2); + pool.Return(logRecord3); + pool.Return(logRecord4); // <- Discarded due to pool size of 2 + + Assert.Equal(2, pool.Count); + } + + [Fact] + public void TrackReferenceTests() + { + LogRecordPool.Resize(2); + + var pool = LogRecordSharedPool.Current; + + var logRecord1 = pool.Rent(); + Assert.NotNull(logRecord1); + + Assert.Equal(1, logRecord1.PoolReferenceCount); + + pool.TrackReference(logRecord1); + + Assert.Equal(2, logRecord1.PoolReferenceCount); + + pool.Return(logRecord1); + + Assert.Equal(1, logRecord1.PoolReferenceCount); + + pool.Return(logRecord1); + + Assert.Equal(1, pool.Count); + Assert.Equal(0, logRecord1.PoolReferenceCount); + + pool.Return(logRecord1); + + Assert.Equal(-1, logRecord1.PoolReferenceCount); + Assert.Equal(1, pool.Count); // Record was not returned because PoolReferences was negative. + } + + [Fact] + public void ClearTests() + { + LogRecordPool.Resize(LogRecordSharedPool.DefaultMaxPoolSize); + + var pool = LogRecordSharedPool.Current; + + var logRecord1 = pool.Rent(); + logRecord1.AttributeStorage = new List>(16) + { + new KeyValuePair("key1", "value1"), + new KeyValuePair("key2", "value2"), + }; + logRecord1.BufferedScopes = new List(8) { null, null }; + + pool.Return(logRecord1); + + Assert.Empty(logRecord1.AttributeStorage); + Assert.Equal(16, logRecord1.AttributeStorage.Capacity); + Assert.Empty(logRecord1.BufferedScopes); + Assert.Equal(8, logRecord1.BufferedScopes.Capacity); + + logRecord1 = pool.Rent(); + + Assert.NotNull(logRecord1.AttributeStorage); + Assert.NotNull(logRecord1.BufferedScopes); + + for (int i = 0; i <= LogRecordSharedPool.DefaultMaxNumberOfAttributes; i++) + { + logRecord1.AttributeStorage!.Add(new KeyValuePair("key", "value")); + } + + for (int i = 0; i <= LogRecordSharedPool.DefaultMaxNumberOfScopes; i++) + { + logRecord1.BufferedScopes!.Add(null); + } + + pool.Return(logRecord1); + + Assert.Null(logRecord1.AttributeStorage); + Assert.Null(logRecord1.BufferedScopes); + } + + [Theory] + [InlineData(false)] + [InlineData(true)] + public async Task ExportTest(bool warmup) + { + LogRecordPool.Resize(LogRecordSharedPool.DefaultMaxPoolSize); + + var pool = LogRecordSharedPool.Current; + + if (warmup) + { + for (int i = 0; i < LogRecordSharedPool.DefaultMaxPoolSize; i++) + { + pool.Return(new LogRecord { PoolReferenceCount = 1 }); + } + } + + using BatchLogRecordExportProcessor processor = new(new NoopExporter()); + + List tasks = new(); + + for (int i = 0; i < Environment.ProcessorCount; i++) + { + tasks.Add(Task.Run(async () => + { + Random random = new Random(); + + await Task.Delay(random.Next(100, 150)).ConfigureAwait(false); + + for (int i = 0; i < 1000; i++) + { + var logRecord = pool.Rent(); + + processor.OnEnd(logRecord); + + // This should no-op mostly. + pool.Return(logRecord); + + await Task.Delay(random.Next(0, 20)).ConfigureAwait(false); + } + })); + } + + await Task.WhenAll(tasks).ConfigureAwait(false); + + processor.ForceFlush(); + + if (warmup) + { + Assert.Equal(LogRecordSharedPool.DefaultMaxPoolSize, pool.Count); + } + + Assert.True(pool.Count <= LogRecordSharedPool.DefaultMaxPoolSize); + } + + [Fact] + public async Task DeadlockTest() + { + /* + * The way the LogRecordPool works is it maintains two counters one + * for readers and one for writers. The counters always increment + * and point to an index in the pool array by way of a modulus on + * the size of the array (index = counter % capacity). Under very + * heavy load it is possible for a reader to receive an index and + * then be yielded. When waking up that index may no longer be valid + * if other threads caused the counters to loop around. There is + * protection for this case in the pool, this test verifies it is + * working. + * + * This is considered a corner case. Many threads have to be renting + * & returning logs in a tight loop for this to happen. Real + * applications should be logging based on logic firing which should + * have more natural back-off time. + */ + + LogRecordPool.Resize(LogRecordSharedPool.DefaultMaxPoolSize); + + var pool = LogRecordSharedPool.Current; + + List tasks = new(); + + for (int i = 0; i < Environment.ProcessorCount; i++) + { + tasks.Add(Task.Run(async () => + { + await Task.Delay(2000).ConfigureAwait(false); + + for (int i = 0; i < 100_000; i++) + { + var logRecord = pool.Rent(); + + pool.Return(logRecord); + } + })); + } + + await Task.WhenAll(tasks).ConfigureAwait(false); + + Assert.True(pool.Count <= LogRecordSharedPool.DefaultMaxPoolSize); + } + + private sealed class NoopExporter : BaseExporter + { + public override ExportResult Export(in Batch batch) + { + return ExportResult.Success; + } + } + } +} diff --git a/test/OpenTelemetry.Tests/Logs/LogRecordThreadStaticPoolTests.cs b/test/OpenTelemetry.Tests/Logs/LogRecordThreadStaticPoolTests.cs new file mode 100644 index 00000000000..36b4d6c1371 --- /dev/null +++ b/test/OpenTelemetry.Tests/Logs/LogRecordThreadStaticPoolTests.cs @@ -0,0 +1,90 @@ +// +// 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. +// + +#nullable enable + +using System.Collections.Generic; +using Xunit; + +namespace OpenTelemetry.Logs.Tests +{ + public sealed class LogRecordThreadStaticPoolTests + { + [Fact] + public void RentReturnTests() + { + LogRecordThreadStaticPool.Storage = null; + + var logRecord = LogRecordThreadStaticPool.Instance.Rent(); + Assert.NotNull(logRecord); + Assert.Null(LogRecordThreadStaticPool.Storage); + + LogRecordThreadStaticPool.Instance.Return(logRecord); + Assert.NotNull(LogRecordThreadStaticPool.Storage); + Assert.Equal(logRecord, LogRecordThreadStaticPool.Storage); + + LogRecordThreadStaticPool.Instance.Return(new()); + Assert.NotNull(LogRecordThreadStaticPool.Storage); + Assert.Equal(logRecord, LogRecordThreadStaticPool.Storage); + + LogRecordThreadStaticPool.Storage = null; + + var manual = new LogRecord(); + LogRecordThreadStaticPool.Instance.Return(manual); + Assert.NotNull(LogRecordThreadStaticPool.Storage); + Assert.Equal(manual, LogRecordThreadStaticPool.Storage); + } + + [Fact] + public void ClearTests() + { + var logRecord1 = LogRecordThreadStaticPool.Instance.Rent(); + logRecord1.AttributeStorage = new List>(16) + { + new KeyValuePair("key1", "value1"), + new KeyValuePair("key2", "value2"), + }; + logRecord1.BufferedScopes = new List(8) { null, null }; + + LogRecordThreadStaticPool.Instance.Return(logRecord1); + + Assert.Empty(logRecord1.AttributeStorage); + Assert.Equal(16, logRecord1.AttributeStorage.Capacity); + Assert.Empty(logRecord1.BufferedScopes); + Assert.Equal(8, logRecord1.BufferedScopes.Capacity); + + logRecord1 = LogRecordThreadStaticPool.Instance.Rent(); + + Assert.NotNull(logRecord1.AttributeStorage); + Assert.NotNull(logRecord1.BufferedScopes); + + for (int i = 0; i <= LogRecordSharedPool.DefaultMaxNumberOfAttributes; i++) + { + logRecord1.AttributeStorage!.Add(new KeyValuePair("key", "value")); + } + + for (int i = 0; i <= LogRecordSharedPool.DefaultMaxNumberOfScopes; i++) + { + logRecord1.BufferedScopes!.Add(null); + } + + LogRecordThreadStaticPool.Instance.Return(logRecord1); + + Assert.Null(logRecord1.AttributeStorage); + Assert.Null(logRecord1.BufferedScopes); + } + } +} diff --git a/test/OpenTelemetry.Tests/Logs/OpenTelemetryLoggerProviderTests.cs b/test/OpenTelemetry.Tests/Logs/OpenTelemetryLoggerProviderTests.cs index 330fa4b50e7..6ddd5d7caa4 100644 --- a/test/OpenTelemetry.Tests/Logs/OpenTelemetryLoggerProviderTests.cs +++ b/test/OpenTelemetry.Tests/Logs/OpenTelemetryLoggerProviderTests.cs @@ -85,5 +85,65 @@ public void ForceFlushTest() Assert.Single(exportedItems); } + + [Fact] + public void ThreadStaticPoolUsedByProviderTests() + { + using var provider1 = new OpenTelemetryLoggerProvider(new OpenTelemetryLoggerOptions()); + + Assert.Equal(LogRecordThreadStaticPool.Instance, provider1.LogRecordPool); + + var options = new OpenTelemetryLoggerOptions(); + options.AddProcessor(new SimpleLogRecordExportProcessor(new NoopExporter())); + + using var provider2 = new OpenTelemetryLoggerProvider(options); + + Assert.Equal(LogRecordThreadStaticPool.Instance, provider2.LogRecordPool); + + options.AddProcessor(new SimpleLogRecordExportProcessor(new NoopExporter())); + + using var provider3 = new OpenTelemetryLoggerProvider(options); + + Assert.Equal(LogRecordThreadStaticPool.Instance, provider3.LogRecordPool); + } + + [Fact] + public void SharedPoolUsedByProviderTests() + { + var options = new OpenTelemetryLoggerOptions(); + options.AddProcessor(new BatchLogRecordExportProcessor(new NoopExporter())); + + using var provider1 = new OpenTelemetryLoggerProvider(options); + + Assert.Equal(LogRecordSharedPool.Current, provider1.LogRecordPool); + + options = new OpenTelemetryLoggerOptions(); + options.AddProcessor(new SimpleLogRecordExportProcessor(new NoopExporter())); + options.AddProcessor(new BatchLogRecordExportProcessor(new NoopExporter())); + + using var provider2 = new OpenTelemetryLoggerProvider(options); + + Assert.Equal(LogRecordSharedPool.Current, provider2.LogRecordPool); + + options = new OpenTelemetryLoggerOptions(); + options.AddProcessor(new SimpleLogRecordExportProcessor(new NoopExporter())); + options.AddProcessor(new CompositeProcessor(new BaseProcessor[] + { + new SimpleLogRecordExportProcessor(new NoopExporter()), + new BatchLogRecordExportProcessor(new NoopExporter()), + })); + + using var provider3 = new OpenTelemetryLoggerProvider(options); + + Assert.Equal(LogRecordSharedPool.Current, provider3.LogRecordPool); + } + + private sealed class NoopExporter : BaseExporter + { + public override ExportResult Export(in Batch batch) + { + return ExportResult.Success; + } + } } } From 2cd2d1ab96a9d7aa7ce030e3c86dd37bb9e25da6 Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Sat, 18 Jun 2022 10:44:10 -0700 Subject: [PATCH 02/15] Tweak. --- src/OpenTelemetry/Logs/OpenTelemetryLogger.cs | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs b/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs index 14069725066..d94bae7620b 100644 --- a/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs +++ b/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs @@ -59,7 +59,7 @@ public void Log(LogLevel logLevel, EventId eventId, TState state, Except record.ScopeProvider = provider.IncludeScopes ? this.ScopeProvider : null; record.State = provider.ParseStateValues ? null : state; - record.StateValues = provider.ParseStateValues ? this.ParseState(record, state) : null; + record.StateValues = provider.ParseStateValues ? ParseState(record, state) : null; ref LogRecordData data = ref record.Data; @@ -90,7 +90,7 @@ public bool IsEnabled(LogLevel logLevel) public IDisposable BeginScope(TState state) => this.ScopeProvider?.Push(state) ?? NullScope.Instance; - private IReadOnlyList> ParseState(LogRecord logRecord, TState state) + private static IReadOnlyList> ParseState(LogRecord logRecord, TState state) { if (state is IReadOnlyList> stateList) { From 322aa60d2ec6d8821b57f507ace0345d200d1d8b Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Tue, 21 Jun 2022 13:40:56 -0700 Subject: [PATCH 03/15] Update CHANGELOG. --- src/OpenTelemetry/CHANGELOG.md | 3 +++ 1 file changed, 3 insertions(+) diff --git a/src/OpenTelemetry/CHANGELOG.md b/src/OpenTelemetry/CHANGELOG.md index 3b4cc4c70fe..0e635e9cf8b 100644 --- a/src/OpenTelemetry/CHANGELOG.md +++ b/src/OpenTelemetry/CHANGELOG.md @@ -22,6 +22,9 @@ `set` methods ([#3378](https://github.com/open-telemetry/opentelemetry-dotnet/pull/3378)) +* `LogRecord` instances are now reused to reduce memory pressure + ([#3385](https://github.com/open-telemetry/opentelemetry-dotnet/pull/3385)) + ## 1.3.0 Released 2022-Jun-03 From 8fcbd113cb20f304166d0262eb776d4d880095f0 Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Tue, 21 Jun 2022 13:44:59 -0700 Subject: [PATCH 04/15] Code review. --- .../InMemoryExporterLoggingExtensions.cs | 12 +----------- src/OpenTelemetry/Logs/LogRecord.cs | 13 +++++++++++++ 2 files changed, 14 insertions(+), 11 deletions(-) diff --git a/src/OpenTelemetry.Exporter.InMemory/InMemoryExporterLoggingExtensions.cs b/src/OpenTelemetry.Exporter.InMemory/InMemoryExporterLoggingExtensions.cs index d20d9967a04..6e10e5bd668 100644 --- a/src/OpenTelemetry.Exporter.InMemory/InMemoryExporterLoggingExtensions.cs +++ b/src/OpenTelemetry.Exporter.InMemory/InMemoryExporterLoggingExtensions.cs @@ -42,17 +42,7 @@ private static ExportResult ExportLogRecord(in Batch batch, ICollecti foreach (var log in batch) { - log.Buffer(); - - LogRecord copy = new() - { - Data = log.Data, - State = log.State, - StateValues = log.StateValues == null ? null : new List>(log.StateValues), - BufferedScopes = log.BufferedScopes == null ? null : new List(log.BufferedScopes), - }; - - exportedItems.Add(copy); + exportedItems.Add(log.Copy()); } return ExportResult.Success; diff --git a/src/OpenTelemetry/Logs/LogRecord.cs b/src/OpenTelemetry/Logs/LogRecord.cs index 41c263af1a6..9926a7a8f41 100644 --- a/src/OpenTelemetry/Logs/LogRecord.cs +++ b/src/OpenTelemetry/Logs/LogRecord.cs @@ -225,6 +225,19 @@ internal void Buffer() this.BufferLogScopes(); } + internal LogRecord Copy() + { + this.Buffer(); + + return new() + { + Data = this.Data, + State = this.State, + StateValues = this.StateValues == null ? null : new List>(this.StateValues), + BufferedScopes = this.BufferedScopes == null ? null : new List(this.BufferedScopes), + }; + } + /// /// Buffers the state values attached to the log into a list so that /// they can be safely processed after the log message lifecycle has From e425b217bd637bc08f585ec4507192d0c624cfa6 Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Tue, 21 Jun 2022 14:01:00 -0700 Subject: [PATCH 05/15] Code review. --- .../Logs/BatchLogRecordExportProcessor.cs | 2 +- src/OpenTelemetry/Logs/LogRecord.cs | 20 +++++++++++++++++++ .../Logs/Pool/LogRecordSharedPool.cs | 18 +++++------------ .../Logs/LogRecordSharedPoolTests.cs | 2 +- 4 files changed, 27 insertions(+), 15 deletions(-) diff --git a/src/OpenTelemetry/Logs/BatchLogRecordExportProcessor.cs b/src/OpenTelemetry/Logs/BatchLogRecordExportProcessor.cs index 4b77537dd2c..644f160dbb0 100644 --- a/src/OpenTelemetry/Logs/BatchLogRecordExportProcessor.cs +++ b/src/OpenTelemetry/Logs/BatchLogRecordExportProcessor.cs @@ -59,7 +59,7 @@ public override void OnEnd(LogRecord data) data!.Buffer(); - LogRecordSharedPool.Current.TrackReference(data); + data.AddReference(); if (!this.TryExport(data)) { diff --git a/src/OpenTelemetry/Logs/LogRecord.cs b/src/OpenTelemetry/Logs/LogRecord.cs index 9926a7a8f41..9fb1c136bf1 100644 --- a/src/OpenTelemetry/Logs/LogRecord.cs +++ b/src/OpenTelemetry/Logs/LogRecord.cs @@ -19,6 +19,8 @@ using System; using System.Collections.Generic; using System.Diagnostics; +using System.Runtime.CompilerServices; +using System.Threading; using Microsoft.Extensions.Logging; using OpenTelemetry.Internal; @@ -219,6 +221,24 @@ internal ref LogRecordData GetDataRef() return ref this.Data; } + [MethodImpl(MethodImplOptions.AggressiveInlining)] + internal void ResetReferenceCount() + { + this.PoolReferenceCount = 1; + } + + [MethodImpl(MethodImplOptions.AggressiveInlining)] + internal void AddReference() + { + Interlocked.Increment(ref this.PoolReferenceCount); + } + + [MethodImpl(MethodImplOptions.AggressiveInlining)] + internal int RemoveReference() + { + return Interlocked.Decrement(ref this.PoolReferenceCount); + } + internal void Buffer() { this.BufferLogStateValues(); diff --git a/src/OpenTelemetry/Logs/Pool/LogRecordSharedPool.cs b/src/OpenTelemetry/Logs/Pool/LogRecordSharedPool.cs index 14285b8aab4..c9fd04a3bf7 100644 --- a/src/OpenTelemetry/Logs/Pool/LogRecordSharedPool.cs +++ b/src/OpenTelemetry/Logs/Pool/LogRecordSharedPool.cs @@ -17,7 +17,6 @@ #nullable enable using System.Diagnostics.CodeAnalysis; -using System.Runtime.CompilerServices; using System.Threading; namespace OpenTelemetry.Logs @@ -63,20 +62,19 @@ public LogRecord Rent() continue; } - logRecord.PoolReferenceCount = 1; + logRecord.ResetReferenceCount(); return logRecord; } } - return new LogRecord() - { - PoolReferenceCount = 1, - }; + var newLogRecord = new LogRecord(); + newLogRecord.ResetReferenceCount(); + return newLogRecord; } public void Return(LogRecord logRecord) { - if (Interlocked.Decrement(ref logRecord.PoolReferenceCount) != 0) + if (logRecord.RemoveReference() != 0) { return; } @@ -106,12 +104,6 @@ public void Return(LogRecord logRecord) } } - [MethodImpl(MethodImplOptions.AggressiveInlining)] - public void TrackReference(LogRecord logRecord) - { - Interlocked.Increment(ref logRecord.PoolReferenceCount); - } - internal static void Clear(LogRecord logRecord) { var attributeStorage = logRecord.AttributeStorage; diff --git a/test/OpenTelemetry.Tests/Logs/LogRecordSharedPoolTests.cs b/test/OpenTelemetry.Tests/Logs/LogRecordSharedPoolTests.cs index 8e686870587..4e4d2eb4679 100644 --- a/test/OpenTelemetry.Tests/Logs/LogRecordSharedPoolTests.cs +++ b/test/OpenTelemetry.Tests/Logs/LogRecordSharedPoolTests.cs @@ -104,7 +104,7 @@ public void TrackReferenceTests() Assert.Equal(1, logRecord1.PoolReferenceCount); - pool.TrackReference(logRecord1); + logRecord1.AddReference(); Assert.Equal(2, logRecord1.PoolReferenceCount); From 2b7cbce95c1aa89b412bbd5291a70f59989f799e Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Wed, 22 Jun 2022 15:29:55 -0700 Subject: [PATCH 06/15] Code review. --- src/OpenTelemetry/Logs/LogRecord.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/OpenTelemetry/Logs/LogRecord.cs b/src/OpenTelemetry/Logs/LogRecord.cs index 9fb1c136bf1..e4fbfd9ae92 100644 --- a/src/OpenTelemetry/Logs/LogRecord.cs +++ b/src/OpenTelemetry/Logs/LogRecord.cs @@ -287,7 +287,7 @@ private void BufferLogScopes() return; } - List scopes = this.BufferedScopes ??= new List(16); + List scopes = this.BufferedScopes ??= new List(LogRecordSharedPool.DefaultMaxNumberOfScopes); this.ScopeProvider.ForEachScope(AddScopeToBufferedList, scopes); From cbcbf1addf4322493c375de8d6d3923082b949a9 Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Wed, 22 Jun 2022 15:41:10 -0700 Subject: [PATCH 07/15] Code review. --- src/OpenTelemetry/Logs/LogRecord.cs | 2 +- src/OpenTelemetry/Logs/Pool/LogRecordPool.cs | 38 ++++++++++++++++++ .../Logs/Pool/LogRecordSharedPool.cs | 39 +------------------ .../Logs/Pool/LogRecordThreadStaticPool.cs | 2 +- .../Logs/LogRecordSharedPoolTests.cs | 4 +- .../Logs/LogRecordThreadStaticPoolTests.cs | 4 +- 6 files changed, 45 insertions(+), 44 deletions(-) diff --git a/src/OpenTelemetry/Logs/LogRecord.cs b/src/OpenTelemetry/Logs/LogRecord.cs index e4fbfd9ae92..360fe8acf80 100644 --- a/src/OpenTelemetry/Logs/LogRecord.cs +++ b/src/OpenTelemetry/Logs/LogRecord.cs @@ -287,7 +287,7 @@ private void BufferLogScopes() return; } - List scopes = this.BufferedScopes ??= new List(LogRecordSharedPool.DefaultMaxNumberOfScopes); + List scopes = this.BufferedScopes ??= new List(LogRecordPool.DefaultMaxNumberOfScopes); this.ScopeProvider.ForEachScope(AddScopeToBufferedList, scopes); diff --git a/src/OpenTelemetry/Logs/Pool/LogRecordPool.cs b/src/OpenTelemetry/Logs/Pool/LogRecordPool.cs index c6a337b3b0a..d8669588778 100644 --- a/src/OpenTelemetry/Logs/Pool/LogRecordPool.cs +++ b/src/OpenTelemetry/Logs/Pool/LogRecordPool.cs @@ -25,6 +25,9 @@ namespace OpenTelemetry.Logs /// public static class LogRecordPool { + internal const int DefaultMaxNumberOfAttributes = 64; + internal const int DefaultMaxNumberOfScopes = 16; + /// /// Resize the pool. /// @@ -35,5 +38,40 @@ public static void Resize(int capacity) LogRecordSharedPool.Current = new(capacity); } + + internal static void Clear(LogRecord logRecord) + { + var attributeStorage = logRecord.AttributeStorage; + if (attributeStorage != null) + { + if (attributeStorage.Count > DefaultMaxNumberOfAttributes) + { + // Don't allow the pool to grow unconstained. + logRecord.AttributeStorage = null; + } + else + { + /* List.Clear sets the size to 0 but it maintains the + underlying array. */ + attributeStorage.Clear(); + } + } + + var bufferedScopes = logRecord.BufferedScopes; + if (bufferedScopes != null) + { + if (bufferedScopes.Count > DefaultMaxNumberOfScopes) + { + // Don't allow the pool to grow unconstained. + logRecord.BufferedScopes = null; + } + else + { + /* List.Clear sets the size to 0 but it maintains the + underlying array. */ + bufferedScopes.Clear(); + } + } + } } } diff --git a/src/OpenTelemetry/Logs/Pool/LogRecordSharedPool.cs b/src/OpenTelemetry/Logs/Pool/LogRecordSharedPool.cs index c9fd04a3bf7..7c7ef18d1f3 100644 --- a/src/OpenTelemetry/Logs/Pool/LogRecordSharedPool.cs +++ b/src/OpenTelemetry/Logs/Pool/LogRecordSharedPool.cs @@ -24,8 +24,6 @@ namespace OpenTelemetry.Logs internal sealed class LogRecordSharedPool : ILogRecordPool { internal const int DefaultMaxPoolSize = 2048; - internal const int DefaultMaxNumberOfAttributes = 64; - internal const int DefaultMaxNumberOfScopes = 16; internal static LogRecordSharedPool Current = new(DefaultMaxPoolSize); @@ -79,7 +77,7 @@ public void Return(LogRecord logRecord) return; } - Clear(logRecord); + LogRecordPool.Clear(logRecord); while (true) { @@ -104,41 +102,6 @@ public void Return(LogRecord logRecord) } } - internal static void Clear(LogRecord logRecord) - { - var attributeStorage = logRecord.AttributeStorage; - if (attributeStorage != null) - { - if (attributeStorage.Count > DefaultMaxNumberOfAttributes) - { - // Don't allow the pool to grow unconstained. - logRecord.AttributeStorage = null; - } - else - { - /* List.Clear sets the size to 0 but it maintains the - underlying array. */ - attributeStorage.Clear(); - } - } - - var bufferedScopes = logRecord.BufferedScopes; - if (bufferedScopes != null) - { - if (bufferedScopes.Count > DefaultMaxNumberOfScopes) - { - // Don't allow the pool to grow unconstained. - logRecord.BufferedScopes = null; - } - else - { - /* List.Clear sets the size to 0 but it maintains the - underlying array. */ - bufferedScopes.Clear(); - } - } - } - private bool TryRentCoreRare(long rentSnapshot, [NotNullWhen(true)] out LogRecord? logRecord) { SpinWait wait = default; diff --git a/src/OpenTelemetry/Logs/Pool/LogRecordThreadStaticPool.cs b/src/OpenTelemetry/Logs/Pool/LogRecordThreadStaticPool.cs index 90a2c3759ae..2cc91809b25 100644 --- a/src/OpenTelemetry/Logs/Pool/LogRecordThreadStaticPool.cs +++ b/src/OpenTelemetry/Logs/Pool/LogRecordThreadStaticPool.cs @@ -47,7 +47,7 @@ public void Return(LogRecord logRecord) { if (Storage == null) { - LogRecordSharedPool.Clear(logRecord); + LogRecordPool.Clear(logRecord); Storage = logRecord; } } diff --git a/test/OpenTelemetry.Tests/Logs/LogRecordSharedPoolTests.cs b/test/OpenTelemetry.Tests/Logs/LogRecordSharedPoolTests.cs index 4e4d2eb4679..649c314df8f 100644 --- a/test/OpenTelemetry.Tests/Logs/LogRecordSharedPoolTests.cs +++ b/test/OpenTelemetry.Tests/Logs/LogRecordSharedPoolTests.cs @@ -150,12 +150,12 @@ public void ClearTests() Assert.NotNull(logRecord1.AttributeStorage); Assert.NotNull(logRecord1.BufferedScopes); - for (int i = 0; i <= LogRecordSharedPool.DefaultMaxNumberOfAttributes; i++) + for (int i = 0; i <= LogRecordPool.DefaultMaxNumberOfAttributes; i++) { logRecord1.AttributeStorage!.Add(new KeyValuePair("key", "value")); } - for (int i = 0; i <= LogRecordSharedPool.DefaultMaxNumberOfScopes; i++) + for (int i = 0; i <= LogRecordPool.DefaultMaxNumberOfScopes; i++) { logRecord1.BufferedScopes!.Add(null); } diff --git a/test/OpenTelemetry.Tests/Logs/LogRecordThreadStaticPoolTests.cs b/test/OpenTelemetry.Tests/Logs/LogRecordThreadStaticPoolTests.cs index 36b4d6c1371..fc924c059a3 100644 --- a/test/OpenTelemetry.Tests/Logs/LogRecordThreadStaticPoolTests.cs +++ b/test/OpenTelemetry.Tests/Logs/LogRecordThreadStaticPoolTests.cs @@ -71,12 +71,12 @@ public void ClearTests() Assert.NotNull(logRecord1.AttributeStorage); Assert.NotNull(logRecord1.BufferedScopes); - for (int i = 0; i <= LogRecordSharedPool.DefaultMaxNumberOfAttributes; i++) + for (int i = 0; i <= LogRecordPool.DefaultMaxNumberOfAttributes; i++) { logRecord1.AttributeStorage!.Add(new KeyValuePair("key", "value")); } - for (int i = 0; i <= LogRecordSharedPool.DefaultMaxNumberOfScopes; i++) + for (int i = 0; i <= LogRecordPool.DefaultMaxNumberOfScopes; i++) { logRecord1.BufferedScopes!.Add(null); } From 56befa103e1a2994f3c3517a7d047b1519d46b8b Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Wed, 22 Jun 2022 15:49:40 -0700 Subject: [PATCH 08/15] Nit. --- src/OpenTelemetry/Logs/Pool/LogRecordPool.cs | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/src/OpenTelemetry/Logs/Pool/LogRecordPool.cs b/src/OpenTelemetry/Logs/Pool/LogRecordPool.cs index d8669588778..52acfa67a90 100644 --- a/src/OpenTelemetry/Logs/Pool/LogRecordPool.cs +++ b/src/OpenTelemetry/Logs/Pool/LogRecordPool.cs @@ -51,8 +51,8 @@ internal static void Clear(LogRecord logRecord) } else { - /* List.Clear sets the size to 0 but it maintains the - underlying array. */ + /* List.Clear sets the count/size to 0 but it maintains the + underlying array (capacity). */ attributeStorage.Clear(); } } @@ -67,8 +67,8 @@ underlying array. */ } else { - /* List.Clear sets the size to 0 but it maintains the - underlying array. */ + /* List.Clear sets the count/size to 0 but it maintains the + underlying array (capacity). */ bufferedScopes.Clear(); } } From b4f95b5b62462f10f1a7a1fffc8863db2d8677eb Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Thu, 23 Jun 2022 13:40:15 -0700 Subject: [PATCH 09/15] Improvement. --- src/OpenTelemetry/Batch.cs | 25 ++++++++++++++----------- 1 file changed, 14 insertions(+), 11 deletions(-) diff --git a/src/OpenTelemetry/Batch.cs b/src/OpenTelemetry/Batch.cs index 9f04f9ec567..537a19a6c75 100644 --- a/src/OpenTelemetry/Batch.cs +++ b/src/OpenTelemetry/Batch.cs @@ -147,24 +147,27 @@ public struct Enumerator : IEnumerator private static readonly BatchEnumeratorMoveNextFunc MoveNextCircularBufferLogRecord = (ref Enumerator enumerator) => { - var circularBuffer = enumerator.circularBuffer; - - var currentItem = enumerator.Current; - if (currentItem != null) + // Note: This type check here is to give the JIT a hint it can + // remove all of this code when T != LogRecord + if (typeof(T) == typeof(LogRecord)) { - if (typeof(T) == typeof(LogRecord)) + var circularBuffer = enumerator.circularBuffer; + + var currentItem = enumerator.Current; + if (currentItem != null) { LogRecordSharedPool.Current.Return((LogRecord)(object)currentItem); } - } - if (circularBuffer!.RemovedCount < enumerator.targetCount) - { - enumerator.current = circularBuffer.Read(); - return true; + if (circularBuffer!.RemovedCount < enumerator.targetCount) + { + enumerator.current = circularBuffer.Read(); + return true; + } + + enumerator.current = null; } - enumerator.current = null; return false; }; From da49e68c1f5d4f07d25d4e56b2c1c576120b41f2 Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Thu, 23 Jun 2022 14:45:18 -0700 Subject: [PATCH 10/15] Code review. --- src/OpenTelemetry/Logs/OpenTelemetryLogger.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs b/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs index d94bae7620b..052e9cfa767 100644 --- a/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs +++ b/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs @@ -111,7 +111,7 @@ public bool IsEnabled(LogLevel logLevel) } else { - var attributeStorage = logRecord.AttributeStorage ??= new List>(8); + var attributeStorage = logRecord.AttributeStorage ??= new List>(LogRecordPool.DefaultMaxNumberOfAttributes); attributeStorage.Add(new KeyValuePair(string.Empty, state)); return attributeStorage; } From 5b4d2853570c201d56eee1bcad097220edf67566 Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Mon, 27 Jun 2022 10:22:08 -0700 Subject: [PATCH 11/15] Make resize internal. --- .../.publicApi/net462/PublicAPI.Unshipped.txt | 2 -- .../.publicApi/net6.0/PublicAPI.Unshipped.txt | 2 -- .../netstandard2.0/PublicAPI.Unshipped.txt | 2 -- .../netstandard2.1/PublicAPI.Unshipped.txt | 2 -- src/OpenTelemetry/Logs/LogRecord.cs | 2 +- src/OpenTelemetry/Logs/OpenTelemetryLogger.cs | 2 +- ...ogRecordPool.cs => LogRecordPoolHelper.cs} | 26 ++++--------------- .../Logs/Pool/LogRecordSharedPool.cs | 22 +++++++++++----- .../Logs/Pool/LogRecordThreadStaticPool.cs | 4 +-- .../Logs/LogRecordSharedPoolTests.cs | 20 +++++++------- .../Logs/LogRecordThreadStaticPoolTests.cs | 4 +-- 11 files changed, 37 insertions(+), 51 deletions(-) rename src/OpenTelemetry/Logs/Pool/{LogRecordPool.cs => LogRecordPoolHelper.cs} (70%) diff --git a/src/OpenTelemetry/.publicApi/net462/PublicAPI.Unshipped.txt b/src/OpenTelemetry/.publicApi/net462/PublicAPI.Unshipped.txt index a0be84b92af..1ed0d793f9f 100644 --- a/src/OpenTelemetry/.publicApi/net462/PublicAPI.Unshipped.txt +++ b/src/OpenTelemetry/.publicApi/net462/PublicAPI.Unshipped.txt @@ -7,8 +7,6 @@ OpenTelemetry.Logs.LogRecord.Timestamp.set -> void OpenTelemetry.Logs.LogRecord.TraceFlags.set -> void OpenTelemetry.Logs.LogRecord.TraceId.set -> void OpenTelemetry.Logs.LogRecord.TraceState.set -> void -OpenTelemetry.Logs.LogRecordPool OpenTelemetry.Logs.OpenTelemetryLoggerProvider.ForceFlush(int timeoutMilliseconds = -1) -> bool OpenTelemetry.Logs.OpenTelemetryLoggerProvider.OpenTelemetryLoggerProvider() -> void OpenTelemetry.Logs.OpenTelemetryLoggerProvider.OpenTelemetryLoggerProvider(System.Action! configure) -> void -static OpenTelemetry.Logs.LogRecordPool.Resize(int capacity) -> void \ No newline at end of file diff --git a/src/OpenTelemetry/.publicApi/net6.0/PublicAPI.Unshipped.txt b/src/OpenTelemetry/.publicApi/net6.0/PublicAPI.Unshipped.txt index a0be84b92af..1ed0d793f9f 100644 --- a/src/OpenTelemetry/.publicApi/net6.0/PublicAPI.Unshipped.txt +++ b/src/OpenTelemetry/.publicApi/net6.0/PublicAPI.Unshipped.txt @@ -7,8 +7,6 @@ OpenTelemetry.Logs.LogRecord.Timestamp.set -> void OpenTelemetry.Logs.LogRecord.TraceFlags.set -> void OpenTelemetry.Logs.LogRecord.TraceId.set -> void OpenTelemetry.Logs.LogRecord.TraceState.set -> void -OpenTelemetry.Logs.LogRecordPool OpenTelemetry.Logs.OpenTelemetryLoggerProvider.ForceFlush(int timeoutMilliseconds = -1) -> bool OpenTelemetry.Logs.OpenTelemetryLoggerProvider.OpenTelemetryLoggerProvider() -> void OpenTelemetry.Logs.OpenTelemetryLoggerProvider.OpenTelemetryLoggerProvider(System.Action! configure) -> void -static OpenTelemetry.Logs.LogRecordPool.Resize(int capacity) -> void \ No newline at end of file diff --git a/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt b/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt index a0be84b92af..1ed0d793f9f 100644 --- a/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt +++ b/src/OpenTelemetry/.publicApi/netstandard2.0/PublicAPI.Unshipped.txt @@ -7,8 +7,6 @@ OpenTelemetry.Logs.LogRecord.Timestamp.set -> void OpenTelemetry.Logs.LogRecord.TraceFlags.set -> void OpenTelemetry.Logs.LogRecord.TraceId.set -> void OpenTelemetry.Logs.LogRecord.TraceState.set -> void -OpenTelemetry.Logs.LogRecordPool OpenTelemetry.Logs.OpenTelemetryLoggerProvider.ForceFlush(int timeoutMilliseconds = -1) -> bool OpenTelemetry.Logs.OpenTelemetryLoggerProvider.OpenTelemetryLoggerProvider() -> void OpenTelemetry.Logs.OpenTelemetryLoggerProvider.OpenTelemetryLoggerProvider(System.Action! configure) -> void -static OpenTelemetry.Logs.LogRecordPool.Resize(int capacity) -> void \ No newline at end of file diff --git a/src/OpenTelemetry/.publicApi/netstandard2.1/PublicAPI.Unshipped.txt b/src/OpenTelemetry/.publicApi/netstandard2.1/PublicAPI.Unshipped.txt index a0be84b92af..1ed0d793f9f 100644 --- a/src/OpenTelemetry/.publicApi/netstandard2.1/PublicAPI.Unshipped.txt +++ b/src/OpenTelemetry/.publicApi/netstandard2.1/PublicAPI.Unshipped.txt @@ -7,8 +7,6 @@ OpenTelemetry.Logs.LogRecord.Timestamp.set -> void OpenTelemetry.Logs.LogRecord.TraceFlags.set -> void OpenTelemetry.Logs.LogRecord.TraceId.set -> void OpenTelemetry.Logs.LogRecord.TraceState.set -> void -OpenTelemetry.Logs.LogRecordPool OpenTelemetry.Logs.OpenTelemetryLoggerProvider.ForceFlush(int timeoutMilliseconds = -1) -> bool OpenTelemetry.Logs.OpenTelemetryLoggerProvider.OpenTelemetryLoggerProvider() -> void OpenTelemetry.Logs.OpenTelemetryLoggerProvider.OpenTelemetryLoggerProvider(System.Action! configure) -> void -static OpenTelemetry.Logs.LogRecordPool.Resize(int capacity) -> void \ No newline at end of file diff --git a/src/OpenTelemetry/Logs/LogRecord.cs b/src/OpenTelemetry/Logs/LogRecord.cs index 360fe8acf80..f0695050689 100644 --- a/src/OpenTelemetry/Logs/LogRecord.cs +++ b/src/OpenTelemetry/Logs/LogRecord.cs @@ -287,7 +287,7 @@ private void BufferLogScopes() return; } - List scopes = this.BufferedScopes ??= new List(LogRecordPool.DefaultMaxNumberOfScopes); + List scopes = this.BufferedScopes ??= new List(LogRecordPoolHelper.DefaultMaxNumberOfScopes); this.ScopeProvider.ForEachScope(AddScopeToBufferedList, scopes); diff --git a/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs b/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs index 052e9cfa767..88b799434dd 100644 --- a/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs +++ b/src/OpenTelemetry/Logs/OpenTelemetryLogger.cs @@ -111,7 +111,7 @@ public bool IsEnabled(LogLevel logLevel) } else { - var attributeStorage = logRecord.AttributeStorage ??= new List>(LogRecordPool.DefaultMaxNumberOfAttributes); + var attributeStorage = logRecord.AttributeStorage ??= new List>(LogRecordPoolHelper.DefaultMaxNumberOfAttributes); attributeStorage.Add(new KeyValuePair(string.Empty, state)); return attributeStorage; } diff --git a/src/OpenTelemetry/Logs/Pool/LogRecordPool.cs b/src/OpenTelemetry/Logs/Pool/LogRecordPoolHelper.cs similarity index 70% rename from src/OpenTelemetry/Logs/Pool/LogRecordPool.cs rename to src/OpenTelemetry/Logs/Pool/LogRecordPoolHelper.cs index 52acfa67a90..b63028b920b 100644 --- a/src/OpenTelemetry/Logs/Pool/LogRecordPool.cs +++ b/src/OpenTelemetry/Logs/Pool/LogRecordPoolHelper.cs @@ -1,4 +1,4 @@ -// +// // Copyright The OpenTelemetry Authors // // Licensed under the Apache License, Version 2.0 (the "License"); @@ -16,30 +16,14 @@ #nullable enable -using OpenTelemetry.Internal; - namespace OpenTelemetry.Logs { - /// - /// Manages a pool of instances. - /// - public static class LogRecordPool + internal static class LogRecordPoolHelper { - internal const int DefaultMaxNumberOfAttributes = 64; - internal const int DefaultMaxNumberOfScopes = 16; - - /// - /// Resize the pool. - /// - /// The maximum number of s to store in the pool. - public static void Resize(int capacity) - { - Guard.ThrowIfOutOfRange(capacity, min: 1); - - LogRecordSharedPool.Current = new(capacity); - } + public const int DefaultMaxNumberOfAttributes = 64; + public const int DefaultMaxNumberOfScopes = 16; - internal static void Clear(LogRecord logRecord) + public static void Clear(LogRecord logRecord) { var attributeStorage = logRecord.AttributeStorage; if (attributeStorage != null) diff --git a/src/OpenTelemetry/Logs/Pool/LogRecordSharedPool.cs b/src/OpenTelemetry/Logs/Pool/LogRecordSharedPool.cs index 7c7ef18d1f3..b1b15d619d1 100644 --- a/src/OpenTelemetry/Logs/Pool/LogRecordSharedPool.cs +++ b/src/OpenTelemetry/Logs/Pool/LogRecordSharedPool.cs @@ -18,27 +18,37 @@ using System.Diagnostics.CodeAnalysis; using System.Threading; +using OpenTelemetry.Internal; namespace OpenTelemetry.Logs { internal sealed class LogRecordSharedPool : ILogRecordPool { - internal const int DefaultMaxPoolSize = 2048; + public const int DefaultMaxPoolSize = 2048; - internal static LogRecordSharedPool Current = new(DefaultMaxPoolSize); + public static LogRecordSharedPool Current = new(DefaultMaxPoolSize); - internal readonly int Capacity; + public readonly int Capacity; private readonly LogRecord?[] pool; private long rentIndex; private long returnIndex; - internal LogRecordSharedPool(int capacity) + public LogRecordSharedPool(int capacity) { this.Capacity = capacity; this.pool = new LogRecord?[capacity]; } - internal int Count => (int)(Volatile.Read(ref this.returnIndex) - Volatile.Read(ref this.rentIndex)); + public int Count => (int)(Volatile.Read(ref this.returnIndex) - Volatile.Read(ref this.rentIndex)); + + // Note: It might make sense to expose this (somehow) in the future. + // Ideal config is shared pool capacity == max batch size. + public static void Resize(int capacity) + { + Guard.ThrowIfOutOfRange(capacity, min: 1); + + Current = new(capacity); + } public LogRecord Rent() { @@ -77,7 +87,7 @@ public void Return(LogRecord logRecord) return; } - LogRecordPool.Clear(logRecord); + LogRecordPoolHelper.Clear(logRecord); while (true) { diff --git a/src/OpenTelemetry/Logs/Pool/LogRecordThreadStaticPool.cs b/src/OpenTelemetry/Logs/Pool/LogRecordThreadStaticPool.cs index 2cc91809b25..28b417f130d 100644 --- a/src/OpenTelemetry/Logs/Pool/LogRecordThreadStaticPool.cs +++ b/src/OpenTelemetry/Logs/Pool/LogRecordThreadStaticPool.cs @@ -23,7 +23,7 @@ namespace OpenTelemetry.Logs internal sealed class LogRecordThreadStaticPool : ILogRecordPool { [ThreadStatic] - internal static LogRecord? Storage; + public static LogRecord? Storage; private LogRecordThreadStaticPool() { @@ -47,7 +47,7 @@ public void Return(LogRecord logRecord) { if (Storage == null) { - LogRecordPool.Clear(logRecord); + LogRecordPoolHelper.Clear(logRecord); Storage = logRecord; } } diff --git a/test/OpenTelemetry.Tests/Logs/LogRecordSharedPoolTests.cs b/test/OpenTelemetry.Tests/Logs/LogRecordSharedPoolTests.cs index 649c314df8f..0a6d7d37baf 100644 --- a/test/OpenTelemetry.Tests/Logs/LogRecordSharedPoolTests.cs +++ b/test/OpenTelemetry.Tests/Logs/LogRecordSharedPoolTests.cs @@ -28,15 +28,15 @@ public sealed class LogRecordSharedPoolTests [Fact] public void ResizeTests() { - LogRecordPool.Resize(LogRecordSharedPool.DefaultMaxPoolSize); + LogRecordSharedPool.Resize(LogRecordSharedPool.DefaultMaxPoolSize); Assert.NotNull(LogRecordSharedPool.Current); Assert.Equal(LogRecordSharedPool.DefaultMaxPoolSize, LogRecordSharedPool.Current.Capacity); - Assert.Throws(() => LogRecordPool.Resize(0)); + Assert.Throws(() => LogRecordSharedPool.Resize(0)); var beforePool = LogRecordSharedPool.Current; - LogRecordPool.Resize(1); + LogRecordSharedPool.Resize(1); Assert.NotNull(LogRecordSharedPool.Current); Assert.Equal(1, LogRecordSharedPool.Current.Capacity); @@ -46,7 +46,7 @@ public void ResizeTests() [Fact] public void RentReturnTests() { - LogRecordPool.Resize(2); + LogRecordSharedPool.Resize(2); var pool = LogRecordSharedPool.Current; @@ -95,7 +95,7 @@ public void RentReturnTests() [Fact] public void TrackReferenceTests() { - LogRecordPool.Resize(2); + LogRecordSharedPool.Resize(2); var pool = LogRecordSharedPool.Current; @@ -126,7 +126,7 @@ public void TrackReferenceTests() [Fact] public void ClearTests() { - LogRecordPool.Resize(LogRecordSharedPool.DefaultMaxPoolSize); + LogRecordSharedPool.Resize(LogRecordSharedPool.DefaultMaxPoolSize); var pool = LogRecordSharedPool.Current; @@ -150,12 +150,12 @@ public void ClearTests() Assert.NotNull(logRecord1.AttributeStorage); Assert.NotNull(logRecord1.BufferedScopes); - for (int i = 0; i <= LogRecordPool.DefaultMaxNumberOfAttributes; i++) + for (int i = 0; i <= LogRecordPoolHelper.DefaultMaxNumberOfAttributes; i++) { logRecord1.AttributeStorage!.Add(new KeyValuePair("key", "value")); } - for (int i = 0; i <= LogRecordPool.DefaultMaxNumberOfScopes; i++) + for (int i = 0; i <= LogRecordPoolHelper.DefaultMaxNumberOfScopes; i++) { logRecord1.BufferedScopes!.Add(null); } @@ -171,7 +171,7 @@ public void ClearTests() [InlineData(true)] public async Task ExportTest(bool warmup) { - LogRecordPool.Resize(LogRecordSharedPool.DefaultMaxPoolSize); + LogRecordSharedPool.Resize(LogRecordSharedPool.DefaultMaxPoolSize); var pool = LogRecordSharedPool.Current; @@ -241,7 +241,7 @@ public async Task DeadlockTest() * have more natural back-off time. */ - LogRecordPool.Resize(LogRecordSharedPool.DefaultMaxPoolSize); + LogRecordSharedPool.Resize(LogRecordSharedPool.DefaultMaxPoolSize); var pool = LogRecordSharedPool.Current; diff --git a/test/OpenTelemetry.Tests/Logs/LogRecordThreadStaticPoolTests.cs b/test/OpenTelemetry.Tests/Logs/LogRecordThreadStaticPoolTests.cs index fc924c059a3..93a334cc567 100644 --- a/test/OpenTelemetry.Tests/Logs/LogRecordThreadStaticPoolTests.cs +++ b/test/OpenTelemetry.Tests/Logs/LogRecordThreadStaticPoolTests.cs @@ -71,12 +71,12 @@ public void ClearTests() Assert.NotNull(logRecord1.AttributeStorage); Assert.NotNull(logRecord1.BufferedScopes); - for (int i = 0; i <= LogRecordPool.DefaultMaxNumberOfAttributes; i++) + for (int i = 0; i <= LogRecordPoolHelper.DefaultMaxNumberOfAttributes; i++) { logRecord1.AttributeStorage!.Add(new KeyValuePair("key", "value")); } - for (int i = 0; i <= LogRecordPool.DefaultMaxNumberOfScopes; i++) + for (int i = 0; i <= LogRecordPoolHelper.DefaultMaxNumberOfScopes; i++) { logRecord1.BufferedScopes!.Add(null); } From 9b5133c7d0f446be5c8e20e83118e3d4f8d71b0a Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Mon, 27 Jun 2022 10:57:06 -0700 Subject: [PATCH 12/15] Add more details to comments about write race. --- src/OpenTelemetry/Logs/Pool/LogRecordSharedPool.cs | 7 ++++++- 1 file changed, 6 insertions(+), 1 deletion(-) diff --git a/src/OpenTelemetry/Logs/Pool/LogRecordSharedPool.cs b/src/OpenTelemetry/Logs/Pool/LogRecordSharedPool.cs index b1b15d619d1..57234057ae8 100644 --- a/src/OpenTelemetry/Logs/Pool/LogRecordSharedPool.cs +++ b/src/OpenTelemetry/Logs/Pool/LogRecordSharedPool.cs @@ -105,7 +105,12 @@ public void Return(LogRecord logRecord) // for two threads to write to the same index. In that case // only one of the logRecords will make it back into the // pool. Anything lost in the race will collected by the GC - // and the pool will issue new instances as needed + // and the pool will issue new instances as needed. This + // could be abated by an Interlocked.CompareExchange here + // but for the general use case of an exporter returning + // records one-by-one, better to keep this fast and not pay + // for Interlocked.CompareExchange. The race is more + // theoretical. this.pool[returnSnapshot % this.Capacity] = logRecord; return; } From 6b6a6bae85f2270e366bc634817984a892157fcc Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Tue, 28 Jun 2022 12:46:04 -0700 Subject: [PATCH 13/15] State buffering tests. --- src/OpenTelemetry/Logs/LogRecord.cs | 4 +- .../BatchLogRecordExportProcessorTests.cs | 107 ++++++++++++++++++ .../OpenTelemetry.Tests/Logs/LogRecordTest.cs | 79 ++++++++++++- 3 files changed, 187 insertions(+), 3 deletions(-) create mode 100644 test/OpenTelemetry.Tests/Logs/BatchLogRecordExportProcessorTests.cs diff --git a/src/OpenTelemetry/Logs/LogRecord.cs b/src/OpenTelemetry/Logs/LogRecord.cs index f0695050689..fda465c9ae8 100644 --- a/src/OpenTelemetry/Logs/LogRecord.cs +++ b/src/OpenTelemetry/Logs/LogRecord.cs @@ -247,7 +247,9 @@ internal void Buffer() internal LogRecord Copy() { - this.Buffer(); + // Note: We only buffer scopes here because state values are copied + // directly below. + this.BufferLogScopes(); return new() { diff --git a/test/OpenTelemetry.Tests/Logs/BatchLogRecordExportProcessorTests.cs b/test/OpenTelemetry.Tests/Logs/BatchLogRecordExportProcessorTests.cs new file mode 100644 index 00000000000..4a9e6ed3fd5 --- /dev/null +++ b/test/OpenTelemetry.Tests/Logs/BatchLogRecordExportProcessorTests.cs @@ -0,0 +1,107 @@ +// +// 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 !NETFRAMEWORK +using System; +using System.Collections.Generic; +using Microsoft.Extensions.Logging; +using OpenTelemetry.Exporter; +using Xunit; + +namespace OpenTelemetry.Logs.Tests +{ + public sealed class BatchLogRecordExportProcessorTests + { + [Fact] + public void StateValuesAndScopeBufferingTest() + { + var scopeProvider = new LoggerExternalScopeProvider(); + + List exportedItems = new(); + + using var exporter = new BatchLogRecordExportProcessor( + new InMemoryExporter(exportedItems)); + + using var scope = scopeProvider.Push(exportedItems); + + var logRecord = new LogRecord(); + + var state = new LogRecordTest.DisposingState("Hello world"); + + logRecord.ScopeProvider = scopeProvider; + logRecord.StateValues = state; + + exporter.OnEnd(logRecord); + + state.Dispose(); + + Assert.Empty(exportedItems); + + Assert.Null(logRecord.ScopeProvider); + Assert.False(ReferenceEquals(state, logRecord.StateValues)); + Assert.NotNull(logRecord.AttributeStorage); + Assert.NotNull(logRecord.BufferedScopes); + + KeyValuePair actualState = logRecord.StateValues[0]; + + Assert.Same("Value", actualState.Key); + Assert.Same("Hello world", actualState.Value); + + bool foundScope = false; + + logRecord.ForEachScope( + (s, o) => + { + foundScope = ReferenceEquals(s.Scope, exportedItems); + }, + null); + + Assert.True(foundScope); + } + + [Fact] + public void StateBufferingTest() + { + // LogRecord.State is never inspected or buffered. Accessing it + // after OnEnd may throw. This test verifies that behavior. TODO: + // Investigate this. Potentially obsolete logRecord.State and force + // StateValues/ParseStateValues behavior. + List exportedItems = new(); + + using var exporter = new BatchLogRecordExportProcessor( + new InMemoryExporter(exportedItems)); + + var logRecord = new LogRecord(); + + var state = new LogRecordTest.DisposingState("Hello world"); + logRecord.State = state; + + exporter.OnEnd(logRecord); + + state.Dispose(); + + Assert.Throws(() => + { + IReadOnlyList> state = (IReadOnlyList>)logRecord.State; + + foreach (var kvp in state) + { + } + }); + } + } +} +#endif diff --git a/test/OpenTelemetry.Tests/Logs/LogRecordTest.cs b/test/OpenTelemetry.Tests/Logs/LogRecordTest.cs index 05305be10ff..79fb0d2fa19 100644 --- a/test/OpenTelemetry.Tests/Logs/LogRecordTest.cs +++ b/test/OpenTelemetry.Tests/Logs/LogRecordTest.cs @@ -256,8 +256,7 @@ public void CheckStateCanBeSet() using var loggerFactory = InitializeLoggerFactory(out List exportedItems, configure: null); var logger = loggerFactory.CreateLogger(); - var message = $"This does not matter."; - logger.LogInformation(message); + logger.LogInformation("This does not matter."); var logRecord = exportedItems[0]; logRecord.State = "newState"; @@ -744,6 +743,34 @@ public void ParseStateValuesUsingCustomTest() Assert.Same(state, actualState.Value); } + [Fact] + public void DisposingStateTest() + { + using var loggerFactory = InitializeLoggerFactory(out List exportedItems, configure: options => options.ParseStateValues = true); + var logger = loggerFactory.CreateLogger(); + + DisposingState state = new DisposingState("Hello world"); + + logger.Log( + LogLevel.Information, + 0, + state, + null, + (s, e) => "OpenTelemetry!"); + var logRecord = exportedItems[0]; + + state.Dispose(); + + Assert.Null(logRecord.State); + Assert.NotNull(logRecord.StateValues); + Assert.Equal(1, logRecord.StateValues.Count); + + KeyValuePair actualState = logRecord.StateValues[0]; + + Assert.Same("Value", actualState.Key); + Assert.Same("Hello world", actualState.Value); + } + private static ILoggerFactory InitializeLoggerFactory(out List exportedItems, Action configure = null) { var items = exportedItems = new List(); @@ -790,6 +817,54 @@ IEnumerator IEnumerable.GetEnumerator() } } + internal sealed class DisposingState : IReadOnlyList>, IDisposable + { + private string value; + private bool disposed; + + public DisposingState(string value) + { + this.Value = value; + } + + public int Count => 1; + + public string Value + { + get + { + if (this.disposed) + { + throw new ObjectDisposedException(nameof(DisposingState)); + } + + return this.value; + } + private set => this.value = value; + } + + public KeyValuePair this[int index] => index switch + { + 0 => new KeyValuePair(nameof(this.Value), this.Value), + _ => throw new IndexOutOfRangeException(nameof(index)), + }; + + public void Dispose() + { + this.disposed = true; + } + + public IEnumerator> GetEnumerator() + { + for (var i = 0; i < this.Count; i++) + { + yield return this[i]; + } + } + + IEnumerator IEnumerable.GetEnumerator() => this.GetEnumerator(); + } + private class RedactionProcessor : BaseProcessor { private readonly Field fieldToUpdate; From a1242dd2b6b4c3787cbfbfb22e02e4792a290150 Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Tue, 28 Jun 2022 13:01:29 -0700 Subject: [PATCH 14/15] Comments about buffering. --- src/OpenTelemetry/Logs/LogRecord.cs | 13 +++++++++++++ 1 file changed, 13 insertions(+) diff --git a/src/OpenTelemetry/Logs/LogRecord.cs b/src/OpenTelemetry/Logs/LogRecord.cs index fda465c9ae8..34d398cfa6b 100644 --- a/src/OpenTelemetry/Logs/LogRecord.cs +++ b/src/OpenTelemetry/Logs/LogRecord.cs @@ -239,10 +239,23 @@ internal int RemoveReference() return Interlocked.Decrement(ref this.PoolReferenceCount); } + // Note: Typically called when LogRecords are added into a batch so they + // can be safely processed outside of the log call chain. internal void Buffer() { + // Note: State values are buffered because some states are not safe + // to access outside of the log call chain. See: + // https://github.com/open-telemetry/opentelemetry-dotnet/issues/2905 this.BufferLogStateValues(); + this.BufferLogScopes(); + + // Note: There is no buffering of "State" only "StateValues". We + // don't inspect "object State" at all. It is undefined what + // exporters will do with "State". Some might ignore it, some might + // attempt to access it as a list. That is potentially dangerous. + // TODO: Investigate what to do here. Should we obsolete State and + // just use the StateValues design? } internal LogRecord Copy() From 4000f85ed3df51a24deec9e84b7fc27abcc35eb8 Mon Sep 17 00:00:00 2001 From: Mikel Blanchard Date: Tue, 28 Jun 2022 13:11:21 -0700 Subject: [PATCH 15/15] Added code comments. --- src/OpenTelemetry/Logs/LogRecord.cs | 7 +++++++ 1 file changed, 7 insertions(+) diff --git a/src/OpenTelemetry/Logs/LogRecord.cs b/src/OpenTelemetry/Logs/LogRecord.cs index 34d398cfa6b..61c8199391c 100644 --- a/src/OpenTelemetry/Logs/LogRecord.cs +++ b/src/OpenTelemetry/Logs/LogRecord.cs @@ -287,7 +287,14 @@ private void BufferLogStateValues() } var attributeStorage = this.AttributeStorage ??= new List>(stateValues.Count); + + // Note: AddRange here will copy all of the KeyValuePairs from + // stateValues to AttributeStorage. This "captures" the state and + // fixes issues where the values are generated at enumeration time + // like + // https://github.com/open-telemetry/opentelemetry-dotnet/issues/2905. attributeStorage.AddRange(stateValues); + this.StateValues = attributeStorage; }