diff --git a/src/OpenTelemetry/CHANGELOG.md b/src/OpenTelemetry/CHANGELOG.md index bcd7388b28b..1b7d64f1804 100644 --- a/src/OpenTelemetry/CHANGELOG.md +++ b/src/OpenTelemetry/CHANGELOG.md @@ -7,6 +7,11 @@ ## Unreleased +* Fixed an issue where `LogRecord.ForEachScope` may return scopes from a + previous log if accessed in a custom processor before + `BatchLogRecordExportProcessor.OnEnd` is fired. + ([#3731](https://github.com/open-telemetry/opentelemetry-dotnet/pull/3731)) + ## 1.4.0-beta.1 Released 2022-Sep-29 diff --git a/src/OpenTelemetry/Logs/LogRecord.cs b/src/OpenTelemetry/Logs/LogRecord.cs index f417ee86693..936e3f2e5b7 100644 --- a/src/OpenTelemetry/Logs/LogRecord.cs +++ b/src/OpenTelemetry/Logs/LogRecord.cs @@ -34,6 +34,7 @@ public sealed class LogRecord internal LogRecordData Data; internal LogRecordILoggerData ILoggerData; internal List>? AttributeStorage; + internal List? ScopeStorage; internal List? BufferedScopes; internal int PoolReferenceCount = int.MaxValue; @@ -375,11 +376,13 @@ private void BufferLogScopes() return; } - List scopes = this.BufferedScopes ??= new List(LogRecordPoolHelper.DefaultMaxNumberOfScopes); + var scopeStorage = this.ScopeStorage ??= new List(LogRecordPoolHelper.DefaultMaxNumberOfScopes); - this.ScopeProvider.ForEachScope(AddScopeToBufferedList, scopes); + this.ScopeProvider.ForEachScope(AddScopeToBufferedList, scopeStorage); this.ScopeProvider = null; + + this.BufferedScopes = scopeStorage; } internal struct LogRecordILoggerData diff --git a/src/OpenTelemetry/Logs/Pool/LogRecordPoolHelper.cs b/src/OpenTelemetry/Logs/Pool/LogRecordPoolHelper.cs index b63028b920b..e024e72063e 100644 --- a/src/OpenTelemetry/Logs/Pool/LogRecordPoolHelper.cs +++ b/src/OpenTelemetry/Logs/Pool/LogRecordPoolHelper.cs @@ -41,19 +41,19 @@ underlying array (capacity). */ } } - var bufferedScopes = logRecord.BufferedScopes; - if (bufferedScopes != null) + var scopeStorage = logRecord.ScopeStorage; + if (scopeStorage != null) { - if (bufferedScopes.Count > DefaultMaxNumberOfScopes) + if (scopeStorage.Count > DefaultMaxNumberOfScopes) { // Don't allow the pool to grow unconstained. - logRecord.BufferedScopes = null; + logRecord.ScopeStorage = null; } else { /* List.Clear sets the count/size to 0 but it maintains the underlying array (capacity). */ - bufferedScopes.Clear(); + scopeStorage.Clear(); } } } diff --git a/test/OpenTelemetry.Tests/Logs/LogRecordSharedPoolTests.cs b/test/OpenTelemetry.Tests/Logs/LogRecordSharedPoolTests.cs index 0a6d7d37baf..2541c5cc5db 100644 --- a/test/OpenTelemetry.Tests/Logs/LogRecordSharedPoolTests.cs +++ b/test/OpenTelemetry.Tests/Logs/LogRecordSharedPoolTests.cs @@ -136,19 +136,19 @@ public void ClearTests() new KeyValuePair("key1", "value1"), new KeyValuePair("key2", "value2"), }; - logRecord1.BufferedScopes = new List(8) { null, null }; + logRecord1.ScopeStorage = 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); + Assert.Empty(logRecord1.ScopeStorage); + Assert.Equal(8, logRecord1.ScopeStorage.Capacity); logRecord1 = pool.Rent(); Assert.NotNull(logRecord1.AttributeStorage); - Assert.NotNull(logRecord1.BufferedScopes); + Assert.NotNull(logRecord1.ScopeStorage); for (int i = 0; i <= LogRecordPoolHelper.DefaultMaxNumberOfAttributes; i++) { @@ -157,13 +157,13 @@ public void ClearTests() for (int i = 0; i <= LogRecordPoolHelper.DefaultMaxNumberOfScopes; i++) { - logRecord1.BufferedScopes!.Add(null); + logRecord1.ScopeStorage!.Add(null); } pool.Return(logRecord1); Assert.Null(logRecord1.AttributeStorage); - Assert.Null(logRecord1.BufferedScopes); + Assert.Null(logRecord1.ScopeStorage); } [Theory] diff --git a/test/OpenTelemetry.Tests/Logs/LogRecordTest.cs b/test/OpenTelemetry.Tests/Logs/LogRecordTest.cs index 65a65745099..8f521c649bb 100644 --- a/test/OpenTelemetry.Tests/Logs/LogRecordTest.cs +++ b/test/OpenTelemetry.Tests/Logs/LogRecordTest.cs @@ -934,6 +934,39 @@ public void DisposingStateTest() Assert.Same("Hello world", actualState.Value); } + [Theory] + [InlineData(true)] + [InlineData(false)] + public void ReusedLogRecordScopeTest(bool buffer) + { + var processor = new ScopeProcessor(buffer); + + using var loggerFactory = LoggerFactory.Create(builder => + { + builder.AddOpenTelemetry(options => + { + options.IncludeScopes = true; + options.AddProcessor(processor); + }); + }); + + var logger = loggerFactory.CreateLogger("TestLogger"); + + using (var scope1 = logger.BeginScope("scope1")) + { + logger.LogInformation("message1"); + } + + using (var scope2 = logger.BeginScope("scope2")) + { + logger.LogInformation("message2"); + } + + Assert.Equal(2, processor.Scopes.Count); + Assert.Equal("scope1", processor.Scopes[0]); + Assert.Equal("scope2", processor.Scopes[1]); + } + private static ILoggerFactory InitializeLoggerFactory(out List exportedItems, Action configure = null) { var items = exportedItems = new List(); @@ -1084,5 +1117,32 @@ private class CustomState public string Property3 { get; set; } } + + private class ScopeProcessor : BaseProcessor + { + private readonly bool buffer; + + public ScopeProcessor(bool buffer) + { + this.buffer = buffer; + } + + public List Scopes { get; } = new(); + + public override void OnEnd(LogRecord data) + { + data.ForEachScope( + (scope, state) => + { + this.Scopes.Add(scope.Scope); + }, + null); + + if (this.buffer) + { + data.Buffer(); + } + } + } } } diff --git a/test/OpenTelemetry.Tests/Logs/LogRecordThreadStaticPoolTests.cs b/test/OpenTelemetry.Tests/Logs/LogRecordThreadStaticPoolTests.cs index 93a334cc567..f683609c013 100644 --- a/test/OpenTelemetry.Tests/Logs/LogRecordThreadStaticPoolTests.cs +++ b/test/OpenTelemetry.Tests/Logs/LogRecordThreadStaticPoolTests.cs @@ -57,19 +57,19 @@ public void ClearTests() new KeyValuePair("key1", "value1"), new KeyValuePair("key2", "value2"), }; - logRecord1.BufferedScopes = new List(8) { null, null }; + logRecord1.ScopeStorage = 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); + Assert.Empty(logRecord1.ScopeStorage); + Assert.Equal(8, logRecord1.ScopeStorage.Capacity); logRecord1 = LogRecordThreadStaticPool.Instance.Rent(); Assert.NotNull(logRecord1.AttributeStorage); - Assert.NotNull(logRecord1.BufferedScopes); + Assert.NotNull(logRecord1.ScopeStorage); for (int i = 0; i <= LogRecordPoolHelper.DefaultMaxNumberOfAttributes; i++) { @@ -78,13 +78,13 @@ public void ClearTests() for (int i = 0; i <= LogRecordPoolHelper.DefaultMaxNumberOfScopes; i++) { - logRecord1.BufferedScopes!.Add(null); + logRecord1.ScopeStorage!.Add(null); } LogRecordThreadStaticPool.Instance.Return(logRecord1); Assert.Null(logRecord1.AttributeStorage); - Assert.Null(logRecord1.BufferedScopes); + Assert.Null(logRecord1.ScopeStorage); } } }