[Dynamic Instrumentation] Upload code symbols by dudikeleti · Pull Request #4412 · DataDog/dd-trace-dotnet

dudikeleti · 2023-07-18T16:28:27Z

Summary of changes

This PR is for uploading code symbols to SymDB to later let customers define probes and expressions with a better user experience.

Reason for change

Currently, when a user wants to create a probe or add an expression to a probe in Dynamic Instrumentation, they do not get any auto-complete while typing in names of method or local variables, and so they are likely to make spelling mistakes, which would cause them to have a frustrating experience with the product. With this change, we are uploading all the symbols info to SymDB so we can display to the user which symbols exist for the current scope.

Implementation

When granted permission by the customer and ensuring the agent is in a valid version, we enable the uploading of symbols.
For that we are scanning all assemblies (with some exceptions) currently running in the application, as well as the assemblies that will be loaded in the future and adding them to processing queue.
To avoid performance bottlenecks, we perform all the intensive tasks in a background thread using async await.
To prevent exceeding memory limits, we handle the extraction process synchronously, carefully managing memory consumption.
For obtaining both metadata and PDB information, we rely on the dnlib library.

datadog-ddstaging · 2023-07-18T16:54:43Z

Datadog Report

Branch report: dudik/upload-symbols
Commit report: 11cbf34

❌ dd-trace-dotnet: 3412 Failed (0 Known Flaky), 0 New Flaky, 177525 Passed, 1751 Skipped, 56m 2.11s Wall Time

❌ Failed Tests (3412)

This report shows up to 5 failed tests.

InstallAndUninstallMethodProbeWithOverloadsTest - Datadog.Trace.Debugger.IntegrationTests.ProbesTests - Details

Expand for error

 Log file was not found for path: D:\a\1\s\tracer\build_data\logs with file pattern dotnet-tracer-managed-dotnet*. Logs read so far:

InstallAndUninstallMethodProbeWithOverloadsTest - Datadog.Trace.Debugger.IntegrationTests.ProbesTests - Details

Expand for error

 Log file was not found for path: D:\a\1\s\tracer\build_data\logs with file pattern dotnet-tracer-managed-dotnet*. Logs read so far:

InstallAndUninstallMethodProbeWithOverloadsTest - Datadog.Trace.Debugger.IntegrationTests.ProbesTests - Details

Expand for error

 Log file was not found for path: D:\a\1\s\tracer\build_data\logs with file pattern dotnet-tracer-managed-dotnet*. Logs read so far:

InstallAndUninstallMethodProbeWithOverloadsTest - Datadog.Trace.Debugger.IntegrationTests.ProbesTests - Details

Expand for error

 Log file was not found for path: D:\a\1\s\tracer\build_data\logs with file pattern dotnet-tracer-managed-dotnet*. Logs read so far:

InstallAndUninstallMethodProbeWithOverloadsTest - Datadog.Trace.Debugger.IntegrationTests.ProbesTests - Details

Expand for error

 Log file was not found for path: D:\a\1\s\tracer\build_data\logs with file pattern dotnet-tracer-managed-Samples.Probes*. Logs read so far:

OmerRaviv · 2023-07-19T08:43:35Z

+            var @event = string.Empty;
+            try
+            {
+                @event = @$"""ddsource"": ""dd_debugger"",


Naming nitpick - it seems like this is more eventMetadata than event?

Fixed in 6e5b07c

OmerRaviv · 2023-07-19T08:47:19Z

+{
+    internal interface ISymbolSink : IDisposable
+    {
+        Task StartExtractingAssemblySymbolsAsync();


nitpick/design quip - all the other "sinks" we use in LiveDebugger's sole responsibility is indeed to be a "sink" in the sense that they receive incoming data and funnel it off to datadog-agent (while taking care of whatever subtleties there might be necessary, e.g. in re-transmitting probe statuses, etc etc).

This seems to break that abstraction somehow in that here we have a "sink" that is actually responsible for kicking off the extraction?

Fixed in bb2b32d

OmerRaviv · 2023-07-19T08:50:31Z

+        private static bool ShouldRetry(int statusCode)
+        {
+            int[] statusCodesToRetry = { 408, 425, 429, 503, 504 };
+            return statusCodesToRetry.Any(code => code == statusCode);
+        }


Curious, where does the decision to retry for these status codes come from? How come we don't do it anywhere else in our code base?

Oh, just found at least once source in

dd-trace-dotnet/tracer/src/Datadog.Trace/Logging/DirectSubmission/Sink/LogsApi.cs

Line 92 in 77a8cb8

shouldRetry = response.StatusCode switch

Should we try to extract and reuse?

Fixed in f3cf79f

OmerRaviv · 2023-07-19T08:55:50Z

+        private static TimeSpan GetDelayTime(int retryAttempt)
+        {
+            const int baseDelayMs = 250;
+            int maxDelayMs = baseDelayMs * (int)Math.Pow(2, retryAttempt);
+
+            Random random = new Random();
+            int delayMs = random.Next(baseDelayMs, maxDelayMs);
+
+            return TimeSpan.FromMilliseconds(delayMs);


I was wondering if we really need to allocate a 'Random' here each time, and if we need randomness at all? But as a more general comment, should we try to just reuse the same code for retry logic that appear in other places in the code base?

Fixed in f3cf79f

GreenMatan

Reviewed most of the changes. There are some more logical details that I want to re-review and then I'll submit the final batch of comments.
Great job!

OmerRaviv · 2023-07-19T10:43:52Z

+
+        public async Task StartExtractingAssemblySymbolsAsync()
+        {
+            RegisterToAssemblyLoadEvent();


We should be careful not to do any work at all or even register to assembly load event if the aforementioned environment variable is turned off, or if DiscoveryService tells us the SymDB endpoint is not available.

As far as I can tell this PR doesn't address the requirement that Symbol Database upload should only occur if we receive an instruction to perform it via Remote Configuration. If your plan it add that in a subsequent PR, since we don't want it on by default, I propose it should be gated by an environment variable that should be false by default for the time being, i.e. something like DD_INTERNAM_FORCE_SYMBOL_DATABASED_UPLOAD?

I think it's OK to wait with this until a subsequent PR, but I think it's important to note that we might need to trigger the upload late (long after the tracer finished initializing), as soon as both the above mentioned conditions are met (we've received the notification from remote config AND datadog-agent has been upgraded to a version that supports the sym-db endpoint.

Fixed in 6e5b07c

OmerRaviv · 2023-07-19T11:08:29Z

+      "scopeType": "Assembly",
+      "name": "Datadog.Trace.Tests, Version=1.0.0.0, Culture=neutral, PublicKeyToken=def86d061d0d2eeb",
+      "type": null,
+      "sourceFile": "C:\\dev\\Datadog\\dd-trace-dotnet\\tracer\\test\\Datadog.Trace.Tests\\bin\\Debug\\net6.0\\Datadog.Trace.Tests.dll",


Just FYI This will need to be sanitized for the test to pass in CI and on Linux

Fixed in bb2b32d

GreenMatan

I've finished reviewing, submitting the last batch of comments

OmerRaviv · 2023-07-19T12:49:49Z

+        {
+            if (Volatile.Read(ref _endpoint) is not { } endpoint)
+            {
+                Log.Warning("Failed to upload symbol: symbol endpoint not yet retrieved from discovery service");


This warning isn't very actionable or helpful to users. I'd suggest something like "Dynamic Instrumentation failed to upload symbols for auto-complete suggestions. Ensure that you are working with datadog-agent v7.45.0 or higher" (am I correct in assuming that's the right version?)

We should only write this to log once, and avoid any further attempt to upload symbols until we get a notification from DiscoveryService that datadog-agent has been upgraded and the endpoint is now available.

Is DiscoveryService notification is reversable? i.e. is it possible to get a valid endpoint and then, a null endpoint? From other location in source it's not seems to be able but I want to make sure.
If not, please take a look on 6e5b07c and 26bee6a

andrewlock · 2023-07-21T16:28:12Z

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 (4412) - mean (68ms)  : 65, 72
     .   : milestone, 68,
    master - mean (70ms)  : 59, 81
     .   : milestone, 70,

    section CallTarget+Inlining+NGEN
    This PR (4412) - mean (1,040ms)  : 1007, 1072
     .   : milestone, 1040,
    master - mean (1,033ms)  : 1005, 1061
     .   : milestone, 1033,

gantt
    title Execution time (ms) FakeDbCommand (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4412) - mean (105ms)  : 102, 109
     .   : milestone, 105,
    master - mean (106ms)  : 100, 112
     .   : milestone, 106,

    section CallTarget+Inlining+NGEN
    This PR (4412) - mean (742ms)  : 723, 762
     .   : milestone, 742,
    master - mean (745ms)  : 720, 771
     .   : milestone, 745,

gantt
    title Execution time (ms) FakeDbCommand (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4412) - mean (89ms)  : 85, 93
     .   : milestone, 89,
    master - mean (89ms)  : 86, 92
     .   : milestone, 89,

    section CallTarget+Inlining+NGEN
    This PR (4412) - mean (708ms)  : 687, 729
     .   : milestone, 708,
    master - mean (703ms)  : 683, 723
     .   : milestone, 703,

gantt
    title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4412) - mean (187ms)  : 178, 196
     .   : milestone, 187,
    master - mean (188ms)  : 176, 200
     .   : milestone, 188,

    section CallTarget+Inlining+NGEN
    This PR (4412) - mean (1,126ms)  : 1091, 1160
     .   : milestone, 1126,
    master - mean (1,121ms)  : 1073, 1170
     .   : milestone, 1121,

gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4412) - mean (272ms)  : 264, 280
     .   : milestone, 272,
    master - mean (269ms)  : 254, 284
     .   : milestone, 269,

    section CallTarget+Inlining+NGEN
    This PR (4412) - mean (1,100ms)  : 1050, 1150
     .   : milestone, 1100,
    master - mean (1,096ms)  : 1065, 1127
     .   : milestone, 1096,

gantt
    title Execution time (ms) HttpMessageHandler (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4412) - mean (258ms)  : 246, 270
     .   : milestone, 258,
    master - mean (262ms)  : 251, 272
     .   : milestone, 262,

    section CallTarget+Inlining+NGEN
    This PR (4412) - mean (1,048ms)  : 1006, 1089
     .   : milestone, 1048,
    master - mean (1,049ms)  : 1013, 1086
     .   : milestone, 1049,

andrewlock · 2023-07-21T16:40:55Z

Benchmarks Report 🐌

Benchmarks for #4412 compared to master:

1 benchmarks are faster, with geometric mean 1.115
4 benchmarks are slower, with geometric mean 1.136
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.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.31μs	45ns	242ns	0.0388	0.0172	0	7.28 KB
master	`StartStopWithChild`	netcoreapp3.1	10.1μs	49.2ns	209ns	0.0245	0.0098	0	7.39 KB
master	`StartStopWithChild`	net472	15.5μs	63.5ns	246ns	1.31	0.348	0.113	7.67 KB
#4412	`StartStopWithChild`	net6.0	8.38μs	47.1ns	323ns	0.0211	0.00846	0	7.28 KB
#4412	`StartStopWithChild`	netcoreapp3.1	10μs	52.1ns	261ns	0.0251	0.01	0	7.39 KB
#4412	`StartStopWithChild`	net472	15.8μs	65.1ns	252ns	1.28	0.309	0.101	7.66 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`WriteAndFlushEnrichedTraces`	net6.0	458μs	106ns	382ns	0	2.7 KB
master	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	636μs	134ns	500ns	0	2.7 KB
master	`WriteAndFlushEnrichedTraces`	net472	794μs	350ns	1.31μs	0.398	3.3 KB
#4412	`WriteAndFlushEnrichedTraces`	net6.0	475μs	199ns	770ns	0	2.7 KB
#4412	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	636μs	201ns	777ns	0	2.7 KB
#4412	`WriteAndFlushEnrichedTraces`	net472	821μs	320ns	1.24μs	0.408	3.3 KB

Benchmarks.Trace.Asm.AppSecBodyBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`AllCycleSimpleBody`	net6.0	43.4μs	34.3ns	133ns	0.0219	0	2.03 KB
master	`AllCycleSimpleBody`	netcoreapp3.1	45.5μs	221ns	937ns	0.0242	0	2.01 KB
master	`AllCycleSimpleBody`	net472	46.7μs	35.5ns	138ns	0.327	0	2.08 KB
master	`AllCycleMoreComplexBody`	net6.0	228μs	76.7ns	297ns	0.113	0	8.63 KB
master	`AllCycleMoreComplexBody`	netcoreapp3.1	233μs	213ns	825ns	0	0	8.52 KB
master	`AllCycleMoreComplexBody`	net472	237μs	63.3ns	245ns	1.3	0	8.7 KB
master	`ObjectExtractorSimpleBody`	net6.0	123ns	0.0798ns	0.309ns	0.00393	0	280 B
master	`ObjectExtractorSimpleBody`	netcoreapp3.1	170ns	0.0862ns	0.322ns	0.00374	0	272 B
master	`ObjectExtractorSimpleBody`	net472	144ns	0.0914ns	0.354ns	0.0446	0	281 B
master	`ObjectExtractorMoreComplexBody`	net6.0	3.02μs	1.03ns	3.71ns	0.0544	0	3.88 KB
master	`ObjectExtractorMoreComplexBody`	netcoreapp3.1	3.97μs	1.35ns	5.21ns	0.0519	0	3.78 KB
master	`ObjectExtractorMoreComplexBody`	net472	4.11μs	3.75ns	14ns	0.617	0.00615	3.89 KB
#4412	`AllCycleSimpleBody`	net6.0	43.7μs	41.3ns	160ns	0.0212	0	2.03 KB
#4412	`AllCycleSimpleBody`	netcoreapp3.1	44.5μs	113ns	439ns	0.0225	0	2.01 KB
#4412	`AllCycleSimpleBody`	net472	46.6μs	22.7ns	88.1ns	0.324	0	2.08 KB
#4412	`AllCycleMoreComplexBody`	net6.0	230μs	682ns	2.64μs	0.114	0	8.63 KB
#4412	`AllCycleMoreComplexBody`	netcoreapp3.1	233μs	97.7ns	352ns	0.116	0	8.52 KB
#4412	`AllCycleMoreComplexBody`	net472	235μs	98.1ns	380ns	1.29	0	8.7 KB
#4412	`ObjectExtractorSimpleBody`	net6.0	118ns	0.0395ns	0.153ns	0.00396	0	280 B
#4412	`ObjectExtractorSimpleBody`	netcoreapp3.1	172ns	0.0632ns	0.237ns	0.00375	0	272 B
#4412	`ObjectExtractorSimpleBody`	net472	146ns	0.133ns	0.479ns	0.0446	0	281 B
#4412	`ObjectExtractorMoreComplexBody`	net6.0	2.97μs	0.678ns	2.54ns	0.0537	0	3.88 KB
#4412	`ObjectExtractorMoreComplexBody`	netcoreapp3.1	4.05μs	2.58ns	9.98ns	0.0506	0	3.78 KB
#4412	`ObjectExtractorMoreComplexBody`	net472	4.09μs	2.66ns	10.3ns	0.617	0.00613	3.89 KB

Benchmarks.Trace.Asm.AppSecWafBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`RunWaf(args=NestedMap (10))`	net6.0	13μs	3.09ns	11.5ns	0.134	0	9.42 KB
master	`RunWaf(args=NestedMap (10))`	netcoreapp3.1	19.2μs	5.08ns	19ns	0.125	0	9.42 KB
master	`RunWaf(args=NestedMap (10))`	net472	28.8μs	8.98ns	33.6ns	1.5	0	9.48 KB
master	`RunWafWithAttack(args=Neste(...)tack) [22])`	net6.0	78.3μs	56.8ns	220ns	0.196	0	15.77 KB
master	`RunWafWithAttack(args=Neste(...)tack) [22])`	netcoreapp3.1	86.6μs	169ns	632ns	0.171	0	15.72 KB
master	`RunWafWithAttack(args=Neste(...)tack) [22])`	net472	98.5μs	170ns	657ns	2.52	0	16.04 KB
master	`RunWaf(args=NestedMap (100))`	net6.0	23.8μs	8.86ns	34.3ns	0.276	0	19.66 KB
master	`RunWaf(args=NestedMap (100))`	netcoreapp3.1	38.1μs	12.2ns	45.5ns	0.266	0	20.42 KB
master	`RunWaf(args=NestedMap (100))`	net472	54.5μs	12.4ns	46.5ns	3.26	0.0543	20.63 KB
master	`RunWafWithAttack(args=Neste(...)tack) [23])`	net6.0	94μs	52.8ns	205ns	0.373	0	26.01 KB
master	`RunWafWithAttack(args=Neste(...)tack) [23])`	netcoreapp3.1	109μs	181ns	702ns	0.322	0	26.72 KB
master	`RunWafWithAttack(args=Neste(...)tack) [23])`	net472	132μs	67.7ns	262ns	4.32	0.0664	27.19 KB
master	`RunWaf(args=NestedMap (20))`	net6.0	23.8μs	5.56ns	21.6ns	0.273	0	19.4 KB
master	`RunWaf(args=NestedMap (20))`	netcoreapp3.1	38μs	20.5ns	79.5ns	0.265	0	19.84 KB
master	`RunWaf(args=NestedMap (20))`	net472	54μs	22.4ns	86.6ns	3.16	0.0541	20.04 KB
master	`RunWafWithAttack(args=Neste(...)tack) [22])`	net6.0	92.9μs	53.1ns	206ns	0.326	0	25.74 KB
master	`RunWafWithAttack(args=Neste(...)tack) [22])`	netcoreapp3.1	109μs	135ns	525ns	0.341	0	26.15 KB
master	`RunWafWithAttack(args=Neste(...)tack) [22])`	net472	130μs	347ns	1.34μs	4.18	0.0644	26.6 KB
#4412	`RunWaf(args=NestedMap (10))`	net6.0	12.6μs	4.74ns	17.1ns	0.128	0	9.42 KB
#4412	`RunWaf(args=NestedMap (10))`	netcoreapp3.1	19.4μs	3.62ns	13.1ns	0.126	0	9.42 KB
#4412	`RunWaf(args=NestedMap (10))`	net472	28.6μs	10.8ns	40.3ns	1.49	0	9.48 KB
#4412	`RunWafWithAttack(args=Neste(...)tack) [22])`	net6.0	77.9μs	65.7ns	254ns	0.195	0	15.77 KB
#4412	`RunWafWithAttack(args=Neste(...)tack) [22])`	netcoreapp3.1	86.2μs	112ns	404ns	0.213	0	15.72 KB
#4412	`RunWafWithAttack(args=Neste(...)tack) [22])`	net472	98.2μs	25ns	86.6ns	2.54	0	16.04 KB
#4412	`RunWaf(args=NestedMap (100))`	net6.0	24.1μs	8.76ns	32.8ns	0.278	0	19.66 KB
#4412	`RunWaf(args=NestedMap (100))`	netcoreapp3.1	38μs	11.2ns	40.5ns	0.266	0	20.42 KB
#4412	`RunWaf(args=NestedMap (100))`	net472	54.5μs	33.4ns	129ns	3.27	0.0273	20.63 KB
#4412	`RunWafWithAttack(args=Neste(...)tack) [23])`	net6.0	95.1μs	244ns	946ns	0.331	0	26.01 KB
#4412	`RunWafWithAttack(args=Neste(...)tack) [23])`	netcoreapp3.1	108μs	137ns	494ns	0.328	0	26.72 KB
#4412	`RunWafWithAttack(args=Neste(...)tack) [23])`	net472	131μs	288ns	1.12μs	4.29	0.065	27.19 KB
#4412	`RunWaf(args=NestedMap (20))`	net6.0	24.1μs	10.6ns	41.2ns	0.274	0	19.4 KB
#4412	`RunWaf(args=NestedMap (20))`	netcoreapp3.1	37.3μs	12ns	45ns	0.26	0	19.84 KB
#4412	`RunWaf(args=NestedMap (20))`	net472	53.7μs	11.4ns	42.8ns	3.18	0.0535	20.04 KB
#4412	`RunWafWithAttack(args=Neste(...)tack) [22])`	net6.0	91.4μs	61.1ns	237ns	0.36	0	25.74 KB
#4412	`RunWafWithAttack(args=Neste(...)tack) [22])`	netcoreapp3.1	109μs	118ns	442ns	0.325	0	26.14 KB
#4412	`RunWafWithAttack(args=Neste(...)tack) [22])`	net472	129μs	214ns	830ns	4.19	0.0645	26.6 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendRequest`	net6.0	173μs	149ns	559ns	0.172	18.09 KB
master	`SendRequest`	netcoreapp3.1	192μs	197ns	764ns	0.19	20.25 KB
master	`SendRequest`	net472	0.00118ns	0.000546ns	0.00212ns	0	0 b
#4412	`SendRequest`	net6.0	169μs	153ns	593ns	0.252	18.09 KB
#4412	`SendRequest`	netcoreapp3.1	191μs	293ns	1.14μs	0.188	20.25 KB
#4412	`SendRequest`	net472	8.44E‑05ns	8.11E‑05ns	0.000304ns	0	0 b

Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Same speed ✔️ More allocations ⚠️

More allocations ⚠️ in #4412

Benchmark	Base Allocated	Diff Allocated	Change	Change %
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑net6.0	41.48 KB	41.88 KB	402 B	0.97%

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Gen 2	Allocated
master	`WriteAndFlushEnrichedTraces`	net6.0	528μs	2.32μs	9μs	0.532	0	0	41.48 KB
master	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	631μs	836ns	3.24μs	0.308	0	0	41.7 KB
master	`WriteAndFlushEnrichedTraces`	net472	787μs	3.97μs	18.2μs	8.31	2.37	0.396	53.23 KB
#4412	`WriteAndFlushEnrichedTraces`	net6.0	534μs	1.54μs	5.96μs	0.53	0	0	41.88 KB
#4412	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	621μs	1.88μs	7.27μs	0.309	0	0	41.64 KB
#4412	`WriteAndFlushEnrichedTraces`	net472	795μs	2.07μs	7.74μs	8.41	2.4	0.401	53.24 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`ExecuteNonQuery`	net6.0	1.02μs	0.477ns	1.85ns	0.0107	768 B
master	`ExecuteNonQuery`	netcoreapp3.1	1.33μs	0.568ns	2.2ns	0.00992	768 B
master	`ExecuteNonQuery`	net472	1.58μs	2.82ns	10.9ns	0.116	730 B
#4412	`ExecuteNonQuery`	net6.0	1.11μs	0.77ns	2.98ns	0.0106	768 B
#4412	`ExecuteNonQuery`	netcoreapp3.1	1.3μs	0.669ns	2.59ns	0.0106	768 B
#4412	`ExecuteNonQuery`	net472	1.68μs	0.309ns	1.12ns	0.116	730 B

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`CallElasticsearch`	net6.0	1.13μs	0.56ns	2.09ns	0.0138	0	992 B
master	`CallElasticsearch`	netcoreapp3.1	1.48μs	2.18ns	8.17ns	0.0133	0	992 B
master	`CallElasticsearch`	net472	2.35μs	1.31ns	4.9ns	0.159	0.00118	1 KB
master	`CallElasticsearchAsync`	net6.0	1.26μs	1.04ns	4.01ns	0.0133	0	968 B
master	`CallElasticsearchAsync`	netcoreapp3.1	1.55μs	0.787ns	3.05ns	0.0138	0	1.04 KB
master	`CallElasticsearchAsync`	net472	2.47μs	0.933ns	3.61ns	0.168	0.00124	1.06 KB
#4412	`CallElasticsearch`	net6.0	1.19μs	0.466ns	1.74ns	0.0137	0	992 B
#4412	`CallElasticsearch`	netcoreapp3.1	1.4μs	0.522ns	1.95ns	0.0133	0	992 B
#4412	`CallElasticsearch`	net472	2.37μs	0.662ns	2.57ns	0.158	0.00118	1 KB
#4412	`CallElasticsearchAsync`	net6.0	1.34μs	0.774ns	3ns	0.0134	0	968 B
#4412	`CallElasticsearchAsync`	netcoreapp3.1	1.61μs	1.05ns	3.93ns	0.0143	0	1.04 KB
#4412	`CallElasticsearchAsync`	net472	2.52μs	0.824ns	3.19ns	0.168	0.00126	1.06 KB

Benchmarks.Trace.GraphQLBenchmark - Slower ⚠️ Same allocations ✔️

Slower ⚠️ in #4412

Benchmark	diff/base	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.GraphQLBenchmark.ExecuteAsync‑net6.0	1.119	1,173.34	1,312.70

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`ExecuteAsync`	net6.0	1.17μs	0.733ns	2.84ns	0.0128	0	912 B
master	`ExecuteAsync`	netcoreapp3.1	1.49μs	0.891ns	3.33ns	0.012	0	912 B
master	`ExecuteAsync`	net472	1.61μs	0.558ns	1.93ns	0.139	0	875 B
#4412	`ExecuteAsync`	net6.0	1.31μs	0.508ns	1.83ns	0.0124	0	912 B
#4412	`ExecuteAsync`	netcoreapp3.1	1.43μs	0.694ns	2.6ns	0.0122	0	912 B
#4412	`ExecuteAsync`	net472	1.73μs	0.685ns	2.56ns	0.138	0.000858	875 B

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendAsync`	net6.0	3.82μs	1.45ns	5.42ns	0.0267	1.94 KB
master	`SendAsync`	netcoreapp3.1	4.53μs	2.79ns	10.4ns	0.0337	2.48 KB
master	`SendAsync`	net472	7.21μs	2.13ns	7.97ns	0.484	3.05 KB
#4412	`SendAsync`	net6.0	3.73μs	1.19ns	4.46ns	0.0262	1.94 KB
#4412	`SendAsync`	netcoreapp3.1	4.46μs	1.82ns	6.82ns	0.0316	2.48 KB
#4412	`SendAsync`	net472	7μs	2.18ns	8.43ns	0.481	3.05 KB

Benchmarks.Trace.ILoggerBenchmark - Faster 🎉 Same allocations ✔️

Faster 🎉 in #4412

Benchmark	base/diff	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.ILoggerBenchmark.EnrichedLog‑net6.0	1.115	1,415.20	1,268.87

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	1.42μs	0.359ns	1.34ns	0.0225	1.62 KB
master	`EnrichedLog`	netcoreapp3.1	1.85μs	1.14ns	4.28ns	0.022	1.62 KB
master	`EnrichedLog`	net472	2.38μs	1.67ns	6.25ns	0.244	1.54 KB
#4412	`EnrichedLog`	net6.0	1.27μs	0.623ns	2.33ns	0.0229	1.62 KB
#4412	`EnrichedLog`	netcoreapp3.1	1.98μs	1.45ns	5.22ns	0.0218	1.62 KB
#4412	`EnrichedLog`	net472	2.32μs	1.68ns	6.52ns	0.245	1.54 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`EnrichedLog`	net6.0	113μs	128ns	494ns	0.0571	0	4.21 KB
master	`EnrichedLog`	netcoreapp3.1	118μs	269ns	1.04μs	0	0	4.21 KB
master	`EnrichedLog`	net472	148μs	89.9ns	348ns	0.666	0.222	4.38 KB
#4412	`EnrichedLog`	net6.0	114μs	209ns	811ns	0.0567	0	4.21 KB
#4412	`EnrichedLog`	netcoreapp3.1	118μs	143ns	534ns	0.0587	0	4.21 KB
#4412	`EnrichedLog`	net472	147μs	70.2ns	263ns	0.661	0.22	4.38 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	2.97μs	1.05ns	3.92ns	0.0298	2.18 KB
master	`EnrichedLog`	netcoreapp3.1	3.93μs	1.8ns	6.74ns	0.0295	2.18 KB
master	`EnrichedLog`	net472	4.55μs	1.73ns	6.47ns	0.316	1.99 KB
#4412	`EnrichedLog`	net6.0	3.04μs	1.37ns	5.29ns	0.0303	2.18 KB
#4412	`EnrichedLog`	netcoreapp3.1	4.04μs	1.53ns	5.91ns	0.0281	2.18 KB
#4412	`EnrichedLog`	net472	4.57μs	1.98ns	7.42ns	0.315	1.99 KB

Benchmarks.Trace.RedisBenchmark - Slower ⚠️ Same allocations ✔️

Slower ⚠️ in #4412

Benchmark	diff/base	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.RedisBenchmark.SendReceive‑net472	1.133	1,945.40	2,203.76

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendReceive`	net6.0	1.34μs	0.806ns	3.01ns	0.0162	1.16 KB
master	`SendReceive`	netcoreapp3.1	1.66μs	1.52ns	5.91ns	0.0157	1.16 KB
master	`SendReceive`	net472	1.95μs	1.86ns	6.97ns	0.184	1.16 KB
#4412	`SendReceive`	net6.0	1.34μs	0.612ns	2.29ns	0.0162	1.16 KB
#4412	`SendReceive`	netcoreapp3.1	1.65μs	0.722ns	2.7ns	0.0158	1.16 KB
#4412	`SendReceive`	net472	2.21μs	3.7ns	14.3ns	0.184	1.16 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	2.55μs	1.13ns	4.22ns	0.0205	1.53 KB
master	`EnrichedLog`	netcoreapp3.1	3.45μs	2.73ns	9.83ns	0.0208	1.58 KB
master	`EnrichedLog`	net472	3.97μs	1.46ns	5.65ns	0.31	1.96 KB
#4412	`EnrichedLog`	net6.0	2.75μs	5.5ns	20.6ns	0.0205	1.53 KB
#4412	`EnrichedLog`	netcoreapp3.1	3.54μs	2.74ns	10.6ns	0.0213	1.58 KB
#4412	`EnrichedLog`	net472	4.14μs	0.515ns	1.86ns	0.31	1.96 KB

Benchmarks.Trace.SpanBenchmark - Slower ⚠️ Same allocations ✔️

Slower ⚠️ in #4412

Benchmark	diff/base	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.SpanBenchmark.StartFinishSpan‑net6.0	1.159	394.29	457.08

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`StartFinishSpan`	net6.0	394ns	0.241ns	0.902ns	0.00747	536 B
master	`StartFinishSpan`	netcoreapp3.1	563ns	0.248ns	0.928ns	0.00707	536 B
master	`StartFinishSpan`	net472	571ns	0.403ns	1.56ns	0.0854	538 B
master	`StartFinishScope`	net6.0	549ns	0.113ns	0.424ns	0.00912	656 B
master	`StartFinishScope`	netcoreapp3.1	753ns	1.82ns	6.29ns	0.0091	656 B
master	`StartFinishScope`	net472	827ns	0.178ns	0.668ns	0.098	618 B
#4412	`StartFinishSpan`	net6.0	457ns	0.164ns	0.637ns	0.00752	536 B
#4412	`StartFinishSpan`	netcoreapp3.1	602ns	0.757ns	2.83ns	0.00721	536 B
#4412	`StartFinishSpan`	net472	602ns	0.154ns	0.597ns	0.0854	538 B
#4412	`StartFinishScope`	net6.0	569ns	0.159ns	0.593ns	0.00923	656 B
#4412	`StartFinishScope`	netcoreapp3.1	688ns	0.502ns	1.88ns	0.00895	656 B
#4412	`StartFinishScope`	net472	824ns	1.19ns	4.6ns	0.098	618 B

Benchmarks.Trace.TraceAnnotationsBenchmark - Slower ⚠️ Same allocations ✔️

Slower ⚠️ in #4412

Benchmark	diff/base	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.TraceAnnotationsBenchmark.RunOnMethodBegin‑net472	1.135	896.75	1,018.19

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`RunOnMethodBegin`	net6.0	653ns	0.43ns	1.66ns	0.00924	656 B
master	`RunOnMethodBegin`	netcoreapp3.1	837ns	0.339ns	1.22ns	0.00864	656 B
master	`RunOnMethodBegin`	net472	897ns	1.2ns	4.49ns	0.0978	618 B
#4412	`RunOnMethodBegin`	net6.0	591ns	0.176ns	0.683ns	0.00922	656 B
#4412	`RunOnMethodBegin`	netcoreapp3.1	922ns	2.35ns	8.81ns	0.00859	656 B
#4412	`RunOnMethodBegin`	net472	1.02μs	0.302ns	1.17ns	0.0979	618 B

andrewlock · 2023-07-21T18:59:44Z

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 (4412) (11.282M)   : 0, 11281787
    master (11.376M)   : 0, 11375532
    benchmarks/2.38.0 (11.236M)   : 0, 11236366
    benchmarks/2.9.0 (11.394M)   : 0, 11393825

    section Automatic
    This PR (4412) (7.713M)   : 0, 7712668
    master (7.919M)   : 0, 7918955
    benchmarks/2.38.0 (7.801M)   : 0, 7800760
    benchmarks/2.9.0 (8.144M)   : 0, 8144140

    section Trace stats
    master (8.062M)   : 0, 8062003
    benchmarks/2.38.0 (8.108M)   : 0, 8108094

    section Manual
    This PR (4412) (9.916M)   : 0, 9915568
    master (10.217M)   : 0, 10216995
    benchmarks/2.38.0 (9.801M)   : 0, 9801019

    section Manual + Automatic
    This PR (4412) (7.359M)   : 0, 7358980
    master (7.571M)   : 0, 7570528
    benchmarks/2.38.0 (7.496M)   : 0, 7495876

    section Version Conflict
    master (6.874M)   : 0, 6874186
    benchmarks/2.38.0 (6.909M)   : 0, 6909422

gantt
    title Throughput Linux arm64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (4412) (9.622M)   : 0, 9622268
    master (9.563M)   : 0, 9563022
    benchmarks/2.38.0 (9.307M)   : 0, 9307309
    benchmarks/2.9.0 (9.594M)   : 0, 9593733

    section Automatic
    This PR (4412) (6.875M)   : 0, 6875169
    master (6.604M)   : 0, 6603775
    benchmarks/2.38.0 (6.542M)   : 0, 6541724

    section Trace stats
    master (6.992M)   : 0, 6991908
    benchmarks/2.38.0 (6.849M)   : 0, 6848890

    section Manual
    This PR (4412) (8.602M)   : 0, 8601875
    master (8.331M)   : 0, 8330731
    benchmarks/2.38.0 (8.527M)   : 0, 8527309

    section Manual + Automatic
    This PR (4412) (6.125M)   : 0, 6125436
    master (6.117M)   : 0, 6116621
    benchmarks/2.38.0 (6.218M)   : 0, 6218231

    section Version Conflict
    master (5.781M)   : 0, 5781397
    benchmarks/2.38.0 (5.797M)   : 0, 5796642

gantt
    title Throughput Windows x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (4412) (10.489M)   : 0, 10489440
    master (9.694M)   : 0, 9694175
    benchmarks/2.38.0 (9.989M)   : 0, 9989031
    benchmarks/2.9.0 (9.987M)   : 0, 9986795

    section Automatic
    This PR (4412) (7.396M)   : 0, 7396288
    master (7.016M)   : 0, 7015684
    benchmarks/2.38.0 (7.205M)   : 0, 7205091
    benchmarks/2.9.0 (7.318M)   : 0, 7318392

    section Trace stats
    master (7.375M)   : 0, 7375236
    benchmarks/2.38.0 (7.525M)   : 0, 7525282

    section Manual
    This PR (4412) (9.147M)   : 0, 9146848
    master (8.768M)   : 0, 8767658
    benchmarks/2.38.0 (8.930M)   : 0, 8929797

    section Manual + Automatic
    This PR (4412) (7.285M)   : 0, 7285285
    master (6.836M)   : 0, 6835550
    benchmarks/2.38.0 (6.992M)   : 0, 6992269

    section Version Conflict
    master (6.216M)   : 0, 6215629
    benchmarks/2.38.0 (6.384M)   : 0, 6384465

gantt
    title Throughput Linux x64 (ASM) (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (4412) (7.661M)   : 0, 7661483
    master (7.453M)   : 0, 7453178
    benchmarks/2.38.0 (7.409M)   : 0, 7408569
    benchmarks/2.9.0 (7.712M)   : 0, 7712409

    section No attack
    This PR (4412) (2.198M)   : 0, 2198200
    master (2.167M)   : 0, 2166529
    benchmarks/2.38.0 (2.172M)   : 0, 2172364
    benchmarks/2.9.0 (3.214M)   : 0, 3213626

    section Attack
    This PR (4412) (1.740M)   : 0, 1740396
    master (1.718M)   : 0, 1718268
    benchmarks/2.38.0 (1.734M)   : 0, 1733807
    benchmarks/2.9.0 (2.542M)   : 0, 2541537

    section Blocking
    This PR (4412) (3.452M)   : 0, 3451613
    master (3.509M)   : 0, 3509485
    benchmarks/2.38.0 (3.442M)   : 0, 3442478

datadog-ddstaging · 2023-08-03T23:06:13Z

Datadog Report

Branch report: dudik/upload-symbols
Commit report: a48838a

❌ dd-trace-dotnet: 3615 Failed (1 Known Flaky), 0 New Flaky, 173075 Passed, 1156 Skipped, 56m 2.56s Wall Time