Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Bump to Serilog v3 #4294

Merged
merged 3 commits into from
Jul 10, 2023
Merged

Bump to Serilog v3 #4294

merged 3 commits into from
Jul 10, 2023

Conversation

bouwkast
Copy link
Contributor

@bouwkast bouwkast commented Jun 21, 2023 •
edited
Loading

Summary of changes

Bump supported version of Serilog to include v3.

Reason for change

New major release of Serilog.

Implementation details

Increased max exclusive version to 4, reran the PackageVersionGenerators Nuke target.

Test coverage

  • Current tests pass
  • Tested out the sample in AutomaticTraceIdInjection with local version of Datadog.Trace and seemed that everything worked.

Other details

Fixes #4287

@datadog-ddstaging
Copy link

datadog-ddstaging bot commented Jun 21, 2023 •
edited
Loading

Datadog Report

Branch report: steven/serilog-v3
Commit report: 786d164

❄️ dd-trace-dotnet: 18 Failed (0 Known Flaky), 1 New Flaky, 292782 Passed, 929 Skipped, 26m 40.19s Wall Time

❌ Failed Tests (18)

This report shows up to 5 failed tests.

  • SubmitsTraces - Datadog.Trace.ClrProfiler.IntegrationTests.OpenTelemetrySdkTests - Details

    Expand for error 
     Result: False
 Span: TraceId: 5235578776846953809, SpanId: 5978269392788512110, Name: MyServiceName.internal, Resource: StartActiveSpan.Child, Service: MyServiceName
 Errors:
 - Expected to have no remaining tags, but the following tags were found: ["telemetry.sdk.name"="opentelemetry","telemetry.sdk.language"="dotnet","telemetry.sdk.version"="1.5.0"]
 Expected: True
 Actual:   False

  • SubmitsTraces - Datadog.Trace.ClrProfiler.IntegrationTests.OpenTelemetrySdkTests - Details

    Expand for error 
     Result: False
 Span: TraceId: 6752295963037476634, SpanId: 13150569626094340184, Name: MyServiceName.internal, Resource: StartActiveSpan.Child, Service: MyServiceName
 Errors:
 - Expected to have no remaining tags, but the following tags were found: ["telemetry.sdk.name"="opentelemetry","telemetry.sdk.language"="dotnet","telemetry.sdk.version"="1.5.0"]
 Expected: True
 Actual:   False

  • SubmitsTraces - Datadog.Trace.ClrProfiler.IntegrationTests.OpenTelemetrySdkTests - Details

    Expand for error 
     Result: False
 Span: TraceId: 18034917453632748510, SpanId: 5777069077615956402, Name: MyServiceName.internal, Resource: StartActiveSpan.Child, Service: MyServiceName
 Errors:
 - Expected to have no remaining tags, but the following tags were found: ["telemetry.sdk.name"="opentelemetry","telemetry.sdk.language"="dotnet","telemetry.sdk.version"="1.5.0"]
 Expected: True
 Actual:   False

  • SubmitsTraces - Datadog.Trace.ClrProfiler.IntegrationTests.OpenTelemetrySdkTests - Details

    Expand for error 
     Result: False
 Span: TraceId: 4386821862850425952, SpanId: 7570525957428767491, Name: MyServiceName.internal, Resource: StartActiveSpan.Child, Service: MyServiceName
 Errors:
 - Expected to have no remaining tags, but the following tags were found: ["telemetry.sdk.name"="opentelemetry","telemetry.sdk.language"="dotnet","telemetry.sdk.version"="1.5.0"]
 Expected: True
 Actual:   False

  • SubmitsTraces - Datadog.Trace.ClrProfiler.IntegrationTests.OpenTelemetrySdkTests - Details

    Expand for error 
     Result: False
 Span: TraceId: 15296030319290329508, SpanId: 4793874332471933315, Name: MyServiceName.internal, Resource: StartActiveSpan.Child, Service: MyServiceName
 Errors:
 - Expected to have no remaining tags, but the following tags were found: ["telemetry.sdk.name"="opentelemetry","telemetry.sdk.language"="dotnet","telemetry.sdk.version"="1.5.0"]
 Expected: True
 Actual:   False

New Flaky Tests (1)

  • CheckEndpointsAreAttached - Datadog.Profiler.IntegrationTests.CodeHotspot.CodeHotspotTest - Last Failure

    Expand for error 
     Expected endpoints.Distinct() to be a collection with 1 item(s), but found an empty collection.
 
 With configuration:
 - Use declared types and members
 - Compare enums by value
 - Include all non-private properties
 - Include all non-private fields
 - Match member by name (or throw)
 - Without automatic conversion.
 - Without automatic conversion.
 ...

@andrewlock

This comment has been minimized.

Sign in to view
@andrewlock

This comment has been minimized.

Sign in to view
@andrewlock

This comment has been minimized.

Sign in to view
@bouwkast bouwkast force-pushed the steven/serilog-v3 branch from 786d164 to c04becd Compare July 5, 2023 18:41
@datadog-ddstaging
Copy link

datadog-ddstaging bot commented Jul 5, 2023 •
edited
Loading

Datadog Report

Branch report: steven/serilog-v3
Commit report: 992f151

✅ dd-trace-dotnet: 0 Failed, 0 New Flaky, 290998 Passed, 1026 Skipped, 32m 30.97s Wall Time

@andrewlock

This comment has been minimized.

Sign in to view
@andrewlock

This comment has been minimized.

Sign in to view
@andrewlock

This comment has been minimized.

Sign in to view
@bouwkast bouwkast marked this pull request as ready for review July 6, 2023 13:15
@bouwkast bouwkast requested review from a team as code owners July 6, 2023 13:15
andrewlock
andrewlock reviewed Jul 6, 2023
View reviewed changes
Copy link
Member

@andrewlock andrewlock left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM in general, thanks! Just one missed update I think. Also, I suggest changing the default package version used in the LogsInjection.Serilog sample to be 3.0.1. On Windows we don't test multiple package versions (yet), so this version bump won't have been covered by the tests

tracer/dependabot/Datadog.Dependabot.Integrations.csproj Outdated
@@ -173,7 +173,7 @@

<!-- Integration: Serilog -->
<!-- Assembly: Serilog -->
<!-- Latest package https://www.nuget.org/packages/Serilog/2.12.0 -->
<!-- Latest package https://www.nuget.org/packages/Serilog/3.0.1 -->
<PackageReference Include="Serilog" Version="2.12.0" />
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I think we need to bump this too?

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Hmm I must've missed this somehow when committing thanks for catching!

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm not entirely sure why, but for some reason this one wasn't being updated by the GeneratePackageVersions so I manually did it

@bouwkast bouwkast force-pushed the steven/serilog-v3 branch from d41326f to 992f151 Compare July 6, 2023 18:28
@andrewlock
Copy link
Member

Execution-Time Benchmarks Report ⏱️

Execution-time results for samples comparing the following branches/commits:

Execution-time benchmarks measure the whole time it takes to execute a program. And are intended to measure the one-off costs. Cases where the execution time results for the PR are worse than latest master results are shown in red. The following thresholds were used for comparing the execution times:

  • Welch test with statistical test for significance of 5%
  • Only results indicating a difference greater than 5% and 5 ms are considered.

Note that these results are based on a single point-in-time result for each branch. For full results, see the dashboard.

Graphs show the p99 interval based on the mean and StdDev of the test run, as well as the mean value of the run (shown as a diamond below the graph).

gantt
    title Execution time (ms) FakeDbCommand (.NET Framework 4.6.2) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4294) - mean (3,026ms)  : 2930, 3122
     .   : milestone, 3026,
    master - mean (3,028ms)  : 2921, 3134
     .   : milestone, 3028,

    section CallTarget+Inlining+NGEN
    This PR (4294) - mean (3,847ms)  : 3756, 3938
     .   : milestone, 3847,
    master - mean (3,848ms)  : 3779, 3916
     .   : milestone, 3848,
Loading 
gantt
    title Execution time (ms) FakeDbCommand (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4294) - mean (3,115ms)  : 2958, 3272
     .   : milestone, 3115,
    master - mean (3,171ms)  : 3039, 3304
     .   : milestone, 3171,

    section CallTarget+Inlining+NGEN
    This PR (4294) - mean (3,655ms)  : 3562, 3748
     .   : milestone, 3655,
    master - mean (3,653ms)  : 3541, 3765
     .   : milestone, 3653,
Loading 
gantt
    title Execution time (ms) FakeDbCommand (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4294) - mean (3,127ms)  : 3005, 3249
     .   : milestone, 3127,
    master - mean (3,101ms)  : 2964, 3238
     .   : milestone, 3101,

    section CallTarget+Inlining+NGEN
    This PR (4294) - mean (3,611ms)  : 3529, 3693
     .   : milestone, 3611,
    master - mean (3,623ms)  : 3534, 3712
     .   : milestone, 3623,
Loading 
gantt
    title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4294) - mean (191ms)  : 187, 196
     .   : milestone, 191,
    master - mean (191ms)  : 187, 194
     .   : milestone, 191,

    section CallTarget+Inlining+NGEN
    This PR (4294) - mean (1,117ms)  : 1086, 1149
     .   : milestone, 1117,
    master - mean (1,115ms)  : 1095, 1135
     .   : milestone, 1115,
Loading 
gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4294) - mean (371ms)  : 365, 378
     .   : milestone, 371,
    master - mean (374ms)  : 368, 380
     .   : milestone, 374,

    section CallTarget+Inlining+NGEN
    This PR (4294) - mean (1,158ms)  : 1131, 1184
     .   : milestone, 1158,
    master - mean (1,173ms)  : 1140, 1206
     .   : milestone, 1173,
Loading 
gantt
    title Execution time (ms) HttpMessageHandler (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4294) - mean (359ms)  : 353, 365
     .   : milestone, 359,
    master - mean (363ms)  : 355, 371
     .   : milestone, 363,

    section CallTarget+Inlining+NGEN
    This PR (4294) - mean (1,125ms)  : 1095, 1154
     .   : milestone, 1125,
    master - mean (1,128ms)  : 1103, 1154
     .   : milestone, 1128,
Loading

@andrewlock
Copy link
Member

Benchmarks Report 🐌

Benchmarks for #4294 compared to master:

  • 4 benchmarks are faster, with geometric mean 1.121
  • 1 benchmarks are slower, with geometric mean 1.168
  • 1 benchmarks have more allocations

The following thresholds were used for comparing the benchmark speeds:

  • Mann–Whitney U test with statistical test for significance of 5%
  • Only results indicating a difference greater than 10% and 0.3 ns are considered.

Allocation changes below 0.5% are ignored.

Benchmark details

Benchmarks.Trace.AgentWriterBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net6.0 482μs 256ns 993ns 0 0 0 2.62 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 642μs 199ns 745ns 0 0 0 2.63 KB
master WriteAndFlushEnrichedTraces net472 809μs 633ns 2.45μs 0.403 0 0 3.22 KB
#4294 WriteAndFlushEnrichedTraces net6.0 485μs 169ns 631ns 0 0 0 2.62 KB
#4294 WriteAndFlushEnrichedTraces netcoreapp3.1 650μs 181ns 654ns 0 0 0 2.63 KB
#4294 WriteAndFlushEnrichedTraces net472 815μs 274ns 1.02μs 0.398 0 0 3.22 KB
Benchmarks.Trace.AppSecBodyBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master AllCycleSimpleBody net6.0 41μs 113ns 438ns 0.0208 0 0 1.65 KB
master AllCycleSimpleBody netcoreapp3.1 41.4μs 47.5ns 184ns 0.0205 0 0 1.63 KB
master AllCycleSimpleBody net472 41.7μs 8.42ns 30.3ns 0.255 0 0 1.69 KB
master AllCycleMoreComplexBody net6.0 223μs 152ns 589ns 0.111 0 0 9.22 KB
master AllCycleMoreComplexBody netcoreapp3.1 230μs 225ns 840ns 0.115 0 0 9.12 KB
master AllCycleMoreComplexBody net472 240μs 89.7ns 347ns 1.44 0 0 9.28 KB
master ObjectExtractorSimpleBody net6.0 117ns 0.044ns 0.165ns 0.00391 0 0 280 B
master ObjectExtractorSimpleBody netcoreapp3.1 176ns 0.062ns 0.232ns 0.00373 0 0 272 B
master ObjectExtractorSimpleBody net472 149ns 0.0972ns 0.376ns 0.0446 0 0 281 B
master ObjectExtractorMoreComplexBody net6.0 3.04μs 0.869ns 3.25ns 0.0547 0 0 3.88 KB
master ObjectExtractorMoreComplexBody netcoreapp3.1 4.27μs 1.29ns 4.82ns 0.0511 0 0 3.78 KB
master ObjectExtractorMoreComplexBody net472 4.18μs 2.95ns 11.4ns 0.618 0.00626 0 3.89 KB
#4294 AllCycleSimpleBody net6.0 38.7μs 18.7ns 67.3ns 0.02 0 0 1.65 KB
#4294 AllCycleSimpleBody netcoreapp3.1 40.9μs 36.4ns 131ns 0.0204 0 0 1.63 KB
#4294 AllCycleSimpleBody net472 41μs 7.83ns 27.1ns 0.268 0 0 1.69 KB
#4294 AllCycleMoreComplexBody net6.0 221μs 111ns 414ns 0.11 0 0 9.22 KB
#4294 AllCycleMoreComplexBody netcoreapp3.1 231μs 87.7ns 340ns 0.114 0 0 9.12 KB
#4294 AllCycleMoreComplexBody net472 239μs 189ns 732ns 1.43 0 0 9.28 KB
#4294 ObjectExtractorSimpleBody net6.0 126ns 0.038ns 0.142ns 0.00396 0 0 280 B
#4294 ObjectExtractorSimpleBody netcoreapp3.1 196ns 0.427ns 1.65ns 0.00376 0 0 272 B
#4294 ObjectExtractorSimpleBody net472 144ns 0.0901ns 0.337ns 0.0446 0 0 281 B
#4294 ObjectExtractorMoreComplexBody net6.0 3.05μs 0.931ns 3.36ns 0.0549 0 0 3.88 KB
#4294 ObjectExtractorMoreComplexBody netcoreapp3.1 4.02μs 1.56ns 5.82ns 0.0503 0 0 3.78 KB
#4294 ObjectExtractorMoreComplexBody net472 4.12μs 2.99ns 11.6ns 0.618 0.00616 0 3.89 KB
Benchmarks.Trace.AspNetCoreBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendRequest net6.0 166μs 98.2ns 368ns 0.165 0 0 18.03 KB
master SendRequest netcoreapp3.1 186μs 209ns 782ns 0.187 0 0 20.09 KB
master SendRequest net472 0ns 0ns 0ns 0 0 0 0 b
#4294 SendRequest net6.0 169μs 60.1ns 225ns 0.252 0 0 18.03 KB
#4294 SendRequest netcoreapp3.1 191μs 286ns 1.11μs 0.191 0 0 20.09 KB
#4294 SendRequest net472 0ns 0ns 0ns 0 0 0 0 b
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Same speed ✔️ More allocations ⚠️

More allocations ⚠️ in #4294

Benchmark Base Allocated Diff Allocated Change Change %
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑net6.0 41.58 KB 41.82 KB 244 B 0.59%

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net6.0 533μs 1.92μs 7.42μs 0.514 0 0 41.58 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 637μs 2.38μs 9.23μs 0.317 0 0 41.78 KB
master WriteAndFlushEnrichedTraces net472 781μs 2.94μs 11.4μs 8.36 2.39 0.398 53.23 KB
#4294 WriteAndFlushEnrichedTraces net6.0 541μs 743ns 2.78μs 0.502 0 0 41.82 KB
#4294 WriteAndFlushEnrichedTraces netcoreapp3.1 635μs 2.09μs 8.08μs 0.347 0 0 41.67 KB
#4294 WriteAndFlushEnrichedTraces net472 774μs 3.19μs 11.5μs 8.2 2.34 0.391 53.23 KB
Benchmarks.Trace.DbCommandBenchmark - Faster 🎉 Same allocations ✔️

Faster 🎉 in #4294

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.DbCommandBenchmark.ExecuteNonQuery‑netcoreapp3.1 1.115 1,205.63 1,081.06
Benchmarks.Trace.DbCommandBenchmark.ExecuteNonQuery‑net6.0 1.114 886.31 795.35

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteNonQuery net6.0 886ns 0.308ns 1.19ns 0.0103 0 0 720 B
master ExecuteNonQuery netcoreapp3.1 1.21μs 0.307ns 1.19ns 0.00955 0 0 720 B
master ExecuteNonQuery net472 1.44μs 1.13ns 4.21ns 0.108 0.000714 0 682 B
#4294 ExecuteNonQuery net6.0 795ns 0.289ns 1.12ns 0.00992 0 0 720 B
#4294 ExecuteNonQuery netcoreapp3.1 1.08μs 0.428ns 1.66ns 0.00956 0 0 720 B
#4294 ExecuteNonQuery net472 1.37μs 0.671ns 2.6ns 0.108 0 0 682 B
Benchmarks.Trace.ElasticsearchBenchmark - Faster 🎉 Same allocations ✔️

Faster 🎉 in #4294

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.ElasticsearchBenchmark.CallElasticsearchAsync‑net6.0 1.130 1,213.18 1,074.01

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master CallElasticsearch net6.0 1.15μs 0.641ns 2.48ns 0.0132 0 0 944 B
master CallElasticsearch netcoreapp3.1 1.25μs 0.473ns 1.83ns 0.0125 0 0 944 B
master CallElasticsearch net472 1.96μs 0.619ns 2.32ns 0.151 0.000981 0 955 B
master CallElasticsearchAsync net6.0 1.21μs 0.379ns 1.47ns 0.0127 0 0 920 B
master CallElasticsearchAsync netcoreapp3.1 1.37μs 0.697ns 2.51ns 0.0131 0 0 992 B
master CallElasticsearchAsync net472 2.08μs 0.472ns 1.83ns 0.16 0 0 1.01 KB
#4294 CallElasticsearch net6.0 1.07μs 0.43ns 1.67ns 0.0129 0 0 944 B
#4294 CallElasticsearch netcoreapp3.1 1.17μs 0.441ns 1.71ns 0.0125 0 0 944 B
#4294 CallElasticsearch net472 2.04μs 0.723ns 2.71ns 0.151 0.00102 0 955 B
#4294 CallElasticsearchAsync net6.0 1.07μs 0.314ns 1.18ns 0.0129 0 0 920 B
#4294 CallElasticsearchAsync netcoreapp3.1 1.32μs 0.453ns 1.75ns 0.0132 0 0 992 B
#4294 CallElasticsearchAsync net472 2.23μs 0.732ns 2.74ns 0.161 0.00111 0 1.01 KB
Benchmarks.Trace.GraphQLBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteAsync net6.0 1.14μs 0.276ns 1.03ns 0.0126 0 0 912 B
master ExecuteAsync netcoreapp3.1 1.38μs 0.905ns 3.26ns 0.0125 0 0 912 B
master ExecuteAsync net472 1.5μs 0.383ns 1.43ns 0.139 0.000743 0 875 B
#4294 ExecuteAsync net6.0 1.17μs 0.561ns 2.1ns 0.0124 0 0 912 B
#4294 ExecuteAsync netcoreapp3.1 1.4μs 1.17ns 4.36ns 0.0126 0 0 912 B
#4294 ExecuteAsync net472 1.45μs 0.442ns 1.65ns 0.139 0 0 875 B
Benchmarks.Trace.HttpClientBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendAsync net6.0 3.74μs 0.783ns 2.82ns 0.0261 0 0 1.9 KB
master SendAsync netcoreapp3.1 4.35μs 1.79ns 6.69ns 0.0326 0 0 2.43 KB
master SendAsync net472 6.91μs 2.59ns 9.68ns 0.474 0 0 3 KB
#4294 SendAsync net6.0 3.63μs 1.49ns 5.56ns 0.0252 0 0 1.9 KB
#4294 SendAsync netcoreapp3.1 4.27μs 2.49ns 9.32ns 0.0321 0 0 2.43 KB
#4294 SendAsync net472 6.95μs 2.06ns 7.96ns 0.475 0 0 3 KB
Benchmarks.Trace.ILoggerBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net6.0 1.33μs 0.619ns 2.4ns 0.0226 0 0 1.62 KB
master EnrichedLog netcoreapp3.1 1.94μs 0.721ns 2.7ns 0.0222 0 0 1.62 KB
master EnrichedLog net472 2.48μs 1.09ns 4.21ns 0.244 0 0 1.54 KB
#4294 EnrichedLog net6.0 1.4μs 0.773ns 2.89ns 0.0229 0 0 1.62 KB
#4294 EnrichedLog netcoreapp3.1 2.15μs 1.35ns 5.05ns 0.0215 0 0 1.62 KB
#4294 EnrichedLog net472 2.39μs 1.24ns 4.8ns 0.244 0 0 1.54 KB
Benchmarks.Trace.Log4netBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net6.0 111μs 91.7ns 355ns 0.0555 0 0 4.21 KB
master EnrichedLog netcoreapp3.1 116μs 119ns 462ns 0.0579 0 0 4.21 KB
master EnrichedLog net472 147μs 57.6ns 223ns 0.663 0.221 0 4.38 KB
#4294 EnrichedLog net6.0 111μs 85.7ns 332ns 0.0552 0 0 4.21 KB
#4294 EnrichedLog netcoreapp3.1 117μs 119ns 445ns 0.0581 0 0 4.21 KB
#4294 EnrichedLog net472 149μs 101ns 392ns 0.675 0.225 0 4.38 KB
Benchmarks.Trace.NLogBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net6.0 3.1μs 0.696ns 2.51ns 0.0528 0 0 3.71 KB
master EnrichedLog netcoreapp3.1 4.01μs 1.91ns 7.14ns 0.0511 0 0 3.69 KB
master EnrichedLog net472 4.93μs 1.82ns 6.8ns 0.526 0.00246 0 3.31 KB
#4294 EnrichedLog net6.0 3.14μs 1.22ns 4.72ns 0.053 0 0 3.71 KB
#4294 EnrichedLog netcoreapp3.1 3.9μs 1.48ns 5.54ns 0.0504 0 0 3.69 KB
#4294 EnrichedLog net472 4.83μs 1.03ns 3.97ns 0.526 0.00241 0 3.31 KB
Benchmarks.Trace.RedisBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendReceive net6.0 1.11μs 0.447ns 1.73ns 0.0155 0 0 1.11 KB
master SendReceive netcoreapp3.1 1.44μs 0.824ns 3.19ns 0.0152 0 0 1.11 KB
master SendReceive net472 1.74μs 0.897ns 3.47ns 0.177 0.000875 0 1.12 KB
#4294 SendReceive net6.0 1.12μs 0.531ns 1.99ns 0.0155 0 0 1.11 KB
#4294 SendReceive netcoreapp3.1 1.53μs 0.485ns 1.82ns 0.0153 0 0 1.11 KB
#4294 SendReceive net472 1.76μs 0.596ns 2.31ns 0.177 0 0 1.12 KB
Benchmarks.Trace.SerilogBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net6.0 2.47μs 0.722ns 2.7ns 0.021 0 0 1.53 KB
master EnrichedLog netcoreapp3.1 3.76μs 3.25ns 12.6ns 0.0206 0 0 1.58 KB
master EnrichedLog net472 4.11μs 1.17ns 4.22ns 0.31 0 0 1.96 KB
#4294 EnrichedLog net6.0 2.43μs 1.14ns 4.42ns 0.0218 0 0 1.53 KB
#4294 EnrichedLog netcoreapp3.1 3.56μs 1.68ns 6.3ns 0.0214 0 0 1.58 KB
#4294 EnrichedLog net472 4.06μs 1.16ns 4.49ns 0.309 0 0 1.96 KB
Benchmarks.Trace.SpanBenchmark - Slower ⚠️ Same allocations ✔️

Slower ⚠️ in #4294

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.SpanBenchmark.StartFinishSpan‑net472 1.168 598.11 698.75

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartFinishSpan net6.0 416ns 0.191ns 0.738ns 0.00742 0 0 536 B
master StartFinishSpan netcoreapp3.1 538ns 0.343ns 1.19ns 0.00726 0 0 536 B
master StartFinishSpan net472 598ns 0.695ns 2.6ns 0.0854 0 0 538 B
master StartFinishScope net6.0 532ns 0.2ns 0.747ns 0.00917 0 0 656 B
master StartFinishScope netcoreapp3.1 664ns 0.607ns 2.27ns 0.00874 0 0 656 B
master StartFinishScope net472 849ns 0.84ns 3.25ns 0.0978 0 0 618 B
#4294 StartFinishSpan net6.0 399ns 0.16ns 0.599ns 0.00758 0 0 536 B
#4294 StartFinishSpan netcoreapp3.1 525ns 2.99ns 20.3ns 0.00716 0 0 536 B
#4294 StartFinishSpan net472 699ns 0.285ns 1.03ns 0.0853 0 0 538 B
#4294 StartFinishScope net6.0 521ns 0.191ns 0.739ns 0.00907 0 0 656 B
#4294 StartFinishScope netcoreapp3.1 680ns 0.377ns 1.46ns 0.00882 0 0 656 B
#4294 StartFinishScope net472 781ns 0.4ns 1.55ns 0.0981 0 0 618 B
Benchmarks.Trace.TraceAnnotationsBenchmark - Faster 🎉 Same allocations ✔️

Faster 🎉 in #4294

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.TraceAnnotationsBenchmark.RunOnMethodBegin‑net472 1.124 1,021.90 908.84

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master RunOnMethodBegin net6.0 548ns 0.258ns 0.999ns 0.00909 0 0 656 B
master RunOnMethodBegin netcoreapp3.1 814ns 2.2ns 8.52ns 0.00889 0 0 656 B
master RunOnMethodBegin net472 1.02μs 0.304ns 1.18ns 0.098 0 0 618 B
#4294 RunOnMethodBegin net6.0 561ns 0.14ns 0.504ns 0.00932 0 0 656 B
#4294 RunOnMethodBegin netcoreapp3.1 790ns 0.21ns 0.787ns 0.00882 0 0 656 B
#4294 RunOnMethodBegin net472 911ns 1.1ns 4.26ns 0.0981 0 0 618 B

pierotibou
pierotibou reviewed Jul 6, 2023
View reviewed changes
Copy link
Collaborator

@pierotibou pierotibou left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

As it's a new major, don't you need to update the logs injection and direct logs submission integration?

Honestly i'm even surprised the tests pass if we haven't updated the integrations (unless I'm missing something obvious which is often the case lately)

@bouwkast
Copy link
Contributor Author

bouwkast commented Jul 6, 2023

As it's a new major, don't you need to update the logs injection and direct logs submission integration?

Honestly i'm even surprised the tests pass if we haven't updated the integrations (unless I'm missing something obvious which is often the case lately)

Hmm yeah good catch

@andrewlock
Copy link
Member

Throughput/Crank Report:zap:

Throughput results for AspNetCoreSimpleController comparing the following branches/commits:

Cases where throughput results for the PR are worse than latest master (5% drop or greater), results are shown in red.

Note that these results are based on a single point-in-time result for each branch. For full results, see one of the many, many dashboards!

gantt
    title Throughput Linux x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (4294) (10.999M)   : 0, 10998866
    master (11.042M)   : 0, 11042376
    benchmarks/2.33.0 (11.213M)   : 0, 11212993
    benchmarks/2.9.0 (11.118M)   : 0, 11117516

    section Automatic
    This PR (4294) (7.616M)   : 0, 7616078
    master (7.609M)   : 0, 7608558
    benchmarks/2.33.0 (7.578M)   : 0, 7577833
    benchmarks/2.9.0 (8.218M)   : 0, 8217621

    section Trace stats
    master (7.500M)   : 0, 7499806
    benchmarks/2.33.0 (7.586M)   : 0, 7586413

    section Manual
    This PR (4294) (9.916M)   : 0, 9916030
    master (9.763M)   : 0, 9763284
    benchmarks/2.33.0 (10.050M)   : 0, 10049682

    section Manual + Automatic
    This PR (4294) (7.315M)   : 0, 7314726
    master (7.362M)   : 0, 7362242
    benchmarks/2.33.0 (7.461M)   : 0, 7461071

    section Version Conflict
    master (6.572M)   : 0, 6571573
    benchmarks/2.33.0 (6.706M)   : 0, 6705768
Loading 
gantt
    title Throughput Linux arm64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (4294) (9.658M)   : 0, 9657923
    benchmarks/2.33.0 (9.854M)   : 0, 9854380
    benchmarks/2.9.0 (9.560M)   : 0, 9560344

    section Automatic
    This PR (4294) (6.755M)   : 0, 6754524
    benchmarks/2.33.0 (6.781M)   : 0, 6781408

    section Trace stats
    benchmarks/2.33.0 (6.876M)   : 0, 6875549

    section Manual
    This PR (4294) (8.478M)   : 0, 8478214
    benchmarks/2.33.0 (8.659M)   : 0, 8658618

    section Manual + Automatic
    This PR (4294) (6.464M)   : 0, 6463689
    benchmarks/2.33.0 (6.364M)   : 0, 6364163

    section Version Conflict
    benchmarks/2.33.0 (5.865M)   : 0, 5865173
Loading 
gantt
    title Throughput Windows x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (4294) (10.590M)   : 0, 10589853
    master (10.421M)   : 0, 10420533
    benchmarks/2.33.0 (10.579M)   : 0, 10578933
    benchmarks/2.9.0 (10.207M)   : 0, 10206911

    section Automatic
    This PR (4294) (7.690M)   : 0, 7689514
    master (7.772M)   : 0, 7772237
    benchmarks/2.33.0 (7.457M)   : 0, 7457212
    benchmarks/2.9.0 (7.491M)   : 0, 7491408

    section Trace stats
    master (7.659M)   : 0, 7658863
    benchmarks/2.33.0 (7.471M)   : 0, 7470661

    section Manual
    This PR (4294) (9.459M)   : 0, 9459307
    master (9.755M)   : 0, 9754911
    benchmarks/2.33.0 (9.168M)   : 0, 9167980

    section Manual + Automatic
    This PR (4294) (7.465M)   : 0, 7465455
    master (7.596M)   : 0, 7595798
    benchmarks/2.33.0 (7.048M)   : 0, 7048019

    section Version Conflict
    master (6.783M)   : 0, 6783176
    benchmarks/2.33.0 (6.484M)   : 0, 6483597
Loading 
gantt
    title Throughput Linux x64 (ASM) (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (4294) (7.679M)   : 0, 7678915
    master (7.802M)   : 0, 7801575
    benchmarks/2.33.0 (7.894M)   : 0, 7894351
    benchmarks/2.9.0 (8.085M)   : 0, 8085159

    section No attack
    This PR (4294) (2.198M)   : 0, 2197837
    master (2.231M)   : 0, 2231481
    benchmarks/2.33.0 (2.233M)   : 0, 2232790
    benchmarks/2.9.0 (3.354M)   : 0, 3353571

    section Attack
    This PR (4294) (1.908M)   : 0, 1907840
    master (1.917M)   : 0, 1916621
    benchmarks/2.33.0 (1.937M)   : 0, 1937400
    benchmarks/2.9.0 (2.567M)   : 0, 2566556

    section Blocking
    This PR (4294) (3.841M)   : 0, 3840807
    master (3.863M)   : 0, 3863430
    benchmarks/2.33.0 (3.859M)   : 0, 3859464
Loading

@andrewlock
Copy link
Member

As it's a new major, don't you need to update the logs injection and direct logs submission integration?

Honestly i'm even surprised the tests pass if we haven't updated the integrations (unless I'm missing something obvious which is often the case lately)

@pierotibou @bouwkast luckily(?) Serilog kept the same assembly version at 2.0.0 (presumably for compatibility reasons)

image

I'm a bit surprised, but it's hard to find the reasoning in the serilog repo, so can't be certain it won't change in a point release, but seems safe for now

Confirmed we're definitely running those tests in ciapp

image

andrewlock
andrewlock approved these changes Jul 7, 2023
View reviewed changes
Copy link
Member

@andrewlock andrewlock left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

LGTM, thanks! 🙂

pierotibou
pierotibou approved these changes Jul 7, 2023
View reviewed changes
Copy link
Collaborator

@pierotibou pierotibou left a comment •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Thanks Andrew for checking and @bouwkast for doing the change obviously

@andrewlock
Copy link
Member

However, there's an elephant in the room here... the linked issue implies this doesn't currently work... but the tests done here suggest that it should work with our existing releases 😕 #4287 (comment)

@bouwkast
Copy link
Contributor Author

bouwkast commented Jul 7, 2023

However, there's an elephant in the room here... the linked issue implies this doesn't currently work... but the tests done here suggest that it should work with our existing releases 😕 #4287 (comment)

So I just tested updating to Serilog 3.0.1 in the AutomaticTraceIdInjection samples with version 2.33.0 of the bundle NuGet and it all seems to work

I also think if the assembly version is still 2.0.0 we probably don't want to bump the supported here to 3.*.* as we might not actually support that if/when the assembly version gets increased.?

@andrewlock
Copy link
Member

So I just tested updating to Serilog 3.0.1 in the AutomaticTraceIdInjection samples with version 2.33.0 of the bundle NuGet and it all seems to work

Awesome, that's what we expected then, so this PR all makes sense 👍

I also think if the assembly version is still 2.0.0 we probably don't want to bump the supported here to 3.. as we might not actually support that if/when the assembly version gets increased.?

Yup, completely agree, we shouldn't bump it unless we need to, this is good to go :shipit: 🚀 🎉

@bouwkast bouwkast merged commit 29d76f1 into master Jul 10, 2023
@bouwkast bouwkast deleted the steven/serilog-v3 branch July 10, 2023 19:37
@github-actions github-actions bot added this to the vNext milestone Jul 10, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@pierotibou pierotibou pierotibou approved these changes

@andrewlock andrewlock andrewlock approved these changes

Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
2.34.0
Development

Successfully merging this pull request may close these issues.

Support Serilog v3.0.0
3 participants
@bouwkast @andrewlock @pierotibou