Skip to content

Commit bd57c3b

Browse files
andreychaandreycha
authored
log4net layout: log latest scope value (#367)
* Fix test by using case insensitive version of StartsWith(). * Adjust test names. * Put latest property value to metadata (requires latest log4net version). * Update readme to reflect the latest state of generated events.
1 parent 7899022 commit bd57c3b

File tree

6 files changed

+412
-333
lines changed

6 files changed

+412
-333
lines changed

‎src/Elastic.CommonSchema.Log4net/Elastic.CommonSchema.Log4net.csproj‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,6 @@
1010
<ProjectReference Include="..\Elastic.CommonSchema\Elastic.CommonSchema.csproj" />
1111
</ItemGroup>
1212
<ItemGroup>
13-
<PackageReference Include="log4net" Version="2.0.15" />
13+
<PackageReference Include="log4net" Version="2.0.17" />
1414
</ItemGroup>
1515
</Project>

‎src/Elastic.CommonSchema.Log4net/LoggingEventConverter.cs‎

Lines changed: 9 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -78,14 +78,17 @@ private static MetadataDictionary GetMetadata(LoggingEvent loggingEvent)
7878

7979
var value = properties[property];
8080

81-
// use string representation of stacks because:
82-
// - if stack is empty then null is returned
83-
// - if stack contains one item log4net anyway supports only string values
84-
// - if stack contains several items then we need all of them
81+
// use latest string representation of the value in the stack
8582
if (value is ThreadContextStack tcs)
86-
value = tcs.ToString();
83+
{
84+
var stackValue = tcs.Peek();
85+
value = !string.IsNullOrEmpty(stackValue) ? stackValue : null;
86+
}
8787
else if (value is LogicalThreadContextStack ltcs)
88-
value = ltcs.ToString();
88+
{
89+
var stackValue = ltcs.Peek();
90+
value = !string.IsNullOrEmpty(stackValue) ? stackValue : null;
91+
}
8992

9093
if (value != null)
9194
metadata[property] = value;

‎src/Elastic.CommonSchema.Log4net/README.md‎

Lines changed: 37 additions & 18 deletions
Original file line numberDiff line numberDiff line change
@@ -45,6 +45,7 @@ is supported and will directly set the appropriate ECS field.
4545

4646
Apart from [mandatory fields](https://www.elastic.co/guide/en/ecs/current/ecs-guidelines.html#_general_guidelines), the output contains additional data:
4747

48+
- `labels` is taken from `metadata` (string and boolean properties)
4849
- `log.origin.file.name` is taken from `LocationInformation`
4950
- `log.origin.file.line` is taken from `LocationInformation`
5051
- `log.origin.function` is taken from `LocationInformation`
@@ -67,21 +68,7 @@ Sample log event output (formatted for readability):
6768
"@timestamp": "2022-08-28T14:06:28.5121651+02:00",
6869
"log.level": "INFO",
6970
"message": "Hi! Welcome to example!",
70-
"metadata": {
71-
"global_property": "Example",
72-
"message_template": "{0}! Welcome to example!"
73-
"0": "Hi"
74-
},
75-
"ecs": {
76-
"version": "8.3.1"
77-
},
78-
"event": {
79-
"timezone": "Central European Time",
80-
"created": "2022-08-28T14:06:28.5121651+02:00"
81-
},
82-
"host": {
83-
"hostname": "HGU780D3"
84-
},
71+
"ecs.version": "8.6.0",
8572
"log": {
8673
"logger": "Elastic.CommonSchema.Log4net.Example.Program",
8774
"original": null,
@@ -93,14 +80,46 @@ Sample log event output (formatted for readability):
9380
"function": "Main"
9481
}
9582
},
83+
"labels": {
84+
"MessageTemplate": "{0}! Welcome to example!"
85+
"0": "Hi"
86+
},
87+
"agent": {
88+
"type": "Elastic.CommonSchema.Log4net.Example",
89+
"version": "1.0.0.0"
90+
},
91+
"event": {
92+
"created": "2024-04-02T17:43:55.3829964+02:00",
93+
"timezone": "W. Europe Standard Time"
94+
},
95+
"host": {
96+
"os": {
97+
"full": "Microsoft Windows 10.0.22631",
98+
"platform": "Win32NT",
99+
"version": "10.0.22631.0"
100+
},
101+
"architecture": "X64",
102+
"hostname": "HGU780D3",
103+
"name": "HGU780D3"
104+
},
96105
"process": {
97-
"thread": {
98-
"id": 1
99-
}
106+
"name": "Elastic.CommonSchema.Log4net.Example",
107+
"pid": 39652,
108+
"thread.id": 17,
109+
"thread.name": ".NET Long Running Task",
110+
"title": ""
100111
},
101112
"service": {
102113
"name": "Elastic.CommonSchema.Log4net.Example",
114+
"type": "dotnet",
103115
"version": "1.0.0.0"
116+
},
117+
"user": {
118+
"domain": "company",
119+
"name": "user"
120+
},
121+
"metadata": {
122+
"GlobalAmountProperty": 3.14
104123
}
105124
}
106125
```

‎tests/Elastic.CommonSchema.Log4net.Tests/EcsFieldsAsPropertiesTests.cs‎

Lines changed: 73 additions & 76 deletions
Original file line numberDiff line numberDiff line change
@@ -10,95 +10,54 @@
1010
using log4net.Core;
1111
using Xunit;
1212

13-
namespace Elastic.CommonSchema.Log4net.Tests
14-
{
15-
[CollectionDefinition("EcsProperties", DisableParallelization = true)]
16-
public class EcsFieldsAsPropertiesTests : LogTestsBase
17-
{
18-
private const string FixedTraceId = "my-trace-id";
19-
20-
[Fact]
21-
public void EcsFieldInLogProperties()
22-
{
23-
void LogAndAssert(ILog log, Func<List<string>> getLogEvents)
24-
{
25-
log.Info("DummyText");
26-
27-
var logEvents = getLogEvents();
28-
logEvents.Should().HaveCount(1);
29-
30-
var (_, info) = ToEcsEvents(logEvents).First();
31-
info.TraceId.Should().Be(FixedTraceId);
32-
}
33-
34-
// Testing these in one unit test because ThreadContext overwrites LogicalThreadContext which overwrites GlobalContext.
35-
// Testing these in isolation introduces race issues when we remove the property
36-
37-
LogicalThreadContext.Properties[LogTemplateProperties.TraceId] = FixedTraceId;
38-
try
39-
{
40-
TestLogger(LogAndAssert);
41-
}
42-
finally
43-
{
44-
LogicalThreadContext.Properties.Remove(LogTemplateProperties.TraceId);
45-
}
46-
47-
ThreadContext.Properties[LogTemplateProperties.TraceId] = FixedTraceId;
48-
try
49-
{
50-
TestLogger(LogAndAssert);
51-
}
52-
finally
53-
{
54-
ThreadContext.Properties.Remove(LogTemplateProperties.TraceId);
55-
}
56-
TestLogger((log, getLogEvents) =>
57-
{
58-
var loggingEvent = new LoggingEvent(GetType(), log.Logger.Repository, log.Logger.Name, Level.Info, "DummyText", null);
59-
loggingEvent.Properties[LogTemplateProperties.TraceId] = FixedTraceId;
60-
log.Logger.Log(loggingEvent);
61-
62-
var logEvents = getLogEvents();
63-
logEvents.Should().HaveCount(1);
64-
65-
var (_, info) = ToEcsEvents(logEvents).First();
66-
info.TraceId.Should().Be(FixedTraceId);
67-
});
68-
69-
GlobalContext.Properties[LogTemplateProperties.TraceId] = FixedTraceId;
70-
try
71-
{
72-
TestLogger(LogAndAssert);
73-
}
74-
finally
75-
{
76-
GlobalContext.Properties.Remove(LogTemplateProperties.TraceId);
77-
}
78-
79-
}
13+
namespace Elastic.CommonSchema.Log4net.Tests;
8014

15+
[CollectionDefinition("EcsProperties", DisableParallelization = true)]
16+
public class EcsFieldsAsPropertiesTests : LogTestsBase
17+
{
18+
private const string FixedTraceId = "my-trace-id";
8119

82-
[Fact]
83-
public void EcsFieldsInThreadContextStack() => TestLogger((log, getLogEvents) =>
20+
[Fact]
21+
public void EcsFieldInLogProperties()
22+
{
23+
void LogAndAssert(ILog log, Func<List<string>> getLogEvents)
8424
{
85-
using var _ = ThreadContext.Stacks[LogTemplateProperties.TraceId].Push(FixedTraceId);
86-
8725
log.Info("DummyText");
8826

8927
var logEvents = getLogEvents();
9028
logEvents.Should().HaveCount(1);
9129

9230
var (_, info) = ToEcsEvents(logEvents).First();
9331
info.TraceId.Should().Be(FixedTraceId);
94-
});
32+
}
33+
34+
// Testing these in one unit test because ThreadContext overwrites LogicalThreadContext which overwrites GlobalContext.
35+
// Testing these in isolation introduces race issues when we remove the property
9536

96-
[Fact]
97-
public void EcsFieldsInLogicalTheadContextStack() => TestLogger((log, getLogEvents) =>
37+
LogicalThreadContext.Properties[LogTemplateProperties.TraceId] = FixedTraceId;
38+
try
39+
{
40+
TestLogger(LogAndAssert);
41+
}
42+
finally
9843
{
99-
using var _ = LogicalThreadContext.Stacks[LogTemplateProperties.TraceId].Push(FixedTraceId);
44+
LogicalThreadContext.Properties.Remove(LogTemplateProperties.TraceId);
45+
}
10046

101-
log.Info("DummyText");
47+
ThreadContext.Properties[LogTemplateProperties.TraceId] = FixedTraceId;
48+
try
49+
{
50+
TestLogger(LogAndAssert);
51+
}
52+
finally
53+
{
54+
ThreadContext.Properties.Remove(LogTemplateProperties.TraceId);
55+
}
56+
TestLogger((log, getLogEvents) =>
57+
{
58+
var loggingEvent = new LoggingEvent(GetType(), log.Logger.Repository, log.Logger.Name, Level.Info, "DummyText", null);
59+
loggingEvent.Properties[LogTemplateProperties.TraceId] = FixedTraceId;
60+
log.Logger.Log(loggingEvent);
10261

10362
var logEvents = getLogEvents();
10463
logEvents.Should().HaveCount(1);
@@ -107,5 +66,43 @@ public void EcsFieldsInLogicalTheadContextStack() => TestLogger((log, getLogEven
10766
info.TraceId.Should().Be(FixedTraceId);
10867
});
10968

69+
GlobalContext.Properties[LogTemplateProperties.TraceId] = FixedTraceId;
70+
try
71+
{
72+
TestLogger(LogAndAssert);
73+
}
74+
finally
75+
{
76+
GlobalContext.Properties.Remove(LogTemplateProperties.TraceId);
77+
}
78+
11079
}
80+
81+
[Fact]
82+
public void EcsFieldsInThreadContextStack() => TestLogger((log, getLogEvents) =>
83+
{
84+
using var _ = ThreadContext.Stacks[LogTemplateProperties.TraceId].Push(FixedTraceId);
85+
86+
log.Info("DummyText");
87+
88+
var logEvents = getLogEvents();
89+
logEvents.Should().HaveCount(1);
90+
91+
var (_, info) = ToEcsEvents(logEvents).First();
92+
info.TraceId.Should().Be(FixedTraceId);
93+
});
94+
95+
[Fact]
96+
public void EcsFieldsInLogicalTheadContextStack() => TestLogger((log, getLogEvents) =>
97+
{
98+
using var _ = LogicalThreadContext.Stacks[LogTemplateProperties.TraceId].Push(FixedTraceId);
99+
100+
log.Info("DummyText");
101+
102+
var logEvents = getLogEvents();
103+
logEvents.Should().HaveCount(1);
104+
105+
var (_, info) = ToEcsEvents(logEvents).First();
106+
info.TraceId.Should().Be(FixedTraceId);
107+
});
111108
}

‎tests/Elastic.CommonSchema.Log4net.Tests/LogTestsBase.cs‎

Lines changed: 25 additions & 27 deletions
Original file line numberDiff line numberDiff line change
@@ -10,41 +10,39 @@
1010
using log4net.Core;
1111
using log4net.Repository.Hierarchy;
1212

13+
namespace Elastic.CommonSchema.Log4net.Tests;
1314

14-
namespace Elastic.CommonSchema.Log4net.Tests
15+
public abstract class LogTestsBase
1516
{
16-
public abstract class LogTestsBase
17-
{
18-
private static readonly object _lock = new();
19-
protected List<(string Json, EcsDocument Base)> ToEcsEvents(List<string> logEvents) =>
20-
logEvents.Select(s => (s, EcsDocument.Deserialize(s)))
21-
.ToList();
17+
private static readonly object _lock = new();
18+
protected List<(string Json, EcsDocument Base)> ToEcsEvents(List<string> logEvents) =>
19+
logEvents.Select(s => (s, EcsDocument.Deserialize(s)))
20+
.ToList();
2221

23-
protected void TestLogger(Action<ILog, Func<List<string>>> act)
22+
protected void TestLogger(Action<ILog, Func<List<string>>> act)
23+
{
24+
lock (_lock)
2425
{
25-
lock (_lock)
26+
var repositoryId = Guid.NewGuid().ToString();
27+
var hierarchy = (Hierarchy)LogManager.CreateRepository(repositoryId);
28+
var appender = new TestAppender
2629
{
27-
var repositoryId = Guid.NewGuid().ToString();
28-
var hierarchy = (Hierarchy)LogManager.CreateRepository(repositoryId);
29-
var appender = new TestAppender
30-
{
31-
Layout = new EcsLayout()
32-
};
33-
hierarchy.Root.AddAppender(appender);
34-
hierarchy.Root.Level = Level.All;
35-
hierarchy.Configured = true;
36-
37-
List<string> GetAndValidateLogEvents()
38-
{
39-
foreach (var log in appender.Events)
40-
Spec.Validate(log);
30+
Layout = new EcsLayout()
31+
};
32+
hierarchy.Root.AddAppender(appender);
33+
hierarchy.Root.Level = Level.All;
34+
hierarchy.Configured = true;
4135

42-
return appender.Events;
43-
}
36+
List<string> GetAndValidateLogEvents()
37+
{
38+
foreach (var log in appender.Events)
39+
Spec.Validate(log);
4440

45-
var log = LogManager.GetLogger(repositoryId, GetType().Name);
46-
act(log, GetAndValidateLogEvents);
41+
return appender.Events;
4742
}
43+
44+
var log = LogManager.GetLogger(repositoryId, GetType().Name);
45+
act(log, GetAndValidateLogEvents);
4846
}
4947
}
5048
}

0 commit comments

Comments
 (0)