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

Don't send some error logs to telemetry #4934

Merged
merged 6 commits into from
Nov 30, 2023
Merged

Don't send some error logs to telemetry #4934

merged 6 commits into from
Nov 30, 2023

Conversation

andrewlock
Copy link
Member

@andrewlock andrewlock commented Nov 28, 2023 •
edited
Loading

Summary of changes

Skips sending some error logs to telemetry

Reason for change

We generate a lot of these specific errors, they're not necessarily actionable for us (though they are for customers), and we don't want to record them in telemetry.

Implementation details

Add a filter to the telemetry sink to filter out specific known message templates.

We don't anticipate needing to use this a lot - it's purely for messages we want to be flagged as errors explicitly for customers, but we don't want to see. For anything that's not actionable by the customer, we should generally use a lower-level log message.

Test coverage

Added a unit test to confirm it behaves as expected

Other details

In the original implementation I just downgraded the logs to Warning, but @bouwkast rightly pointed out we probably shouldn't do that, hence the revert 🙂

@andrewlock andrewlock added area:tracer The core tracer library (Datadog.Trace, does not include OpenTracing, native code, or integrations) type:cleanup Minor code clean up labels Nov 28, 2023
@andrewlock andrewlock requested a review from a team as a code owner November 28, 2023 13:12
@datadog-ddstaging
Copy link

datadog-ddstaging bot commented Nov 28, 2023 •
edited
Loading

Datadog Report

Branch report: andrew/downgrade-warnings
Commit report: 4a263b0

✅ dd-trace-dotnet: 0 Failed, 0 New Flaky, 304840 Passed, 954 Skipped, 30m 59.19s Wall Time

@andrewlock
Copy link
Member Author

andrewlock commented Nov 28, 2023 •
edited
Loading

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 (4934) - mean (70ms)  : 62, 79
     .   : milestone, 70,
    master - mean (71ms)  : 63, 79
     .   : milestone, 71,

    section CallTarget+Inlining+NGEN
    This PR (4934) - mean (1,000ms)  : 977, 1023
     .   : milestone, 1000,
    master - mean (995ms)  : 979, 1012
     .   : milestone, 995,
Loading 
gantt
    title Execution time (ms) FakeDbCommand (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4934) - mean (106ms)  : 102, 109
     .   : milestone, 106,
    master - mean (106ms)  : 103, 109
     .   : milestone, 106,

    section CallTarget+Inlining+NGEN
    This PR (4934) - mean (688ms)  : 669, 706
     .   : milestone, 688,
    master - mean (690ms)  : 672, 707
     .   : milestone, 690,
Loading 
gantt
    title Execution time (ms) FakeDbCommand (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4934) - mean (90ms)  : 88, 92
     .   : milestone, 90,
    master - mean (90ms)  : 86, 94
     .   : milestone, 90,

    section CallTarget+Inlining+NGEN
    This PR (4934) - mean (661ms)  : 638, 684
     .   : milestone, 661,
    master - mean (662ms)  : 636, 687
     .   : milestone, 662,
Loading 
gantt
    title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4934) - mean (189ms)  : 186, 191
     .   : milestone, 189,
    master - mean (189ms)  : 186, 192
     .   : milestone, 189,

    section CallTarget+Inlining+NGEN
    This PR (4934) - mean (1,138ms)  : 1118, 1158
     .   : milestone, 1138,
    master - mean (1,137ms)  : 1117, 1158
     .   : milestone, 1137,
Loading 
gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4934) - mean (273ms)  : 269, 276
     .   : milestone, 273,
    master - mean (273ms)  : 269, 277
     .   : milestone, 273,

    section CallTarget+Inlining+NGEN
    This PR (4934) - mean (1,090ms)  : 1068, 1113
     .   : milestone, 1090,
    master - mean (1,096ms)  : 1069, 1122
     .   : milestone, 1096,
Loading 
gantt
    title Execution time (ms) HttpMessageHandler (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4934) - mean (261ms)  : 258, 265
     .   : milestone, 261,
    master - mean (262ms)  : 259, 265
     .   : milestone, 262,

    section CallTarget+Inlining+NGEN
    This PR (4934) - mean (1,057ms)  : 1032, 1082
     .   : milestone, 1057,
    master - mean (1,065ms)  : 1045, 1086
     .   : milestone, 1065,
Loading

@andrewlock
Copy link
Member Author

andrewlock commented Nov 28, 2023 •
edited
Loading

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 (4934) (10.830M)   : 0, 10829693
    master (11.333M)   : 0, 11332518
    benchmarks/2.9.0 (11.258M)   : 0, 11257868

    section Automatic
    This PR (4934) (7.555M)   : 0, 7555278
    master (7.657M)   : 0, 7657438
    benchmarks/2.9.0 (8.046M)   : 0, 8046105

    section Trace stats
    This PR (4934) (7.958M)   : 0, 7957702
    master (8.054M)   : 0, 8053668

    section Manual
    This PR (4934) (9.670M)   : 0, 9670242
    master (10.004M)   : 0, 10003794

    section Manual + Automatic
    This PR (4934) (7.141M)   : 0, 7141171
    master (7.437M)   : 0, 7436536

    section Version Conflict
    This PR (4934) (6.323M)   : crit ,0, 6323120
    master (6.771M)   : 0, 6770626
Loading 
gantt
    title Throughput Linux arm64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (4934) (9.491M)   : 0, 9491147
    master (9.642M)   : 0, 9641863
    benchmarks/2.9.0 (9.571M)   : 0, 9571091

    section Automatic
    This PR (4934) (6.555M)   : 0, 6555494
    master (6.503M)   : 0, 6503245

    section Trace stats
    This PR (4934) (6.901M)   : 0, 6901141
    master (6.987M)   : 0, 6987377

    section Manual
    This PR (4934) (8.310M)   : 0, 8310105
    master (8.537M)   : 0, 8536637

    section Manual + Automatic
    This PR (4934) (6.127M)   : 0, 6127042
    master (6.089M)   : 0, 6089321

    section Version Conflict
    This PR (4934) (5.762M)   : 0, 5762333
    master (5.724M)   : 0, 5723643
Loading 
gantt
    title Throughput Windows x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (4934) (10.392M)   : 0, 10391626
    master (10.254M)   : 0, 10253707
    benchmarks/2.9.0 (8.981M)   : 0, 8981100

    section Automatic
    This PR (4934) (7.400M)   : 0, 7399638
    master (6.421M)   : 0, 6420836
    benchmarks/2.9.0 (6.621M)   : 0, 6621015

    section Trace stats
    This PR (4934) (7.699M)   : 0, 7699220
    master (6.589M)   : 0, 6589319

    section Manual
    This PR (4934) (9.358M)   : 0, 9357851
    master (7.901M)   : 0, 7900787

    section Manual + Automatic
    This PR (4934) (7.056M)   : 0, 7056057
    master (6.157M)   : 0, 6157174

    section Version Conflict
    This PR (4934) (6.395M)   : 0, 6395109
    master (5.598M)   : 0, 5598196
Loading 
gantt
    title Throughput Linux x64 (ASM) (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    master (7.353M)   : 0, 7352773
    benchmarks/2.9.0 (7.805M)   : 0, 7805126

    section No attack
    master (1.971M)   : 0, 1971063
    benchmarks/2.9.0 (3.177M)   : 0, 3177224

    section Attack
    master (1.553M)   : 0, 1553355
    benchmarks/2.9.0 (2.505M)   : 0, 2504790

    section Blocking
    master (3.237M)   : 0, 3236693

    section IAST default
    master (6.655M)   : 0, 6654796

    section IAST full
    master (5.949M)   : 0, 5949094

    section Base vuln
    master (0.974M)   : 0, 974472

    section IAST vuln
    master (0.921M)   : 0, 920725
Loading

bouwkast
bouwkast reviewed Nov 28, 2023
View reviewed changes
Copy link
Contributor

@bouwkast bouwkast left a comment

Choose a reason for hiding this comment

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

I think they should stay as Error as they are actual errors that are either limiting some functionality or requiring some user intervention.
So I think filtering would probably be the better route.

I haven't really looked much into performance of the filtering, but maybe pushing a property (LogContext.PushProperty) and filtering by that would be more performant than by searching text?

@andrewlock
Copy link
Member Author

So I think filtering would probably be the better route.

I haven't really looked much into performance of the filtering, but maybe pushing a property (LogContext.PushProperty) and filtering by that would be more performant than by searching text?

Thanks for the feedback, as I was writing the PR description I was coming to that way of thinking too!

RE LogContext.PushProperty, it's a nice idea, but I think it's probably not worth the hassle tbh. You'd have to remember to do the push and pop at the callsite + it would allocate so meh 😄 Theoretically we shouldn't have too many errors and I assume the sink filters by level first, so maybe it wouldn't be a big deal 🤔 Ordinal searches are vectorized on newer fx/chips too, so that would speed it up even more 🤷‍♂️ Either way, it's something we could address later if that's the way we want to go 🙂 In fact, given these are fixed string templates, we can presumably make them constants and do a ReferenceEquals comparison! 🤔

@andrewlock
Copy link
Member Author

andrewlock commented Nov 28, 2023 •
edited
Loading

Benchmarks Report 🐌

Benchmarks for #4934 compared to master:

  • 2 benchmarks are faster, with geometric mean 1.331
  • 4 benchmarks are slower, with geometric mean 1.210
  • 1 benchmarks have fewer 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.ActivityBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartStopWithChild net6.0 8.59μs 44.4ns 213ns 0.0265 0.00882 0 7.48 KB
master StartStopWithChild netcoreapp3.1 10.7μs 51.9ns 226ns 0.0266 0.0106 0 7.58 KB
master StartStopWithChild net472 16.9μs 36.8ns 138ns 1.32 0.319 0.109 7.95 KB
#4934 StartStopWithChild net6.0 8.62μs 46.9ns 277ns 0.0242 0.0121 0 7.48 KB
#4934 StartStopWithChild netcoreapp3.1 10.6μs 58ns 343ns 0.0308 0.0154 0 7.58 KB
#4934 StartStopWithChild net472 17.1μs 50ns 194ns 1.34 0.364 0.11 7.95 KB
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 465μs 272ns 980ns 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 632μs 174ns 653ns 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces net472 775μs 408ns 1.58μs 0.386 0 0 3.3 KB
#4934 WriteAndFlushEnrichedTraces net6.0 471μs 308ns 1.07μs 0 0 0 2.7 KB
#4934 WriteAndFlushEnrichedTraces netcoreapp3.1 657μs 636ns 2.38μs 0 0 0 2.7 KB
#4934 WriteAndFlushEnrichedTraces net472 796μs 378ns 1.46μs 0.396 0 0 3.3 KB
Benchmarks.Trace.Asm.AppSecBodyBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master AllCycleSimpleBody net6.0 43.5μs 12.5ns 46.8ns 0.0217 0 0 1.77 KB
master AllCycleSimpleBody netcoreapp3.1 46.1μs 31.2ns 121ns 0.0232 0 0 1.74 KB
master AllCycleSimpleBody net472 49.5μs 25.9ns 100ns 0.268 0 0 1.81 KB
master AllCycleMoreComplexBody net6.0 213μs 335ns 1.3μs 0.106 0 0 9.25 KB
master AllCycleMoreComplexBody netcoreapp3.1 224μs 253ns 981ns 0.111 0 0 9.14 KB
master AllCycleMoreComplexBody net472 235μs 73.1ns 274ns 1.41 0 0 9.32 KB
master ObjectExtractorSimpleBody net6.0 134ns 0.0407ns 0.152ns 0.00395 0 0 280 B
master ObjectExtractorSimpleBody netcoreapp3.1 186ns 0.0658ns 0.246ns 0.00367 0 0 272 B
master ObjectExtractorSimpleBody net472 153ns 0.175ns 0.677ns 0.0446 0 0 281 B
master ObjectExtractorMoreComplexBody net6.0 2.75μs 1.38ns 5.15ns 0.0526 0 0 3.78 KB
master ObjectExtractorMoreComplexBody netcoreapp3.1 3.72μs 1.63ns 6.3ns 0.0502 0 0 3.69 KB
master ObjectExtractorMoreComplexBody net472 3.5μs 2.52ns 9.77ns 0.602 0.00695 0 3.8 KB
#4934 AllCycleSimpleBody net6.0 44.2μs 25.2ns 94.2ns 0.0221 0 0 1.77 KB
#4934 AllCycleSimpleBody netcoreapp3.1 46.2μs 56.8ns 220ns 0.0227 0 0 1.74 KB
#4934 AllCycleSimpleBody net472 49.1μs 129ns 500ns 0.266 0 0 1.81 KB
#4934 AllCycleMoreComplexBody net6.0 215μs 98.8ns 370ns 0.108 0 0 9.25 KB
#4934 AllCycleMoreComplexBody netcoreapp3.1 227μs 150ns 542ns 0.113 0 0 9.14 KB
#4934 AllCycleMoreComplexBody net472 236μs 118ns 442ns 1.42 0 0 9.32 KB
#4934 ObjectExtractorSimpleBody net6.0 131ns 0.0647ns 0.242ns 0.00393 0 0 280 B
#4934 ObjectExtractorSimpleBody netcoreapp3.1 186ns 0.108ns 0.42ns 0.00371 0 0 272 B
#4934 ObjectExtractorSimpleBody net472 152ns 0.149ns 0.578ns 0.0446 0 0 281 B
#4934 ObjectExtractorMoreComplexBody net6.0 2.79μs 1.33ns 5.16ns 0.0528 0 0 3.78 KB
#4934 ObjectExtractorMoreComplexBody netcoreapp3.1 3.75μs 1.18ns 4.56ns 0.0506 0 0 3.69 KB
#4934 ObjectExtractorMoreComplexBody net472 3.49μs 2.32ns 9ns 0.603 0.00523 0 3.8 KB
Benchmarks.Trace.Asm.AppSecWafBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master RunWaf(args=NestedMap (10)) net6.0 53.5μs 310ns 2.58μs 0.227 0 0 16.06 KB
master RunWaf(args=NestedMap (10)) netcoreapp3.1 68.3μs 396ns 3.38μs 0.217 0 0 16.06 KB
master RunWaf(args=NestedMap (10)) net472 96.1μs 494ns 2.32μs 2.56 0.093 0 16.14 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) net6.0 123μs 219ns 847ns 0.305 0 0 22.41 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) netcoreapp3.1 137μs 415ns 2.42μs 0.282 0 0 22.36 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) net472 167μs 54.1ns 209ns 3.6 0.167 0 22.7 KB
master RunWaf(args=NestedMap (100)) net6.0 108μs 37.9ns 147ns 0.436 0 0 32.76 KB
master RunWaf(args=NestedMap (100)) netcoreapp3.1 126μs 59.1ns 205ns 0.409 0 0 33.33 KB
master RunWaf(args=NestedMap (100)) net472 186μs 791ns 3.06μs 5.29 0.371 0 33.67 KB
master RunWafWithAttack(args=Neste(...)tack) [23]) net6.0 173μs 84.8ns 329ns 0.488 0 0 39.1 KB
master RunWafWithAttack(args=Neste(...)tack) [23]) netcoreapp3.1 208μs 706ns 2.73μs 0.511 0 0 39.63 KB
master RunWafWithAttack(args=Neste(...)tack) [23]) net472 271μs 513ns 1.99μs 6.3 0.525 0 40.23 KB
master RunWaf(args=NestedMap (20)) net6.0 104μs 607ns 5.15μs 0.433 0 0 32.18 KB
master RunWaf(args=NestedMap (20)) netcoreapp3.1 127μs 415ns 1.55μs 0.377 0 0 32.3 KB
master RunWaf(args=NestedMap (20)) net472 183μs 82.7ns 309ns 5.14 0.367 0 32.63 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) net6.0 163μs 40.1ns 150ns 0.517 0 0 38.53 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) netcoreapp3.1 207μs 1.06μs 5.2μs 0.501 0 0 38.6 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) net472 260μs 1.04μs 4.05μs 6.22 0.53 0 39.2 KB
#4934 RunWaf(args=NestedMap (10)) net6.0 56μs 27.4ns 106ns 0.209 0 0 16.06 KB
#4934 RunWaf(args=NestedMap (10)) netcoreapp3.1 70.9μs 383ns 2.3μs 0.194 0 0 16.06 KB
#4934 RunWaf(args=NestedMap (10)) net472 96.3μs 496ns 2.22μs 2.55 0.0944 0 16.14 KB
#4934 RunWafWithAttack(args=Neste(...)tack) [22]) net6.0 123μs 269ns 1.04μs 0.298 0 0 22.41 KB
#4934 RunWafWithAttack(args=Neste(...)tack) [22]) netcoreapp3.1 135μs 575ns 2.23μs 0.265 0 0 22.36 KB
#4934 RunWafWithAttack(args=Neste(...)tack) [22]) net472 165μs 514ns 1.99μs 3.59 0.163 0 22.7 KB
#4934 RunWaf(args=NestedMap (100)) net6.0 99.5μs 566ns 4.08μs 0.431 0 0 32.76 KB
#4934 RunWaf(args=NestedMap (100)) netcoreapp3.1 132μs 290ns 1.12μs 0.439 0 0 33.33 KB
#4934 RunWaf(args=NestedMap (100)) net472 184μs 122ns 474ns 5.26 0.369 0 33.67 KB
#4934 RunWafWithAttack(args=Neste(...)tack) [23]) net6.0 167μs 52.2ns 202ns 0.516 0 0 39.1 KB
#4934 RunWafWithAttack(args=Neste(...)tack) [23]) netcoreapp3.1 208μs 1.1μs 6.04μs 0.516 0 0 39.63 KB
#4934 RunWafWithAttack(args=Neste(...)tack) [23]) net472 259μs 450ns 1.74μs 6.33 0.517 0 40.23 KB
#4934 RunWaf(args=NestedMap (20)) net6.0 108μs 40.4ns 156ns 0.427 0 0 32.18 KB
#4934 RunWaf(args=NestedMap (20)) netcoreapp3.1 131μs 673ns 3.23μs 0.389 0 0 32.3 KB
#4934 RunWaf(args=NestedMap (20)) net472 181μs 168ns 651ns 5.18 0.363 0 32.63 KB
#4934 RunWafWithAttack(args=Neste(...)tack) [22]) net6.0 171μs 872ns 3.9μs 0.52 0 0 38.53 KB
#4934 RunWafWithAttack(args=Neste(...)tack) [22]) netcoreapp3.1 210μs 981ns 3.54μs 0.517 0 0 38.6 KB
#4934 RunWafWithAttack(args=Neste(...)tack) [22]) net472 262μs 499ns 1.93μs 6.21 0.529 0 39.2 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 172μs 109ns 424ns 0.171 0 0 18.24 KB
master SendRequest netcoreapp3.1 193μs 263ns 1.02μs 0.192 0 0 20.4 KB
master SendRequest net472 0.00074ns 0.000317ns 0.00119ns 0 0 0 0 b
#4934 SendRequest net6.0 171μs 118ns 458ns 0.171 0 0 18.24 KB
#4934 SendRequest netcoreapp3.1 191μs 217ns 842ns 0.189 0 0 20.4 KB
#4934 SendRequest net472 0.000502ns 0.00019ns 0.000711ns 0 0 0 0 b
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net6.0 560μs 256ns 923ns 0.566 0 0 41.48 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 665μs 1.69μs 6.54μs 0.322 0 0 41.81 KB
master WriteAndFlushEnrichedTraces net472 829μs 3μs 11.6μs 8.39 2.52 0.419 53.24 KB
#4934 WriteAndFlushEnrichedTraces net6.0 544μs 2.77μs 12.1μs 0.556 0 0 41.41 KB
#4934 WriteAndFlushEnrichedTraces netcoreapp3.1 658μs 652ns 2.53μs 0.322 0 0 41.77 KB
#4934 WriteAndFlushEnrichedTraces net472 827μs 3.74μs 15μs 8.33 2.5 0.417 53.22 KB
Benchmarks.Trace.DbCommandBenchmark - Slower ⚠️ Same allocations ✔️

Slower ⚠️ in #4934

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.DbCommandBenchmark.ExecuteNonQuery‑net6.0 1.166 997.61 1,162.85

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteNonQuery net6.0 997ns 0.785ns 3.04ns 0.011 0 0 768 B
master ExecuteNonQuery netcoreapp3.1 1.42μs 0.762ns 2.85ns 0.00999 0 0 768 B
master ExecuteNonQuery net472 1.77μs 0.847ns 3.05ns 0.116 0 0 730 B
#4934 ExecuteNonQuery net6.0 1.16μs 0.649ns 2.51ns 0.0104 0 0 768 B
#4934 ExecuteNonQuery netcoreapp3.1 1.45μs 2.26ns 8.77ns 0.0102 0 0 768 B
#4934 ExecuteNonQuery net472 1.69μs 0.564ns 2.19ns 0.116 0 0 730 B
Benchmarks.Trace.ElasticsearchBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master CallElasticsearch net6.0 1.21μs 0.749ns 2.8ns 0.0134 0 0 936 B
master CallElasticsearch netcoreapp3.1 1.48μs 1.69ns 6.31ns 0.0127 0 0 936 B
master CallElasticsearch net472 2.38μs 0.729ns 2.52ns 0.152 0 0 955 B
master CallElasticsearchAsync net6.0 1.29μs 0.585ns 2.27ns 0.0124 0 0 912 B
master CallElasticsearchAsync netcoreapp3.1 1.67μs 0.757ns 2.83ns 0.0126 0 0 984 B
master CallElasticsearchAsync net472 2.66μs 1.29ns 4.99ns 0.16 0 0 1.01 KB
#4934 CallElasticsearch net6.0 1.3μs 0.606ns 2.27ns 0.013 0 0 936 B
#4934 CallElasticsearch netcoreapp3.1 1.49μs 0.812ns 3.04ns 0.0129 0 0 936 B
#4934 CallElasticsearch net472 2.56μs 1.08ns 4.2ns 0.152 0 0 955 B
#4934 CallElasticsearchAsync net6.0 1.27μs 0.418ns 1.56ns 0.0127 0 0 912 B
#4934 CallElasticsearchAsync netcoreapp3.1 1.65μs 1.33ns 5.14ns 0.0132 0 0 984 B
#4934 CallElasticsearchAsync net472 2.6μs 1.46ns 5.65ns 0.16 0 0 1.01 KB
Benchmarks.Trace.GraphQLBenchmark - Slower ⚠️ Same allocations ✔️

Slower ⚠️ in #4934

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.GraphQLBenchmark.ExecuteAsync‑net6.0 1.136 1,248.17 1,418.25

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteAsync net6.0 1.25μs 0.885ns 3.43ns 0.0124 0 0 912 B
master ExecuteAsync netcoreapp3.1 1.57μs 0.515ns 1.93ns 0.0118 0 0 912 B
master ExecuteAsync net472 1.87μs 1.76ns 6.8ns 0.139 0.000907 0 875 B
#4934 ExecuteAsync net6.0 1.42μs 1.2ns 4.66ns 0.0128 0 0 912 B
#4934 ExecuteAsync netcoreapp3.1 1.57μs 0.774ns 3ns 0.0125 0 0 912 B
#4934 ExecuteAsync net472 1.8μs 0.452ns 1.63ns 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 4.41μs 14.4ns 55.6ns 0.028 0 0 2.1 KB
master SendAsync netcoreapp3.1 4.94μs 1.77ns 6.84ns 0.0344 0 0 2.63 KB
master SendAsync net472 7.74μs 2.67ns 10.4ns 0.522 0 0 3.31 KB
#4934 SendAsync net6.0 4.23μs 4.33ns 16.2ns 0.0295 0 0 2.1 KB
#4934 SendAsync netcoreapp3.1 5.04μs 2.26ns 8.45ns 0.0354 0 0 2.63 KB
#4934 SendAsync net472 7.64μs 1.48ns 5.75ns 0.525 0 0 3.31 KB
Benchmarks.Trace.Iast.StringAspectsBenchmark - Slower ⚠️ Fewer allocations 🎉

Slower ⚠️ in #4934

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatAspectBenchmark(parameters: System.Collections.Generic.List`1[System.String])‑netcoreapp3.1 1.451 71,000.00 103,000.00 bimodal

Faster 🎉 in #4934

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatAspectBenchmark(parameters: System.Collections.Generic.List`1[System.String])‑net6.0 1.513 98,950.00 65,400.00 multimodal

Fewer allocations 🎉 in #4934

Benchmark Base Allocated Diff Allocated Change Change %
Benchmarks.Trace.Iast.StringAspectsBenchmark.StringConcatAspectBenchmark(parameters: System.Collections.Generic.List`1[System.String])‑net472 65.54 KB 57.34 KB -8.19 KB -12.50%

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StringConcatBenchmark(parameters=Syste(...)ring] [48]) net6.0 56.4μs 686ns 6.76μs 0 0 0 43.44 KB
master StringConcatBenchmark(parameters=Syste(...)ring] [48]) netcoreapp3.1 52.9μs 220ns 932ns 0 0 0 42.64 KB
master StringConcatBenchmark(parameters=Syste(...)ring] [48]) net472 37.8μs 139ns 502ns 0 0 0 59.7 KB
master StringConcatAspectBenchmark(parameters=Syste(...)ring] [48]) net6.0 101μs 2.82μs 28.2μs 0 0 0 43.29 KB
master StringConcatAspectBenchmark(parameters=Syste(...)ring] [48]) netcoreapp3.1 70.9μs 330ns 1.24μs 0 0 0 42.64 KB
master StringConcatAspectBenchmark(parameters=Syste(...)ring] [48]) net472 63.4μs 368ns 2.92μs 0 0 0 65.54 KB
#4934 StringConcatBenchmark(parameters=Syste(...)ring] [48]) net6.0 61.2μs 837ns 8.24μs 0 0 0 43.44 KB
#4934 StringConcatBenchmark(parameters=Syste(...)ring] [48]) netcoreapp3.1 59.7μs 800ns 7.8μs 0 0 0 42.64 KB
#4934 StringConcatBenchmark(parameters=Syste(...)ring] [48]) net472 37.8μs 67.9ns 245ns 0 0 0 59.7 KB
#4934 StringConcatAspectBenchmark(parameters=Syste(...)ring] [48]) net6.0 65.1μs 248ns 893ns 0 0 0 43.29 KB
#4934 StringConcatAspectBenchmark(parameters=Syste(...)ring] [48]) netcoreapp3.1 107μs 2.52μs 24.8μs 0 0 0 42.64 KB
#4934 StringConcatAspectBenchmark(parameters=Syste(...)ring] [48]) net472 64.7μs 281ns 1.05μs 0 0 0 57.34 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.51μs 0.77ns 2.88ns 0.0219 0 0 1.57 KB
master EnrichedLog netcoreapp3.1 2.17μs 0.768ns 2.87ns 0.0205 0 0 1.57 KB
master EnrichedLog net472 2.57μs 3.02ns 11.7ns 0.238 0 0 1.5 KB
#4934 EnrichedLog net6.0 1.5μs 0.526ns 2.04ns 0.0217 0 0 1.57 KB
#4934 EnrichedLog netcoreapp3.1 2.19μs 2.64ns 9.87ns 0.021 0 0 1.57 KB
#4934 EnrichedLog net472 2.47μs 2.7ns 10.1ns 0.238 0 0 1.5 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 114μs 107ns 400ns 0.0557 0 0 4.21 KB
master EnrichedLog netcoreapp3.1 118μs 199ns 770ns 0 0 0 4.21 KB
master EnrichedLog net472 148μs 230ns 891ns 0.659 0.22 0 4.39 KB
#4934 EnrichedLog net6.0 112μs 95ns 368ns 0.056 0 0 4.21 KB
#4934 EnrichedLog netcoreapp3.1 116μs 87.5ns 316ns 0.0581 0 0 4.21 KB
#4934 EnrichedLog net472 149μs 123ns 476ns 0.669 0.223 0 4.39 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 2.9μs 0.732ns 2.74ns 0.0289 0 0 2.13 KB
master EnrichedLog netcoreapp3.1 4.21μs 2.38ns 9.2ns 0.0273 0 0 2.13 KB
master EnrichedLog net472 4.99μs 1.62ns 5.61ns 0.309 0 0 1.95 KB
#4934 EnrichedLog net6.0 3.01μs 1.13ns 4.37ns 0.03 0 0 2.13 KB
#4934 EnrichedLog netcoreapp3.1 4.2μs 0.449ns 1.62ns 0.0274 0 0 2.13 KB
#4934 EnrichedLog net472 4.79μs 4.94ns 19.1ns 0.308 0 0 1.95 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.35μs 0.901ns 3.12ns 0.0154 0 0 1.1 KB
master SendReceive netcoreapp3.1 1.76μs 1.54ns 5.95ns 0.0151 0 0 1.1 KB
master SendReceive net472 2.27μs 3.43ns 13.3ns 0.177 0 0 1.12 KB
#4934 SendReceive net6.0 1.33μs 1.03ns 3.98ns 0.0154 0 0 1.1 KB
#4934 SendReceive netcoreapp3.1 1.83μs 0.745ns 2.88ns 0.0146 0 0 1.1 KB
#4934 SendReceive net472 2.13μs 2.17ns 8.41ns 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.68μs 1.01ns 3.77ns 0.0215 0 0 1.53 KB
master EnrichedLog netcoreapp3.1 3.79μs 1.52ns 5.88ns 0.0208 0 0 1.58 KB
master EnrichedLog net472 4.28μs 2.27ns 8.78ns 0.311 0 0 1.97 KB
#4934 EnrichedLog net6.0 2.76μs 1.46ns 5.46ns 0.0207 0 0 1.53 KB
#4934 EnrichedLog netcoreapp3.1 3.9μs 1.25ns 4.85ns 0.0215 0 0 1.58 KB
#4934 EnrichedLog net472 4.36μs 1.22ns 4.41ns 0.31 0 0 1.97 KB
Benchmarks.Trace.SpanBenchmark - Faster 🎉 Same allocations ✔️

Faster 🎉 in #4934

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.SpanBenchmark.StartFinishSpan‑net6.0 1.171 520.85 444.81

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartFinishSpan net6.0 521ns 0.193ns 0.747ns 0.00752 0 0 536 B
master StartFinishSpan netcoreapp3.1 659ns 0.661ns 2.56ns 0.0073 0 0 536 B
master StartFinishSpan net472 718ns 0.241ns 0.9ns 0.0852 0 0 538 B
master StartFinishScope net6.0 531ns 0.0946ns 0.354ns 0.0091 0 0 656 B
master StartFinishScope netcoreapp3.1 812ns 0.51ns 1.91ns 0.0088 0 0 656 B
master StartFinishScope net472 994ns 0.435ns 1.68ns 0.0982 0 0 618 B
#4934 StartFinishSpan net6.0 445ns 0.15ns 0.579ns 0.00762 0 0 536 B
#4934 StartFinishSpan netcoreapp3.1 631ns 0.188ns 0.678ns 0.00736 0 0 536 B
#4934 StartFinishSpan net472 754ns 0.257ns 0.996ns 0.0854 0 0 538 B
#4934 StartFinishScope net6.0 535ns 0.401ns 1.55ns 0.00913 0 0 656 B
#4934 StartFinishScope netcoreapp3.1 797ns 0.303ns 1.17ns 0.00907 0 0 656 B
#4934 StartFinishScope net472 1.02μs 0.557ns 2.16ns 0.0978 0 0 618 B
Benchmarks.Trace.TraceAnnotationsBenchmark - Slower ⚠️ Same allocations ✔️

Slower ⚠️ in #4934

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.TraceAnnotationsBenchmark.RunOnMethodBegin‑net6.0 1.116 585.13 653.17

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master RunOnMethodBegin net6.0 585ns 0.196ns 0.758ns 0.00934 0 0 656 B
master RunOnMethodBegin netcoreapp3.1 884ns 1.28ns 4.94ns 0.00883 0 0 656 B
master RunOnMethodBegin net472 1.06μs 0.391ns 1.51ns 0.098 0 0 618 B
#4934 RunOnMethodBegin net6.0 653ns 0.306ns 1.06ns 0.00906 0 0 656 B
#4934 RunOnMethodBegin netcoreapp3.1 967ns 0.819ns 2.95ns 0.00873 0 0 656 B
#4934 RunOnMethodBegin net472 1.04μs 0.249ns 0.932ns 0.098 0 0 618 B

@andrewlock
Downgrade "Error occured sending data to the agent"
caf4a7a 
It's an error, but one we can't do anything about. Warnings are written to the logs in the same way, so this shouldn't be a big deal hopefully?

Alternatively, we could apply a filter to the log telemetry logs
@andrewlock
Downgrade "The process does not have sufficient permissions to read p…
16e5b13 
…erformance counters" to warning

It's an error, but one we can't do anything about. Warnings are written to the logs in the same way, so this shouldn't be a big deal hopefully?

Alternatively, we could apply a filter to the log telemetry logs
@andrewlock
Revert "Downgrade "Error occured sending data to the agent""
591808c 
This reverts commit bef6b34.
@andrewlock
Revert "Downgrade "The process does not have sufficient permissions t…
9d1ff96 
…o read performance counters" to warning"

This reverts commit 677fa4e.
@andrewlock
Exclude specific logs that we can't do anything about
e57b1a6
@andrewlock
Add unit test for not sending the message
4a263b0
@andrewlock andrewlock changed the title Downgrade some errors to warnings Don't send some error logs to telemetry Nov 29, 2023
@andrewlock
Copy link
Member Author

I think they should stay as Error as they are actual errors that are either limiting some functionality or requiring some user intervention. So I think filtering would probably be the better route.

Thanks again for the feedback, I've pushed the new implementation up and I think it's going to be fine, and I don't think we need to worry about perf for it at this stage.

bouwkast
bouwkast approved these changes Nov 29, 2023
View reviewed changes
Copy link
Contributor

@bouwkast bouwkast left a comment

Choose a reason for hiding this comment

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

Nice!

@andrewlock andrewlock merged commit e5ab6ed into master Nov 30, 2023
54 checks passed
@andrewlock andrewlock deleted the andrew/downgrade-warnings branch November 30, 2023 15:44
@github-actions github-actions bot added this to the vNext milestone Nov 30, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers

@lucaspimentel lucaspimentel lucaspimentel approved these changes

@bouwkast bouwkast bouwkast approved these changes

Assignees
No one assigned
Labels
area:tracer The core tracer library (Datadog.Trace, does not include OpenTracing, native code, or integrations) type:cleanup Minor code clean up
Projects
None yet
Milestone
2.43.0
Development

Successfully merging this pull request may close these issues.
3 participants
@andrewlock @lucaspimentel @bouwkast