serilog
serilog copied to clipboard
Performance Improvements - `CreateLogger()` and Logging Initialization
Changes:
- Lazy Initialization of the Configuration internals List's and Set's.
- Reuse the instances of List's and Set's Created on LoggerConfiguration after Logger creation.
- Lazy Inicialization of the Logger*Configuration.
- Avoid LINQ.
- Add Internal Empty Sink for Reduce Allocations and use the
EmptySinkwhen no sink was set. - Avoid array alocation with params modifier. (Public API Changes, adding a new Overload)
- Prefer Collection Expression.
- Add a new Benchmark to test the
CreateLogger()and the Serilog initialization time and memory usage.
Thanks for sending this and the other five benchmarking PRs, @rafaelsc!
Given benchmarks have the same ongoing maintenance costs as other kinds of tests, I think we need to grow the benchmark suite in a fairly conservative manner. I don't think we should merge these currently as it's not clear we'll be able to get benefit from them in the immediate future.
We tend to use benchmarks in a style that pairs them with optimizations in a specific area; or, we create temporary benchmarks when making those kinds of changes (e.g. https://github.com/serilog/serilog/issues/1944#issuecomment-2037884675).
If you're keen to dig into perf, perhaps working on a specific chunk of candidate code (say, JSON formatting, or something similar that hasn't been updated to match modern .NET APIs) and pairing improvements with benchmarks would be a smoother path forward?
Appreciate your efforts, and thanks nonetheless!
Hi @nblumhardt,
Years ago I paired many performance optimizations in the code with update/new benchmarks, and you said that has "hard to keep up, and to review it properly" because of the size of the changes. That is why this time I break down and smalls PRs this time, imaging that would be easy comparing the old benchmark result with the new in the future PR file comparation.
I'm been working in change for ~30% performance improvement and ~5% less memory usage for CreateLogger().
I can add this changes to this PR and put the Benchmark (Old and new) in the comments. In some weeks.
For the others I will need more time to migrate the old improvements and update them.
Hi @rafaelsc, thanks for the reply! I should probably have been clearer, small changes are good, but ideally we should review and discuss only one or two of them at a time. It's not just the change itself, but the purpose and plan that we can sync up on that way.
The CreateLogger() improvement sounds interesting; I'm happy checking out and aiming to review whatever you're interested in working on :-) but Serilog's still a fairly "opinionated" project in some parts, and sometimes even a good change won't be merged if it doesn't fit with the overall direction at the current time.
If you're keen to tackle anything that takes a lot of time and isn't in the issues list with a discussion already, sending a heads-up to make sure we're on the same page first will help things roll along smoothly.
Thanks again for all the PRs, nonetheless!
I just update this PR (Title, Description, Changes) with the performance improvement, and I'll be be extreme happy in updating with any "opinionated" changes.
My goal is just make Seirlog faster then Microsoft Logging again.
But I notice the new Recent changes made on #2058, #2060, #2055, and I will need to look this recent changes another day. And because of that I changed this PR to draft for now.
Recent changes was checked. And here are the Benchmark Results
This is new InitializationBenchmark with the Current Serilog code for CreateLogger for some mix of Sinks, Filters and Properties.
BenchmarkDotNet=v0.13.5, OS=Windows 11 (10.0.22631.3593)
AMD Ryzen 9 3900XT, 1 CPU, 24 logical and 12 physical cores
.NET SDK=8.0.300
[Host] : .NET 8.0.5 (8.0.524.21615), X64 RyuJIT AVX2
DefaultJob : .NET 8.0.5 (8.0.524.21615), X64 RyuJIT AVX2
| Method | NumberOfSinksFiltersAndProps | Mean | Error | StdDev | Gen0 | Gen1 | Allocated |
|---|---|---|---|---|---|---|---|
| CreateLogger | 0 | 907.9 ns | 18.19 ns | 30.88 ns | 0.3567 | 0.0010 | 2.91 KB |
| CreateLogger | 1 | 1,599.8 ns | 31.76 ns | 63.43 ns | 0.4845 | 0.0019 | 3.97 KB |
| CreateLogger | 4 | 2,418.2 ns | 47.55 ns | 89.32 ns | 0.6828 | 0.0038 | 5.6 KB |
| CreateLogger | 100 | 26,328.2 ns | 525.15 ns | 1,298.03 ns | 7.9651 | 0.7019 | 65.25 KB |
And this is the changes added on this PR.
| Method | NumberOfSinksFiltersAndProps | Mean | Error | StdDev | Gen0 | Gen1 | Allocated |
|---|---|---|---|---|---|---|---|
| CreateLogger | 0 | 574.0 ns | 11.27 ns | 12.52 ns | 0.3290 | 0.0010 | 2.69 KB |
| CreateLogger | 1 | 943.3 ns | 10.90 ns | 9.66 ns | 0.4654 | 0.0019 | 3.8 KB |
| CreateLogger | 4 | 1,569.1 ns | 31.43 ns | 72.21 ns | 0.5436 | 0.0038 | 4.45 KB |
| CreateLogger | 100 | 20,079.0 ns | 335.79 ns | 314.09 ns | 4.6387 | 0.4272 | 38.02 KB |
Up to ~35% of improvement and less ~20% allocation, for 4 sinks, filter and properties.
@rafaelsc Will you continue to work on that PR? Changes look good. If not I can continue in my fork and fix review comments and split cosmetic changes from optimizations. @nblumhardt Are you interested in that PR?
@sungam3r thanks for the nudge. We've merged a lot in the last few years; I think most of the remaining ones are stalled or borderline for one reason or another. I'll run through all open issues/PRs this week and send a note on each.
Closing this one as stale; thanks again for all the effort on this.