diff --git a/src/Elastic.CommonSchema.Log4net/Elastic.CommonSchema.Log4net.csproj b/src/Elastic.CommonSchema.Log4net/Elastic.CommonSchema.Log4net.csproj index a0ef4601..71f53fd8 100644 --- a/src/Elastic.CommonSchema.Log4net/Elastic.CommonSchema.Log4net.csproj +++ b/src/Elastic.CommonSchema.Log4net/Elastic.CommonSchema.Log4net.csproj @@ -10,6 +10,6 @@ - + diff --git a/src/Elastic.CommonSchema.Log4net/LoggingEventConverter.cs b/src/Elastic.CommonSchema.Log4net/LoggingEventConverter.cs index cf22d989..0c435d6a 100644 --- a/src/Elastic.CommonSchema.Log4net/LoggingEventConverter.cs +++ b/src/Elastic.CommonSchema.Log4net/LoggingEventConverter.cs @@ -78,14 +78,17 @@ private static MetadataDictionary GetMetadata(LoggingEvent loggingEvent) var value = properties[property]; - // use string representation of stacks because: - // - if stack is empty then null is returned - // - if stack contains one item log4net anyway supports only string values - // - if stack contains several items then we need all of them + // use latest string representation of the value in the stack if (value is ThreadContextStack tcs) - value = tcs.ToString(); + { + var stackValue = tcs.Peek(); + value = !string.IsNullOrEmpty(stackValue) ? stackValue : null; + } else if (value is LogicalThreadContextStack ltcs) - value = ltcs.ToString(); + { + var stackValue = ltcs.Peek(); + value = !string.IsNullOrEmpty(stackValue) ? stackValue : null; + } if (value != null) metadata[property] = value; diff --git a/src/Elastic.CommonSchema.Log4net/README.md b/src/Elastic.CommonSchema.Log4net/README.md index 58978bb6..47a0aa54 100644 --- a/src/Elastic.CommonSchema.Log4net/README.md +++ b/src/Elastic.CommonSchema.Log4net/README.md @@ -45,6 +45,7 @@ is supported and will directly set the appropriate ECS field. Apart from [mandatory fields](https://www.elastic.co/guide/en/ecs/current/ecs-guidelines.html#_general_guidelines), the output contains additional data: +- `labels` is taken from `metadata` (string and boolean properties) - `log.origin.file.name` is taken from `LocationInformation` - `log.origin.file.line` is taken from `LocationInformation` - `log.origin.function` is taken from `LocationInformation` @@ -67,21 +68,7 @@ Sample log event output (formatted for readability): "@timestamp": "2022-08-28T14:06:28.5121651+02:00", "log.level": "INFO", "message": "Hi! Welcome to example!", - "metadata": { - "global_property": "Example", - "message_template": "{0}! Welcome to example!" - "0": "Hi" - }, - "ecs": { - "version": "8.3.1" - }, - "event": { - "timezone": "Central European Time", - "created": "2022-08-28T14:06:28.5121651+02:00" - }, - "host": { - "hostname": "HGU780D3" - }, + "ecs.version": "8.6.0", "log": { "logger": "Elastic.CommonSchema.Log4net.Example.Program", "original": null, @@ -93,14 +80,46 @@ Sample log event output (formatted for readability): "function": "Main" } }, + "labels": { + "MessageTemplate": "{0}! Welcome to example!" + "0": "Hi" + }, + "agent": { + "type": "Elastic.CommonSchema.Log4net.Example", + "version": "1.0.0.0" + }, + "event": { + "created": "2024-04-02T17:43:55.3829964+02:00", + "timezone": "W. Europe Standard Time" + }, + "host": { + "os": { + "full": "Microsoft Windows 10.0.22631", + "platform": "Win32NT", + "version": "10.0.22631.0" + }, + "architecture": "X64", + "hostname": "HGU780D3", + "name": "HGU780D3" + }, "process": { - "thread": { - "id": 1 - } + "name": "Elastic.CommonSchema.Log4net.Example", + "pid": 39652, + "thread.id": 17, + "thread.name": ".NET Long Running Task", + "title": "" }, "service": { "name": "Elastic.CommonSchema.Log4net.Example", + "type": "dotnet", "version": "1.0.0.0" + }, + "user": { + "domain": "company", + "name": "user" + }, + "metadata": { + "GlobalAmountProperty": 3.14 } } ``` diff --git a/tests/Elastic.CommonSchema.Log4net.Tests/EcsFieldsAsPropertiesTests.cs b/tests/Elastic.CommonSchema.Log4net.Tests/EcsFieldsAsPropertiesTests.cs index b6e38798..67fceb60 100644 --- a/tests/Elastic.CommonSchema.Log4net.Tests/EcsFieldsAsPropertiesTests.cs +++ b/tests/Elastic.CommonSchema.Log4net.Tests/EcsFieldsAsPropertiesTests.cs @@ -10,80 +10,18 @@ using log4net.Core; using Xunit; -namespace Elastic.CommonSchema.Log4net.Tests -{ - [CollectionDefinition("EcsProperties", DisableParallelization = true)] - public class EcsFieldsAsPropertiesTests : LogTestsBase - { - private const string FixedTraceId = "my-trace-id"; - - [Fact] - public void EcsFieldInLogProperties() - { - void LogAndAssert(ILog log, Func> getLogEvents) - { - log.Info("DummyText"); - - var logEvents = getLogEvents(); - logEvents.Should().HaveCount(1); - - var (_, info) = ToEcsEvents(logEvents).First(); - info.TraceId.Should().Be(FixedTraceId); - } - - // Testing these in one unit test because ThreadContext overwrites LogicalThreadContext which overwrites GlobalContext. - // Testing these in isolation introduces race issues when we remove the property - - LogicalThreadContext.Properties[LogTemplateProperties.TraceId] = FixedTraceId; - try - { - TestLogger(LogAndAssert); - } - finally - { - LogicalThreadContext.Properties.Remove(LogTemplateProperties.TraceId); - } - - ThreadContext.Properties[LogTemplateProperties.TraceId] = FixedTraceId; - try - { - TestLogger(LogAndAssert); - } - finally - { - ThreadContext.Properties.Remove(LogTemplateProperties.TraceId); - } - TestLogger((log, getLogEvents) => - { - var loggingEvent = new LoggingEvent(GetType(), log.Logger.Repository, log.Logger.Name, Level.Info, "DummyText", null); - loggingEvent.Properties[LogTemplateProperties.TraceId] = FixedTraceId; - log.Logger.Log(loggingEvent); - - var logEvents = getLogEvents(); - logEvents.Should().HaveCount(1); - - var (_, info) = ToEcsEvents(logEvents).First(); - info.TraceId.Should().Be(FixedTraceId); - }); - - GlobalContext.Properties[LogTemplateProperties.TraceId] = FixedTraceId; - try - { - TestLogger(LogAndAssert); - } - finally - { - GlobalContext.Properties.Remove(LogTemplateProperties.TraceId); - } - - } +namespace Elastic.CommonSchema.Log4net.Tests; +[CollectionDefinition("EcsProperties", DisableParallelization = true)] +public class EcsFieldsAsPropertiesTests : LogTestsBase +{ + private const string FixedTraceId = "my-trace-id"; - [Fact] - public void EcsFieldsInThreadContextStack() => TestLogger((log, getLogEvents) => + [Fact] + public void EcsFieldInLogProperties() + { + void LogAndAssert(ILog log, Func> getLogEvents) { - using var _ = ThreadContext.Stacks[LogTemplateProperties.TraceId].Push(FixedTraceId); - log.Info("DummyText"); var logEvents = getLogEvents(); @@ -91,14 +29,35 @@ public void EcsFieldsInThreadContextStack() => TestLogger((log, getLogEvents) => var (_, info) = ToEcsEvents(logEvents).First(); info.TraceId.Should().Be(FixedTraceId); - }); + } + + // Testing these in one unit test because ThreadContext overwrites LogicalThreadContext which overwrites GlobalContext. + // Testing these in isolation introduces race issues when we remove the property - [Fact] - public void EcsFieldsInLogicalTheadContextStack() => TestLogger((log, getLogEvents) => + LogicalThreadContext.Properties[LogTemplateProperties.TraceId] = FixedTraceId; + try + { + TestLogger(LogAndAssert); + } + finally { - using var _ = LogicalThreadContext.Stacks[LogTemplateProperties.TraceId].Push(FixedTraceId); + LogicalThreadContext.Properties.Remove(LogTemplateProperties.TraceId); + } - log.Info("DummyText"); + ThreadContext.Properties[LogTemplateProperties.TraceId] = FixedTraceId; + try + { + TestLogger(LogAndAssert); + } + finally + { + ThreadContext.Properties.Remove(LogTemplateProperties.TraceId); + } + TestLogger((log, getLogEvents) => + { + var loggingEvent = new LoggingEvent(GetType(), log.Logger.Repository, log.Logger.Name, Level.Info, "DummyText", null); + loggingEvent.Properties[LogTemplateProperties.TraceId] = FixedTraceId; + log.Logger.Log(loggingEvent); var logEvents = getLogEvents(); logEvents.Should().HaveCount(1); @@ -107,5 +66,43 @@ public void EcsFieldsInLogicalTheadContextStack() => TestLogger((log, getLogEven info.TraceId.Should().Be(FixedTraceId); }); + GlobalContext.Properties[LogTemplateProperties.TraceId] = FixedTraceId; + try + { + TestLogger(LogAndAssert); + } + finally + { + GlobalContext.Properties.Remove(LogTemplateProperties.TraceId); + } + } + + [Fact] + public void EcsFieldsInThreadContextStack() => TestLogger((log, getLogEvents) => + { + using var _ = ThreadContext.Stacks[LogTemplateProperties.TraceId].Push(FixedTraceId); + + log.Info("DummyText"); + + var logEvents = getLogEvents(); + logEvents.Should().HaveCount(1); + + var (_, info) = ToEcsEvents(logEvents).First(); + info.TraceId.Should().Be(FixedTraceId); + }); + + [Fact] + public void EcsFieldsInLogicalTheadContextStack() => TestLogger((log, getLogEvents) => + { + using var _ = LogicalThreadContext.Stacks[LogTemplateProperties.TraceId].Push(FixedTraceId); + + log.Info("DummyText"); + + var logEvents = getLogEvents(); + logEvents.Should().HaveCount(1); + + var (_, info) = ToEcsEvents(logEvents).First(); + info.TraceId.Should().Be(FixedTraceId); + }); } diff --git a/tests/Elastic.CommonSchema.Log4net.Tests/LogTestsBase.cs b/tests/Elastic.CommonSchema.Log4net.Tests/LogTestsBase.cs index b11ca14c..2fc642cd 100644 --- a/tests/Elastic.CommonSchema.Log4net.Tests/LogTestsBase.cs +++ b/tests/Elastic.CommonSchema.Log4net.Tests/LogTestsBase.cs @@ -10,41 +10,39 @@ using log4net.Core; using log4net.Repository.Hierarchy; +namespace Elastic.CommonSchema.Log4net.Tests; -namespace Elastic.CommonSchema.Log4net.Tests +public abstract class LogTestsBase { - public abstract class LogTestsBase - { - private static readonly object _lock = new(); - protected List<(string Json, EcsDocument Base)> ToEcsEvents(List logEvents) => - logEvents.Select(s => (s, EcsDocument.Deserialize(s))) - .ToList(); + private static readonly object _lock = new(); + protected List<(string Json, EcsDocument Base)> ToEcsEvents(List logEvents) => + logEvents.Select(s => (s, EcsDocument.Deserialize(s))) + .ToList(); - protected void TestLogger(Action>> act) + protected void TestLogger(Action>> act) + { + lock (_lock) { - lock (_lock) + var repositoryId = Guid.NewGuid().ToString(); + var hierarchy = (Hierarchy)LogManager.CreateRepository(repositoryId); + var appender = new TestAppender { - var repositoryId = Guid.NewGuid().ToString(); - var hierarchy = (Hierarchy)LogManager.CreateRepository(repositoryId); - var appender = new TestAppender - { - Layout = new EcsLayout() - }; - hierarchy.Root.AddAppender(appender); - hierarchy.Root.Level = Level.All; - hierarchy.Configured = true; - - List GetAndValidateLogEvents() - { - foreach (var log in appender.Events) - Spec.Validate(log); + Layout = new EcsLayout() + }; + hierarchy.Root.AddAppender(appender); + hierarchy.Root.Level = Level.All; + hierarchy.Configured = true; - return appender.Events; - } + List GetAndValidateLogEvents() + { + foreach (var log in appender.Events) + Spec.Validate(log); - var log = LogManager.GetLogger(repositoryId, GetType().Name); - act(log, GetAndValidateLogEvents); + return appender.Events; } + + var log = LogManager.GetLogger(repositoryId, GetType().Name); + act(log, GetAndValidateLogEvents); } } } diff --git a/tests/Elastic.CommonSchema.Log4net.Tests/MessageTests.cs b/tests/Elastic.CommonSchema.Log4net.Tests/MessageTests.cs index 07b87bf7..703cec5a 100644 --- a/tests/Elastic.CommonSchema.Log4net.Tests/MessageTests.cs +++ b/tests/Elastic.CommonSchema.Log4net.Tests/MessageTests.cs @@ -3,155 +3,186 @@ // See the LICENSE file in the project root for more information using System; +using System.Collections.Generic; using System.Linq; using FluentAssertions; using log4net; using log4net.Core; using Xunit; -namespace Elastic.CommonSchema.Log4net.Tests +namespace Elastic.CommonSchema.Log4net.Tests; + +public class MessageTests : LogTestsBase { - public class MessageTests : LogTestsBase + [Fact] + public void ToEcs_AnyEvent_PopulatesBaseFields() => TestLogger((log, getLogEvents) => { - [Fact] - public void ToEcs_AnyEvent_PopulatesBaseFields() => TestLogger((log, getLogEvents) => - { - log.Info("DummyText"); + log.Info("DummyText"); - var logEvents = getLogEvents(); - logEvents.Should().HaveCount(1); + var logEvents = getLogEvents(); + logEvents.Should().HaveCount(1); - var (_, info) = ToEcsEvents(logEvents).First(); + var (_, info) = ToEcsEvents(logEvents).First(); - info.Should().NotBeNull(); + info.Should().NotBeNull(); - info.Timestamp.Should().BeWithin(TimeSpan.FromSeconds(5)); - info.Ecs.Version.Should().Be(EcsDocument.Version); - info.Message.Should().Be("DummyText"); - }); + info.Timestamp.Should().BeWithin(TimeSpan.FromSeconds(5)); + info.Ecs.Version.Should().Be(EcsDocument.Version); + info.Message.Should().Be("DummyText"); + }); - [Fact] - public void ToEcs_AnyEvent_PopulatesLogField() => TestLogger((log, getLogEvents) => - { - log.Info("DummyText"); + [Fact] + public void ToEcs_AnyEvent_PopulatesLogField() => TestLogger((log, getLogEvents) => + { + log.Info("DummyText"); - var logEvents = getLogEvents(); - logEvents.Should().HaveCount(1); + var logEvents = getLogEvents(); + logEvents.Should().HaveCount(1); - var (_, info) = ToEcsEvents(logEvents).First(); + var (_, info) = ToEcsEvents(logEvents).First(); - info.Log.Should().NotBeNull(); + info.Log.Should().NotBeNull(); - info.Log.Level.Should().Be("INFO"); - info.Log.Logger.Should().Be(GetType().Name); - info.Log.OriginFunction.Should().NotBeNullOrEmpty(); - }); + info.Log.Level.Should().Be("INFO"); + info.Log.Logger.Should().Be(GetType().Name); + info.Log.OriginFunction.Should().NotBeNullOrEmpty(); + }); - [Fact] - public void ToEcs_AnyEvent_PopulatesEventField() => TestLogger((log, getLogEvents) => - { - log.Info("DummyText"); + [Fact] + public void ToEcs_AnyEvent_PopulatesEventField() => TestLogger((log, getLogEvents) => + { + log.Info("DummyText"); - var logEvents = getLogEvents(); - logEvents.Should().HaveCount(1); + var logEvents = getLogEvents(); + logEvents.Should().HaveCount(1); - var (_, info) = ToEcsEvents(logEvents).First(); + var (_, info) = ToEcsEvents(logEvents).First(); - info.Event.Should().NotBeNull(); - info.Event.Created.Should().BeWithin(TimeSpan.FromSeconds(5)); - info.Event.Timezone.Should().Be(TimeZoneInfo.Local.StandardName); - }); + info.Event.Should().NotBeNull(); + info.Event.Created.Should().BeWithin(TimeSpan.FromSeconds(5)); + info.Event.Timezone.Should().Be(TimeZoneInfo.Local.StandardName); + }); - [Fact] - public void ToEcs_AnyEvent_PopulatesProcessField() => TestLogger((log, getLogEvents) => - { - var loggingEvent = new LoggingEvent(GetType(), log.Logger.Repository, log.Logger.Name, Level.Info, "DummyText", null); - log.Logger.Log(loggingEvent); + [Fact] + public void ToEcs_AnyEvent_PopulatesProcessField() => TestLogger((log, getLogEvents) => + { + var loggingEvent = new LoggingEvent(GetType(), log.Logger.Repository, log.Logger.Name, Level.Info, "DummyText", null); + log.Logger.Log(loggingEvent); - var logEvents = getLogEvents(); - logEvents.Should().HaveCount(1); + var logEvents = getLogEvents(); + logEvents.Should().HaveCount(1); - var (_, info) = ToEcsEvents(logEvents).First(); + var (_, info) = ToEcsEvents(logEvents).First(); - info.Process.Should().NotBeNull(); - if (int.TryParse(loggingEvent.ThreadName, out var threadId)) - info.Process.ThreadId.Should().Be(threadId); - else - info.Process.ThreadName.Should().Be(loggingEvent.ThreadName); - }); + info.Process.Should().NotBeNull(); + if (int.TryParse(loggingEvent.ThreadName, out var threadId)) + info.Process.ThreadId.Should().Be(threadId); + else + info.Process.ThreadName.Should().Be(loggingEvent.ThreadName); + }); - [Fact] - public void ToEcs_AnyEvent_PopulatesHostField() => TestLogger((log, getLogEvents) => - { - var loggingEvent = new LoggingEvent(GetType(), log.Logger.Repository, log.Logger.Name, Level.Info, "DummyText", null); - log.Logger.Log(loggingEvent); + [Fact] + public void ToEcs_AnyEvent_PopulatesHostField() => TestLogger((log, getLogEvents) => + { + var loggingEvent = new LoggingEvent(GetType(), log.Logger.Repository, log.Logger.Name, Level.Info, "DummyText", null); + log.Logger.Log(loggingEvent); - var logEvents = getLogEvents(); - logEvents.Should().HaveCount(1); + var logEvents = getLogEvents(); + logEvents.Should().HaveCount(1); - var (_, info) = ToEcsEvents(logEvents).First(); + var (_, info) = ToEcsEvents(logEvents).First(); - info.Host.Should().NotBeNull(); - var fqdn = loggingEvent.LookupProperty(LoggingEvent.HostNameProperty).ToString(); - fqdn.Should().NotBeNullOrEmpty(); - info.Host.Hostname.Should().StartWith(fqdn.Split('.', StringSplitOptions.None).First()); - }); + info.Host.Should().NotBeNull(); + var fqdn = loggingEvent.LookupProperty(LoggingEvent.HostNameProperty).ToString(); + fqdn.Should().NotBeNullOrEmpty(); + info.Host.Hostname.Should().StartWithEquivalent(fqdn.Split('.', StringSplitOptions.None).First()); + }); - [Fact] - public void ToEcs_EventWithException_PopulatesErrorField() => TestLogger((log, getLogEvents) => + [Fact] + public void ToEcs_EventWithException_PopulatesErrorField() => TestLogger((log, getLogEvents) => + { + var innerException = new ArgumentException("Wrong argument"); + try { - var innerException = new ArgumentException("Wrong argument"); try { - try - { - throw innerException; - } - catch (Exception e) - { - throw new InvalidOperationException("Oops", e); - } + throw innerException; } catch (Exception e) { - log.Info("DummyText", e); + throw new InvalidOperationException("Oops", e); + } + } + catch (Exception e) + { + log.Info("DummyText", e); - var logEvents = getLogEvents(); - logEvents.Should().HaveCount(1); + var logEvents = getLogEvents(); + logEvents.Should().HaveCount(1); - var (_, info) = ToEcsEvents(logEvents).First(); + var (_, info) = ToEcsEvents(logEvents).First(); - info.Error.Should().NotBeNull(); - info.Error.Message.Should().Be(e.Message); - info.Error.Type.Should().Be(e.GetType().FullName); + info.Error.Should().NotBeNull(); + info.Error.Message.Should().Be(e.Message); + info.Error.Type.Should().Be(e.GetType().FullName); - info.Error.StackTrace.Should().Contain(e.Message); - info.Error.StackTrace.Should().Contain("at void"); + info.Error.StackTrace.Should().Contain(e.Message); + info.Error.StackTrace.Should().Contain("at void"); - info.Error.StackTrace.Should().Contain(innerException.Message); - info.Error.StackTrace.Should().Contain("at void"); - } - }); + info.Error.StackTrace.Should().Contain(innerException.Message); + info.Error.StackTrace.Should().Contain("at void"); + } + }); - [Fact] - public void ToEcs_EventWithFormat_MetadataContainsTemplateAndArgs() => TestLogger((log, getLogEvents) => - { - log.InfoFormat("Log with {0}", "format"); + [Fact] + public void ToEcs_EventWithFormat_LabelsContainTemplateAndArgs() => TestLogger((log, getLogEvents) => + { + log.InfoFormat("Log with {0}", "format"); - var logEvents = getLogEvents(); - logEvents.Should().HaveCount(1); + var logEvents = getLogEvents(); + logEvents.Should().HaveCount(1); - var (_, info) = ToEcsEvents(logEvents).First(); + var (_, info) = ToEcsEvents(logEvents).First(); - info.Should().NotBeNull(); - info.Labels.Should().NotBeNull(); + info.Should().NotBeNull(); + info.Labels.Should().NotBeNull(); - info.Labels["MessageTemplate"].Should().Be("Log with {0}"); - info.Labels["0"].Should().Be("format"); - }); + info.Labels["MessageTemplate"].Should().Be("Log with {0}"); + info.Labels["0"].Should().Be("format"); + }); - [Fact] - public void ToEcs_AnyEvent_PopulatesMetadataFieldWithoutLog4netProperties() => TestLogger((log, getLogEvents) => + [Fact] + public void ToEcs_AnyEvent_PopulatesMetadataAndLabelsFieldsWithoutLog4netProperties() => TestLogger((log, getLogEvents) => + { + log.Info("DummyText"); + + var logEvents = getLogEvents(); + logEvents.Should().HaveCount(1); + + var (_, info) = ToEcsEvents(logEvents).First(); + + if (info.Metadata != null) + { + info.Metadata.Should().NotContainKey(LoggingEvent.IdentityProperty); + info.Metadata.Should().NotContainKey(LoggingEvent.HostNameProperty); + info.Metadata.Should().NotContainKey(LoggingEvent.UserNameProperty); + } + if (info.Labels != null) + { + info.Labels.Should().NotContainKey(LoggingEvent.IdentityProperty); + info.Labels.Should().NotContainKey(LoggingEvent.HostNameProperty); + info.Labels.Should().NotContainKey(LoggingEvent.UserNameProperty); + } + }); + + [Fact] + public void ToEcs_EventWithGlobalContextProperty_PopulatesLabelsField() => TestLogger((log, getLogEvents) => + { + const string property = "global-prop"; + const string propertyValue = "global-value"; + GlobalContext.Properties[property] = propertyValue; + + try { log.Info("DummyText"); @@ -160,52 +191,42 @@ public void ToEcs_AnyEvent_PopulatesMetadataFieldWithoutLog4netProperties() => T var (_, info) = ToEcsEvents(logEvents).First(); - if (info.Metadata != null) - { - info.Metadata.Should().NotContainKey(LoggingEvent.IdentityProperty); - info.Metadata.Should().NotContainKey(LoggingEvent.HostNameProperty); - info.Metadata.Should().NotContainKey(LoggingEvent.UserNameProperty); - } - if (info.Labels != null) - { - info.Labels.Should().NotContainKey(LoggingEvent.IdentityProperty); - info.Labels.Should().NotContainKey(LoggingEvent.HostNameProperty); - info.Labels.Should().NotContainKey(LoggingEvent.UserNameProperty); - } - }); - - [Fact] - public void ToEcs_EventWithGlobalContextProperty_PopulatesMetadataField() => TestLogger((log, getLogEvents) => + info.Labels.Should().ContainKey(property); + info.Labels[property].Should().Be(propertyValue); + } + finally { - const string property = "global-prop"; - const string propertyValue = "global-value"; - GlobalContext.Properties[property] = propertyValue; + GlobalContext.Properties.Remove(property); + } + }); - try - { - log.Info("DummyText"); + [Fact] + public void ToEcs_EventWithThreadContextStack_PopulatesLabelsField() => TestLogger((log, getLogEvents) => + { + const string property = "thread-context-stack-prop"; + const string propertyValue = "thread-context-stack-value"; + using var _ = ThreadContext.Stacks[property].Push(propertyValue); - var logEvents = getLogEvents(); - logEvents.Should().HaveCount(1); + log.Info("DummyText"); - var (_, info) = ToEcsEvents(logEvents).First(); + var logEvents = getLogEvents(); + logEvents.Should().HaveCount(1); - info.Labels.Should().ContainKey(property); - info.Labels[property].Should().Be(propertyValue); - } - finally - { - GlobalContext.Properties.Remove(property); - } - }); + var (_, info) = ToEcsEvents(logEvents).First(); - [Fact] - public void ToEcs_EventWithThreadContextStack_PopulatesMetadataField() => TestLogger((log, getLogEvents) => - { - const string property = "thread-context-stack-prop"; - const string propertyValue = "thread-context-stack-value"; - using var _ = ThreadContext.Stacks[property].Push(propertyValue); + info.Labels.Should().ContainKey(property); + info.Labels[property].Should().Be(propertyValue); + }); + + [Fact] + public void ToEcs_EventWithThreadContextProperty_PopulatesLabelsField() => TestLogger((log, getLogEvents) => + { + const string property = "thread-context-prop"; + const string propertyValue = "thread-context-value"; + ThreadContext.Properties[property] = propertyValue; + try + { log.Info("DummyText"); var logEvents = getLogEvents(); @@ -215,40 +236,45 @@ public void ToEcs_EventWithThreadContextStack_PopulatesMetadataField() => TestLo info.Labels.Should().ContainKey(property); info.Labels[property].Should().Be(propertyValue); - }); - - [Fact] - public void ToEcs_EventWithThreadContextProperty_PopulatesMetadataField() => TestLogger((log, getLogEvents) => + } + finally { - const string property = "thread-context-prop"; - const string propertyValue = "thread-context-value"; - ThreadContext.Properties[property] = propertyValue; + ThreadContext.Properties.Remove(property); + } + }); - try - { - log.Info("DummyText"); + [Fact] + public void ToEcs_EventInLogicalThreadContextStack_PopulatesLabelsField() => TestLogger((log, getLogEvents) => + { + const string property = "logical-thread-context-stack-prop"; + const string propertyValue = "logical-thread-context-stack-value"; + using var _ = LogicalThreadContext.Stacks[property].Push(propertyValue); - var logEvents = getLogEvents(); - logEvents.Should().HaveCount(1); + log.Info("DummyText"); - var (_, info) = ToEcsEvents(logEvents).First(); + var logEvents = getLogEvents(); + logEvents.Should().HaveCount(1); - info.Labels.Should().ContainKey(property); - info.Labels[property].Should().Be(propertyValue); - } - finally - { - ThreadContext.Properties.Remove(property); - } - }); + var (_, info) = ToEcsEvents(logEvents).First(); - [Fact] - public void ToEcs_EventInLogicalThreadContextStack_PopulatesMetadataField() => TestLogger((log, getLogEvents) => - { - const string property = "logical-thread-context-stack-prop"; - const string propertyValue = "logical-thread-context-stack-value"; - using var _ = LogicalThreadContext.Stacks[property].Push(propertyValue); + info.Metadata.Should().BeNull(); + info.Labels.Should().NotBeNull(); + info.Labels.Should().ContainKey(property); + info.Labels[property].Should().Be(propertyValue); + }); + + [Fact] + public void ToEcs_EventWithLogicalThreadContextProperty_PopulatesLabelsAndMetadataFields() => TestLogger((log, getLogEvents) => + { + const string property = "logical-thread-context-prop"; + const string propertyValue = "logical-thread-context-value"; + const string metadataProperty = "logical-thread-context-prop-metadata"; + LogicalThreadContext.Properties[property] = propertyValue; + LogicalThreadContext.Properties[metadataProperty] = 2.0; + + try + { log.Info("DummyText"); var logEvents = getLogEvents(); @@ -256,59 +282,95 @@ public void ToEcs_EventInLogicalThreadContextStack_PopulatesMetadataField() => T var (_, info) = ToEcsEvents(logEvents).First(); - info.Metadata.Should().BeNull(); - info.Labels.Should().NotBeNull(); - info.Labels.Should().ContainKey(property); info.Labels[property].Should().Be(propertyValue); - }); + info.Metadata.Should().ContainKey(metadataProperty); + info.Metadata[metadataProperty].Should().Be(2.0); + } + finally + { + LogicalThreadContext.Properties.Remove(property); + } + }); - [Fact] - public void ToEcs_EventWithLogicalThreadContextProperty_PopulatesMetadataField() => TestLogger((log, getLogEvents) => + [Fact] + public void ToEcs_EventWithProperties_PopulatesLabelsField() => TestLogger((log, getLogEvents) => + { + const string property = "additional-prop"; + const string propertyValue = "additional-value"; + + var loggingEvent = new LoggingEvent(GetType(), log.Logger.Repository, log.Logger.Name, Level.Info, "DummyText", null); + loggingEvent.Properties[property] = propertyValue; + log.Logger.Log(loggingEvent); + + var logEvents = getLogEvents(); + logEvents.Should().HaveCount(1); + + var (_, info) = ToEcsEvents(logEvents).First(); + + info.Labels.Should().ContainKey(property); + info.Labels[property].Should().Be(propertyValue); + }); + + [Fact] + public void ToEcs_EventsInMultipleThreadContextStacks_PopulatesLabelsFieldWithLatestValue() => TestLogger((log, getLogEvents) => + { + const string property = "thread-context-stack-prop"; + const string propertyValue = "thread-context-stack-value"; + const string latestPropertyValue = "latest-thread-context-stack-value"; + using (ThreadContext.Stacks[property].Push(propertyValue)) { - const string property = "logical-thread-context-prop"; - const string propertyValue = "logical-thread-context-value"; - const string metadataProperty = "logical-thread-context-prop-metadata"; - LogicalThreadContext.Properties[property] = propertyValue; - LogicalThreadContext.Properties[metadataProperty] = 2.0; + TestStackValue(log, getLogEvents, property, propertyValue); - try + using (ThreadContext.Stacks[property].Push(latestPropertyValue)) { - log.Info("DummyText"); + TestStackValue(log, getLogEvents, property, latestPropertyValue); + } - var logEvents = getLogEvents(); - logEvents.Should().HaveCount(1); + TestStackValue(log, getLogEvents, property, propertyValue); + } - var (_, info) = ToEcsEvents(logEvents).First(); + void TestStackValue(ILog log, Func> getLogEvents, string property, string expectedPropertyValue) + { + log.Info("DummyText"); - info.Labels.Should().ContainKey(property); - info.Labels[property].Should().Be(propertyValue); - info.Metadata.Should().ContainKey(metadataProperty); - info.Metadata[metadataProperty].Should().Be(2.0); - } - finally + var logEvents = getLogEvents(); + + var (_, info) = ToEcsEvents(logEvents).Last(); + + info.Labels.Should().ContainKey(property); + info.Labels[property].Should().Be(expectedPropertyValue); + } + }); + + [Fact] + public void ToEcs_EventsInLogicalThreadContextStacks_PopulatesLabelsFieldWithLatestValue() => TestLogger((log, getLogEvents) => + { + const string property = "logical-thread-context-stack-prop"; + const string propertyValue = "logical-thread-context-stack-value"; + const string latestPropertyValue = "latest-logical-thread-context-stack-value"; + using (LogicalThreadContext.Stacks[property].Push(propertyValue)) + { + TestStackValue(log, getLogEvents, property, propertyValue); + + using (LogicalThreadContext.Stacks[property].Push(latestPropertyValue)) { - LogicalThreadContext.Properties.Remove(property); + TestStackValue(log, getLogEvents, property, latestPropertyValue); } - }); - [Fact] - public void ToEcs_EventWithProperties_PopulatesMetadataField() => TestLogger((log, getLogEvents) => - { - const string property = "additional-prop"; - const string propertyValue = "additional-value"; + TestStackValue(log, getLogEvents, property, propertyValue); + } - var loggingEvent = new LoggingEvent(GetType(), log.Logger.Repository, log.Logger.Name, Level.Info, "DummyText", null); - loggingEvent.Properties[property] = propertyValue; - log.Logger.Log(loggingEvent); + void TestStackValue(ILog log, Func> getLogEvents, string property, string expectedPropertyValue) + { + log.Info("DummyText"); var logEvents = getLogEvents(); - logEvents.Should().HaveCount(1); - var (_, info) = ToEcsEvents(logEvents).First(); + var (_, info) = ToEcsEvents(logEvents).Last(); info.Labels.Should().ContainKey(property); - info.Labels[property].Should().Be(propertyValue); - }); - } + info.Labels[property].Should().Be(expectedPropertyValue); + } + }); }