Implement ISupportExternalScope

[JustusGreiberORGADATA]

Fixes: #113

Implement ISupportExternalScope for the provider. This will cause the logging infrastructure to manage the scope externally and provide it to the logger via IExternalScopeProvider. This has 2 benefits:

• Only one AsyncLocal for all providers: Not every logger needs to synchronize a thread safe scope collection.
• Acitvity.Current data provided as default scopes starting with .NET 5. This is the default distributed tracing solution for .NET applications. Because the Activity data is included in the default scopes through IExternalScopeProvider, ASP.NET Core removed the explicit Activity scope from the logs and instead relies on this implicit data. So adding it is important to allow consumers of this library to still be able to trace back their logs to the request that generated them.

The Pull Request is done in 3 steps:

1. Unify the test project

The test project was duplicated for .NET 5 and .NET 6 targeting. This pretty much meant writing every test twice if you wanted to add any functionality. Instead we can multi target a single test project to all target frameworks. This makes it easier to add new frameworks and allowed to easily expand the tested frameworks to the following values, giving a full test coverage to all target frameworks:

netcoreapp3.1;net5.0;net6.0;net461;net462;net47;net471;net472;net48

(Some test can't be run against every framework so they are taken out with the preprocessor. Also because not that many people likely have that many .NET Framework Versions installed one should maybe look to instead do those test on Github Actions or something like that in the future.)

2. Remove old .NET Core 1.1 exclusive code

Although the project only targets .NET Standard 2.0 and up there was still exclusive code for 1.1 so I removed that.

3. Switch to ISupportExternalScope

This is a breaking change, because external scope can't be used with the scope factories anymore. To still allow a consumer of this library to modify the scope data, the scope provider is passed to the configured ILog4NetLoggingEventFactory. The default Log4NetLoggingEventFactory has been modified to replicate the behaviour of the standard scope factories (I hope atleast there weren't a lot of tests sadly). Because this is a breaking change anyway, I also made MessageCandidate a readonly struct instead, that is passed by reference. This should allow for less allocations (no need to create a class on the heap, instead the values can be just pushed to the stack) and therefore be more resource friendly (still need to do a measurement on that one to be sure :)).

See:
datalust/seq-extensions-logging#36
dotnet/runtime#31372
dotnet/aspnetcore#22376
https://docs.microsoft.com/en-us/dotnet/core/diagnostics/distributed-tracing-instrumentation-walkthroughs

[JustusGreiberORGADATA]

@huorswords This is pretty much ready so feel free to check out the code already, it is a draft because there are tiny things I wanna think about left:

• is in MessageCandidate really better for performance?
• should Log4NetLoggingEventFactory make EnrichWithScopes virtual to make custom scope implementations easier?
• is Microsoft.Extensions.Logging.Scope actually a good namespace or would Microsoft.Extensions.Logging.Log4Net.Scope be safer, to never get in the way of the official framework.
• adding a ProviderAlias https://docs.microsoft.com/en-us/dotnet/api/microsoft.extensions.logging.provideraliasattribute?view=dotnet-plat-ext-6.0

[huorswords]

Thank you very much by your amazing contribution.

I'll try to answer the questions...

is in MessageCandidate really better for performance?

I have not tested at all, but yes, I think so, I feel comfortable with your proposal.

After reading the post you included as documentation in code, I think that could be very interesting to manage it as you have defined, specially when the scenario involves a lot of concurrent threads writing all to the Log4NetProvider. All actions that we can do to improve memory usage, are welcome.

should Log4NetLoggingEventFactory make EnrichWithScopes virtual to make custom scope implementations easier?

In this case, everything we can do to let the library consumers adapt the code to fulfil their needs, the better. So I think that it is a reasonable approach, always considering that the default behavior should be kept in place.

is Microsoft.Extensions.Logging.Scope actually a good namespace or would Microsoft.Extensions.Logging.Log4Net.Scope be safer, to never get in the way of the official framework.

My original idea (probably wrong) when I have decided to set the Microsoft.Extensions.Logging namespace was to fit into the current official namespace naming and avoid to import additional namespaces. If you consider that it is not correct at all, let's rethink about it. We have two options, I think:

1. Move namespaces base to match the library name (aka Microsoft.Logging.Extensions.Log4Net)
2. Try to specify the logging provider in the class name itself.

In this case, and in order to avoid big breaking change, I think that the better option is 2: to change NullScope & NullScopeProvider to Log4NetNullScope and Log4NetNullScopeProvider, regardless that it is a bit verbose name, considering that it is in a library for integrating Log4Net into Microsoft.Extensions.Logging framework.

What are your thoughts on that?

adding a ProviderAlias https://docs.microsoft.com/en-us/dotnet/api/microsoft.extensions.logging.provideraliasattribute?view=dotnet-plat-ext-6.0

I have considered it in the past, but at last I didn't found a good reason to include it yet. For me it is an extra. Do you think that could be important or maybe it could be considered just a configuration bonus?

Again, THANK YOU by your effort. This is a high level PR.

[JustusGreiberORGADATA]

is in MessageCandidate really better for performance?
I have not tested at all, but yes, I think so, I feel comfortable with your proposal.

Benchmark: https://github.com/Orgadata-AG/Microsoft.Extensions.Logging.Log4Net.AspNetCore/tree/allocation-benchmark/src/Benchmark.Tests

Allocating is the old way with a class, non allocation the readonly struct.

Result is that it uses less allocations and therefore does less Gen 0 garbadge collections and is pretty much the same in speed.

BenchmarkDotNet=v0.13.1, OS=Windows 10.0.22000
Intel Core i7-8559U CPU 2.70GHz (Coffee Lake), 1 CPU, 8 logical and 4 physical cores
.NET SDK=6.0.101
  [Host]               : .NET Core 3.1.22 (CoreCLR 4.700.21.56803, CoreFX 4.700.21.57101), X64 RyuJIT
  .NET 5.0             : .NET 5.0.13 (5.0.1321.56516), X64 RyuJIT
  .NET 6.0             : .NET 6.0.1 (6.0.121.56705), X64 RyuJIT
  .NET Core 3.1        : .NET Core 3.1.22 (CoreCLR 4.700.21.56803, CoreFX 4.700.21.57101), X64 RyuJIT
  .NET Framework 4.6.1 : .NET Framework 4.8 (4.8.4420.0), X64 RyuJIT
  .NET Framework 4.6.2 : .NET Framework 4.8 (4.8.4420.0), X64 RyuJIT
  .NET Framework 4.7   : .NET Framework 4.8 (4.8.4420.0), X64 RyuJIT
  .NET Framework 4.7.1 : .NET Framework 4.8 (4.8.4420.0), X64 RyuJIT
  .NET Framework 4.7.2 : .NET Framework 4.8 (4.8.4420.0), X64 RyuJIT
  .NET Framework 4.8   : .NET Framework 4.8 (4.8.4420.0), X64 RyuJIT

Method	Job	Runtime	Mean	Error	StdDev	Ratio	RatioSD	Gen 0	Allocated
Allocating	.NET 5.0	.NET 5.0	401.9 ns	2.39 ns	2.00 ns	1.00	0.00	0.0782	328 B
NonAllocating	.NET 5.0	.NET 5.0	398.3 ns	2.03 ns	1.80 ns	0.99	0.01	0.0629	264 B
Allocating	.NET 6.0	.NET 6.0	302.2 ns	3.11 ns	2.91 ns	1.00	0.00	0.0782	328 B
NonAllocating	.NET 6.0	.NET 6.0	299.2 ns	5.86 ns	6.27 ns	0.99	0.03	0.0629	264 B
Allocating	.NET Core 3.1	.NET Core 3.1	490.8 ns	3.60 ns	3.01 ns	1.00	0.00	0.0782	328 B
NonAllocating	.NET Core 3.1	.NET Core 3.1	490.2 ns	3.17 ns	2.65 ns	1.00	0.01	0.0629	264 B
Allocating	.NET Framework 4.6.1	.NET Framework 4.6.1	521.2 ns	4.38 ns	3.42 ns	1.00	0.00	0.0839	353 B
NonAllocating	.NET Framework 4.6.1	.NET Framework 4.6.1	516.7 ns	3.61 ns	3.01 ns	0.99	0.01	0.0687	289 B
Allocating	.NET Framework 4.6.2	.NET Framework 4.6.2	515.3 ns	6.61 ns	6.19 ns	1.00	0.00	0.0839	353 B
NonAllocating	.NET Framework 4.6.2	.NET Framework 4.6.2	514.3 ns	3.02 ns	2.52 ns	1.00	0.01	0.0687	289 B
Allocating	.NET Framework 4.7	.NET Framework 4.7	515.3 ns	1.28 ns	1.00 ns	1.00	0.00	0.0839	353 B
NonAllocating	.NET Framework 4.7	.NET Framework 4.7	513.7 ns	1.82 ns	1.42 ns	1.00	0.00	0.0687	289 B
Allocating	.NET Framework 4.7.1	.NET Framework 4.7.1	520.1 ns	5.52 ns	4.89 ns	1.00	0.00	0.0839	353 B
NonAllocating	.NET Framework 4.7.1	.NET Framework 4.7.1	516.8 ns	4.68 ns	3.90 ns	0.99	0.01	0.0687	289 B
Allocating	.NET Framework 4.7.2	.NET Framework 4.7.2	522.2 ns	9.93 ns	8.29 ns	1.00	0.00	0.0839	353 B
NonAllocating	.NET Framework 4.7.2	.NET Framework 4.7.2	517.6 ns	1.60 ns	1.34 ns	0.99	0.01	0.0687	289 B
Allocating	.NET Framework 4.8	.NET Framework 4.8	522.9 ns	1.33 ns	1.11 ns	1.00	0.00	0.0839	353 B
NonAllocating	.NET Framework 4.8	.NET Framework 4.8	516.7 ns	0.86 ns	0.67 ns	0.99	0.00	0.0687	289 B

[JustusGreiberORGADATA]

should Log4NetLoggingEventFactory make EnrichWithScopes virtual to make custom scope implementations easier?

In this case, everything we can do to let the library consumers adapt the code to fulfil their needs, the better. So I think that it is a reasonable approach, always considering that the default behavior should be kept in place.

I made it virtual.

In this case, and in order to avoid big breaking change, I think that the better option is 2: to change NullScope & NullScopeProvider to Log4NetNullScope and Log4NetNullScopeProvider, regardless that it is a bit verbose name, considering that it is in a library for integrating Log4Net into Microsoft.Extensions.Logging framework.

What are your thoughts on that?

I saw that all the classes in the other subfolders already have a different namespace starting with Microsoft.Extensions.Logging.Log4Net.AspNetCore.*, which would never get introduced in the official framework anyway, because it is too long. I changed NullScope and NullScopeProvider to the same format, to make everything consistent again that should be enough to prevent any conflict and makes the whole thing consistent again.

I have considered it in the past, but at last I didn't found a good reason to include it yet. For me it is an extra. Do you think that could be important or maybe it could be considered just a configuration bonus?

I saw the alias for the default loggers used with filter rules for specific providers or something similar, but it seems to be possible to use the full type name so it's probably not a problem and there is no real need to add it [0].

I also made another tiny breaking change: If the logging scope is provided as KeyValuePair<string, object> the object used to be converted with object.ToString(). But if the object is something like int/float/double/... this will be a Culture aware conversion. This means if the object is something like System.Double the value CultureInfo.CurrentCulture will influence the conversion. For example 3.4 could be printed as 3,4 if the CurrentCulture is German.
I thought that would not be very good for a web application where the users will have different cultures depending on the request, otherwise you would have trouble searching for log messages that contain a specific value.
So I made instead used the invariant culture (CultureInfo.InvariantCulture), which implies culture independent conversion.

[0] https://github.com/dotnet/runtime/blob/57bfe474518ab5b7cfe6bf7424a79ce3af9d6657/src/libraries/Microsoft.Extensions.Logging/src/LoggerRuleSelector.cs#L28

[JustusGreiberORGADATA]

@huorswords I think i have everything ready now. But before you merge you should read my last comment, because there is another tiny breaking change, that you should be aware of/approve.

[huorswords]

Perfect. I will put an additional side note on Release notes in order to let the consumers know that the conversion of numeric values now is managed through InvariantCulture.

[huorswords]

Great job @JustusGreiberORGADATA!