"Fix" timeouts in SSI run #6117

andrewlock · 2024-10-04T14:02:20Z

Summary of changes

Set _NO_DEBUG_HEAP=1 to fix a timeout issue that only happens on .NET 6, on Windows, on the scheduled SSI run

Reason for change

We have a weird issue. Ever since #5240 was merged, the scheduled SSI run has been failing on .NET 6 WindowsIntegrationTests. The failure is a timeout, because grabbing a stacktrace becomes crazy expensive - it takes ~10s to call Environment.StackTrace.

We (@kevingosse) have looked through multiple dumps, and in all cases we're in the middle of ConvertPortablePDB, which is doing a ultimately calling RtlCompareMemoryUlong.

This method is basically scanning the memory to make sure that everything is set to 0xFEEEFEEE - presumably it's the sentinel value that the heap uses to detect corruption.

Example stack trace

[0x0]   ntdll!RtlCompareMemoryUlong+0x10   0x40f31971a0   0x7ffea493ed15   
[0x1]   ntdll!RtlpAllocateHeap+0x9b5   0x40f31971b0   0x7ffea493c4f9   
[0x2]   ntdll!RtlpAllocateHeapInternal+0x6c9   0x40f3197380   0x7ffea4a1c7f6   
[0x3]   ntdll!RtlDebugAllocateHeap+0xf2   0x40f3197490   0x7ffea49d3762   
[0x4]   ntdll!RtlpAllocateHeap+0x95402   0x40f31974f0   0x7ffea493c4f9   
[0x5]   ntdll!RtlpAllocateHeapInternal+0x6c9   0x40f31976c0   0x7ffe5dbd9ad8   
[0x6]   Microsoft_DiaSymReader_Native_amd64!malloc_base+0x44   0x40f31977d0   0x7ffe5dbc2cef   
[0x7]   Microsoft_DiaSymReader_Native_amd64!operator new+0x1f   0x40f3197800   0x7ffe5dbc3201   
[0x8]   Microsoft_DiaSymReader_Native_amd64!operator new+0x9   0x40f3197830   0x7ffe5dcf1754   
[0x9]   Microsoft_DiaSymReader_Native_amd64!CDebugSSubSectionEnum::Get+0x154   0x40f3197860   0x7ffe5dcc2b79   
[0xa]   Microsoft_DiaSymReader_Native_amd64!Mod1::fUpdateTiOrIdReferencedByNonSyms+0x119   0x40f3197890   0x7ffe5dcc4a2b   
[0xb]   Microsoft_DiaSymReader_Native_amd64!Mod1::processC13+0x14b   0x40f3197920   0x7ffe5dcc165e   
[0xc]   Microsoft_DiaSymReader_Native_amd64!Mod1::fProcessSyms+0x126e   0x40f3197bd0   0x7ffe5dcc2a3b   
[0xd]   Microsoft_DiaSymReader_Native_amd64!Mod1::fUpdateSyms+0x1b   0x40f3197c90   0x7ffe5dcb81cb   
[0xe]   Microsoft_DiaSymReader_Native_amd64!Mod1::Close+0x1eb   0x40f3197cc0   0x7ffe5dc9d3d3   
[0xf]   Microsoft_DiaSymReader_Native_amd64!PortablePDB::ConvertPortablePDB+0x463   0x40f3197d30   0x7ffe5dc86c6e   
[0x10]   Microsoft_DiaSymReader_Native_amd64!PDB1::OpenPortablePDB+0x9e   0x40f3198670   0x7ffe5dc85c41   
[0x11]   Microsoft_DiaSymReader_Native_amd64!PDB1::OpenEx2W+0x621   0x40f31986e0   0x7ffe5dc875fe   
[0x12]   Microsoft_DiaSymReader_Native_amd64!PDB1::OpenValidate4+0x8e   0x40f31987a0   0x7ffe5dcd2a2b   
[0x13]   Microsoft_DiaSymReader_Native_amd64!LOCATOR::FOpenValidate4+0x8b   0x40f3198850   0x7ffe5dcd1c34   
[0x14]   Microsoft_DiaSymReader_Native_amd64!LOCATOR::FLocatePdb+0x144   0x40f3198f00   0x7ffe5dc996da   
[0x15]   Microsoft_DiaSymReader_Native_amd64!PDBCommon::OpenValidate7+0xea   0x40f3199ff0   0x7ffe5dbe847b   
[0x16]   Microsoft_DiaSymReader_Native_amd64!CDiaDataSource::loadDataForExeHelper+0xab   0x40f319ae00   0x7ffe5dbe8305   
[0x17]   Microsoft_DiaSymReader_Native_amd64!CDiaDataSource::loadDataForExeEx3+0x35   0x40f319af90   0x7ffe5dbb8c78   
[0x18]   Microsoft_DiaSymReader_Native_amd64!sh::CDiaWrapper::Create+0x158   0x40f319afe0   0x7ffe5dba9bf4   
[0x19]   Microsoft_DiaSymReader_Native_amd64!sh::SymReader::InitWithRestrictedSearch+0x94   0x40f319b060   0x7ffe5dbb092e   
[0x1a]   Microsoft_DiaSymReader_Native_amd64!sh::SymBinder::GetReaderForFile+0xae   0x40f319b090   0x7ffe8b40852e   
[0x1b]   coreclr!Module::GetISymUnmanagedReader+0x7ce   0x40f319b0d0   0x7ffe8b4089d2   
[0x1c]   coreclr!Module::GetISymUnmanagedReaderNoThrow+0x72   0x40f319b320   0x7ffe8b4153e3   
[0x1d]   coreclr!DebugStackTrace::GetStackFramesInternal+0xa83   0x40f319b3c0   0x7ffe607bb1c2   
[0x1e]   System_Private_CoreLib!System.Diagnostics.StackFrameHelper.InitializeSourceInfo+0x42   0x40f319be00   0x7ffe607bb912   
[0x1f]   System_Private_CoreLib!System.Diagnostics.StackTrace.CaptureStackTrace+0x42   0x40f319bf00   0x7ffe607bba03   
[0x20]   System_Private_CoreLib!System.Diagnostics.StackTrace..ctor+0x13   0x40f319bf60   0x7ffe605b431c   
[0x21]   System_Private_CoreLib!System.Environment.get_StackTrace+0x1c   0x40f319bf90   0x7ffe2bb15da0   
[0x22]   Datadog_Trace!Datadog.Trace.Logging.DatadogLogging.GetLoggerFor+0x80   0x40f319bfc0   0x257516f648550000   
[0x23]   0x257516f648550000!+   0x40f319bfc8   0x1c8fc9e9000   
[0x24]   0x1c8fc9e9000!+   0x40f319bfd0   0x1c8fd1951c0   
[0x25]   0x1c8fd1951c0!+   0x40f319bfd8   0x1c8fd1951c0   
[0x26]   0x1c8fd1951c0!+   0x40f319bfe0   0x8b267570   
[0x27]   0x8b267570!+   0x40f319bfe8   0x7ffe2b8085a8   
[0x28]   0x7ffe2b8085a8!+   0x40f319bff0   0x40f319c2c8   
[0x29]   0x40f319c2c8!+   0x40f319bff8   0x1c880076070   
[0x2a]   0x1c880076070!+   0x40f319c000   0x0

What is really weird is the fact that this only happens

When the SSI variables are enabled (DD_INJECTION_ENABLED is set)
When procdump is attached to capture dumps
When it's .NET 6, Windows (not .NET 7+, not Linux)

Testing shows that not attaching procdump solves it.

Even more confusing, I can reproduce locally using the following:

$env:enable_crash_dumps="true"
.\tracer\build.ps1 BuildTracerHome
.\tracer\build.ps1 BuildAndRunWindowsIntegrationTests --framework net6.0 --filter HttpMessageHandlerTests.HttpClient_SubmitsTraces --sample-name Samples.HttpMessageHandler

Note that locally I don't even need to enable the SSI variables 😕

No, none of this makes any sense to me, I've been digging into this for days now 🤦‍♂️

The only thing that 100% causes it is procdump. And setting _NO_DEBUG_HEAP=1 disables the debug allocate heap, which solves it.

I'd love to figure this one out, but given this doesn't seem like it should be a prod issue, taking the easy option right now, until we can work out what it is about #5240 that it doesn't like 🤷‍♂️

Test coverage

I'll trigger a full SSI run to make sure it is solved

Other details

Note that in the Windows integration tests, the profiler isn't actually available, because we don't download it. But that doesn't seem to make a difference, because locally when the profiler is there I still repro

…ling it

datadog-ddstaging · 2024-10-04T14:27:14Z

Datadog Report

Branch report: andrew/fix-timeouts-in-ssi
Commit report: fe1605a
Test service: dd-trace-dotnet

✅ 0 Failed, 371461 Passed, 2727 Skipped, 50h 7m 54.81s Total Time

andrewlock · 2024-10-04T14:34:21Z

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 (6117) - mean (71ms)  : 67, 74
     .   : milestone, 71,
    master - mean (70ms)  : 68, 73
     .   : milestone, 70,

    section CallTarget+Inlining+NGEN
    This PR (6117) - mean (1,109ms)  : 1085, 1134
     .   : milestone, 1109,
    master - mean (1,109ms)  : 1085, 1132
     .   : milestone, 1109,

gantt
    title Execution time (ms) FakeDbCommand (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6117) - mean (111ms)  : 107, 115
     .   : milestone, 111,
    master - mean (110ms)  : 107, 114
     .   : milestone, 110,

    section CallTarget+Inlining+NGEN
    This PR (6117) - mean (771ms)  : 754, 788
     .   : milestone, 771,
    master - mean (773ms)  : 756, 790
     .   : milestone, 773,

gantt
    title Execution time (ms) FakeDbCommand (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6117) - mean (93ms)  : 90, 96
     .   : milestone, 93,
    master - mean (93ms)  : 89, 97
     .   : milestone, 93,

    section CallTarget+Inlining+NGEN
    This PR (6117) - mean (728ms)  : 712, 744
     .   : milestone, 728,
    master - mean (731ms)  : 710, 753
     .   : milestone, 731,

gantt
    title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6117) - mean (191ms)  : 188, 194
     .   : milestone, 191,
    master - mean (190ms)  : 187, 194
     .   : milestone, 190,

    section CallTarget+Inlining+NGEN
    This PR (6117) - mean (1,197ms)  : 1174, 1220
     .   : milestone, 1197,
    master - mean (1,200ms)  : 1173, 1227
     .   : milestone, 1200,

gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6117) - mean (277ms)  : 273, 282
     .   : milestone, 277,
    master - mean (276ms)  : 272, 281
     .   : milestone, 276,

    section CallTarget+Inlining+NGEN
    This PR (6117) - mean (939ms)  : 921, 957
     .   : milestone, 939,
    master - mean (940ms)  : 923, 957
     .   : milestone, 940,

gantt
    title Execution time (ms) HttpMessageHandler (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6117) - mean (266ms)  : 263, 270
     .   : milestone, 266,
    master - mean (265ms)  : 262, 269
     .   : milestone, 265,

    section CallTarget+Inlining+NGEN
    This PR (6117) - mean (927ms)  : 909, 945
     .   : milestone, 927,
    master - mean (924ms)  : 904, 944
     .   : milestone, 924,

andrewlock · 2024-10-04T15:21:22Z

Benchmarks Report for tracer 🐌

Benchmarks for #6117 compared to master:

3 benchmarks are faster, with geometric mean 1.165
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	7.94μs	44.6ns	289ns	0.0124	0.00413	0	5.42 KB
master	`StartStopWithChild`	netcoreapp3.1	10.1μs	56.5ns	357ns	0.0246	0.00985	0	5.62 KB
master	`StartStopWithChild`	net472	16.2μs	51.3ns	178ns	1.05	0.331	0.0969	6.08 KB
#6117	`StartStopWithChild`	net6.0	7.75μs	41.1ns	218ns	0.0157	0.00786	0	5.43 KB
#6117	`StartStopWithChild`	netcoreapp3.1	10μs	41.1ns	169ns	0.0243	0.00973	0	5.62 KB
#6117	`StartStopWithChild`	net472	16μs	29.1ns	113ns	1.01	0.306	0.0966	6.06 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`WriteAndFlushEnrichedTraces`	net6.0	466μs	154ns	532ns	0	2.7 KB
master	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	626μs	250ns	900ns	0	2.7 KB
master	`WriteAndFlushEnrichedTraces`	net472	829μs	349ns	1.26μs	0.411	3.3 KB
#6117	`WriteAndFlushEnrichedTraces`	net6.0	482μs	247ns	957ns	0	2.7 KB
#6117	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	648μs	471ns	1.76μs	0	2.7 KB
#6117	`WriteAndFlushEnrichedTraces`	net472	836μs	543ns	2.1μs	0.414	3.3 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendRequest`	net6.0	192μs	1.12μs	10.5μs	0.194	18.45 KB
master	`SendRequest`	netcoreapp3.1	209μs	1μs	4.38μs	0.228	20.61 KB
master	`SendRequest`	net472	0ns	0ns	0ns	0	0 b
#6117	`SendRequest`	net6.0	192μs	995ns	4.87μs	0.192	18.45 KB
#6117	`SendRequest`	netcoreapp3.1	216μs	1.21μs	8.57μs	0.213	20.61 KB
#6117	`SendRequest`	net472	0.000218ns	9.9E‑05ns	0.000384ns	0	0 b

Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Same speed ✔️ Fewer allocations 🎉

Fewer allocations 🎉 in #6117

Benchmark	Base Allocated	Diff Allocated	Change	Change %
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑net6.0	41.63 KB	41.39 KB	-243 B	-0.58%

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Gen 2	Allocated
master	`WriteAndFlushEnrichedTraces`	net6.0	568μs	2.59μs	9.68μs	0.587	0	0	41.63 KB
master	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	673μs	2.36μs	8.85μs	0.336	0	0	41.61 KB
master	`WriteAndFlushEnrichedTraces`	net472	843μs	3.65μs	13.7μs	8.08	2.55	0.425	53.31 KB
#6117	`WriteAndFlushEnrichedTraces`	net6.0	566μs	1.64μs	6.35μs	0.553	0	0	41.39 KB
#6117	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	657μs	2.79μs	10.8μs	0.329	0	0	41.75 KB
#6117	`WriteAndFlushEnrichedTraces`	net472	855μs	4μs	15.5μs	8.33	2.5	0.417	53.31 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`ExecuteNonQuery`	net6.0	1.32μs	1.21ns	4.67ns	0.0139	0	1.02 KB
master	`ExecuteNonQuery`	netcoreapp3.1	1.74μs	1.44ns	5.59ns	0.0131	0	1.02 KB
master	`ExecuteNonQuery`	net472	2.08μs	1.62ns	6.26ns	0.156	0.00105	987 B
#6117	`ExecuteNonQuery`	net6.0	1.38μs	1.41ns	5.44ns	0.0139	0	1.02 KB
#6117	`ExecuteNonQuery`	netcoreapp3.1	1.72μs	1.74ns	6.28ns	0.0138	0	1.02 KB
#6117	`ExecuteNonQuery`	net472	1.99μs	1.81ns	6.76ns	0.156	0	987 B

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`CallElasticsearch`	net6.0	1.21μs	1.05ns	3.64ns	0.0134	976 B
master	`CallElasticsearch`	netcoreapp3.1	1.54μs	1.42ns	5.33ns	0.0131	976 B
master	`CallElasticsearch`	net472	2.49μs	0.918ns	3.43ns	0.158	995 B
master	`CallElasticsearchAsync`	net6.0	1.26μs	0.575ns	2.15ns	0.0132	952 B
master	`CallElasticsearchAsync`	netcoreapp3.1	1.68μs	0.647ns	2.42ns	0.0136	1.02 KB
master	`CallElasticsearchAsync`	net472	2.59μs	1.66ns	6.42ns	0.167	1.05 KB
#6117	`CallElasticsearch`	net6.0	1.18μs	1.68ns	6.27ns	0.0137	976 B
#6117	`CallElasticsearch`	netcoreapp3.1	1.54μs	0.573ns	2.15ns	0.0131	976 B
#6117	`CallElasticsearch`	net472	2.52μs	1.05ns	4.08ns	0.158	995 B
#6117	`CallElasticsearchAsync`	net6.0	1.33μs	1.38ns	5.33ns	0.0134	952 B
#6117	`CallElasticsearchAsync`	netcoreapp3.1	1.62μs	0.594ns	2.3ns	0.0137	1.02 KB
#6117	`CallElasticsearchAsync`	net472	2.58μs	1.96ns	7.58ns	0.167	1.05 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`ExecuteAsync`	net6.0	1.36μs	0.299ns	1.08ns	0.0129	952 B
master	`ExecuteAsync`	netcoreapp3.1	1.69μs	0.458ns	1.65ns	0.0127	952 B
master	`ExecuteAsync`	net472	1.81μs	1.11ns	4.3ns	0.145	915 B
#6117	`ExecuteAsync`	net6.0	1.22μs	4.92ns	19.1ns	0.0132	952 B
#6117	`ExecuteAsync`	netcoreapp3.1	1.62μs	6.72ns	26ns	0.0127	952 B
#6117	`ExecuteAsync`	net472	1.81μs	0.678ns	2.62ns	0.145	915 B

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendAsync`	net6.0	4.42μs	2.15ns	7.75ns	0.0307	2.22 KB
master	`SendAsync`	netcoreapp3.1	5.05μs	2.85ns	10.7ns	0.0377	2.76 KB
master	`SendAsync`	net472	7.75μs	1.68ns	6.52ns	0.496	3.15 KB
#6117	`SendAsync`	net6.0	4.29μs	1.54ns	5.76ns	0.0301	2.22 KB
#6117	`SendAsync`	netcoreapp3.1	4.96μs	3.72ns	14.4ns	0.0374	2.76 KB
#6117	`SendAsync`	net472	7.71μs	1.72ns	6.67ns	0.497	3.15 KB

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

Faster 🎉 in #6117

Benchmark	base/diff	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.ILoggerBenchmark.EnrichedLog‑netcoreapp3.1	1.128	2,399.67	2,126.43

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	1.46μs	0.96ns	3.46ns	0.0234	1.64 KB
master	`EnrichedLog`	netcoreapp3.1	2.4μs	0.769ns	2.77ns	0.0227	1.64 KB
master	`EnrichedLog`	net472	2.51μs	1.53ns	5.93ns	0.25	1.57 KB
#6117	`EnrichedLog`	net6.0	1.6μs	0.922ns	3.45ns	0.023	1.64 KB
#6117	`EnrichedLog`	netcoreapp3.1	2.13μs	0.99ns	3.83ns	0.0224	1.64 KB
#6117	`EnrichedLog`	net472	2.45μs	0.806ns	3.12ns	0.249	1.57 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	114μs	164ns	636ns	0.057	0	4.28 KB
master	`EnrichedLog`	netcoreapp3.1	120μs	299ns	1.16μs	0.0598	0	4.28 KB
master	`EnrichedLog`	net472	148μs	167ns	648ns	0.664	0.221	4.46 KB
#6117	`EnrichedLog`	net6.0	114μs	141ns	546ns	0.0577	0	4.28 KB
#6117	`EnrichedLog`	netcoreapp3.1	119μs	143ns	555ns	0	0	4.28 KB
#6117	`EnrichedLog`	net472	146μs	77ns	288ns	0.656	0.219	4.46 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	3.12μs	3.23ns	12.1ns	0.0305	2.2 KB
master	`EnrichedLog`	netcoreapp3.1	4.62μs	1.16ns	4.51ns	0.0301	2.2 KB
master	`EnrichedLog`	net472	4.81μs	2.07ns	8.01ns	0.319	2.02 KB
#6117	`EnrichedLog`	net6.0	3.04μs	0.853ns	3.08ns	0.0305	2.2 KB
#6117	`EnrichedLog`	netcoreapp3.1	4.28μs	1.39ns	5.22ns	0.03	2.2 KB
#6117	`EnrichedLog`	net472	4.86μs	1.32ns	4.93ns	0.32	2.02 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`SendReceive`	net6.0	1.41μs	0.7ns	2.71ns	0.0163	0	1.14 KB
master	`SendReceive`	netcoreapp3.1	1.8μs	0.806ns	3.12ns	0.0154	0	1.14 KB
master	`SendReceive`	net472	2.09μs	0.826ns	3.2ns	0.183	0.00103	1.16 KB
#6117	`SendReceive`	net6.0	1.4μs	0.974ns	3.77ns	0.016	0	1.14 KB
#6117	`SendReceive`	netcoreapp3.1	1.84μs	1.71ns	6.61ns	0.0156	0	1.14 KB
#6117	`SendReceive`	net472	1.97μs	0.977ns	3.79ns	0.183	0	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.73μs	0.984ns	3.81ns	0.0218	1.6 KB
master	`EnrichedLog`	netcoreapp3.1	3.74μs	0.987ns	3.56ns	0.0224	1.65 KB
master	`EnrichedLog`	net472	4.24μs	2.31ns	8.95ns	0.323	2.04 KB
#6117	`EnrichedLog`	net6.0	2.73μs	0.663ns	2.57ns	0.0217	1.6 KB
#6117	`EnrichedLog`	netcoreapp3.1	3.76μs	7.82ns	30.3ns	0.0224	1.65 KB
#6117	`EnrichedLog`	net472	4.23μs	1.08ns	4.18ns	0.322	2.04 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`StartFinishSpan`	net6.0	407ns	0.473ns	1.83ns	0.00806	576 B
master	`StartFinishSpan`	netcoreapp3.1	560ns	0.913ns	3.53ns	0.00777	576 B
master	`StartFinishSpan`	net472	647ns	0.579ns	2.24ns	0.0918	578 B
master	`StartFinishScope`	net6.0	556ns	0.299ns	1.16ns	0.00985	696 B
master	`StartFinishScope`	netcoreapp3.1	722ns	0.622ns	2.41ns	0.00937	696 B
master	`StartFinishScope`	net472	888ns	3.51ns	13.6ns	0.104	658 B
#6117	`StartFinishSpan`	net6.0	399ns	0.148ns	0.533ns	0.00815	576 B
#6117	`StartFinishSpan`	netcoreapp3.1	534ns	0.998ns	3.87ns	0.00774	576 B
#6117	`StartFinishSpan`	net472	705ns	0.439ns	1.7ns	0.0918	578 B
#6117	`StartFinishScope`	net6.0	507ns	0.238ns	0.921ns	0.00985	696 B
#6117	`StartFinishScope`	netcoreapp3.1	714ns	0.611ns	2.37ns	0.00965	696 B
#6117	`StartFinishScope`	net472	879ns	1.08ns	3.9ns	0.104	658 B

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

Faster 🎉 in #6117

Benchmark	base/diff	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.TraceAnnotationsBenchmark.RunOnMethodBegin‑net6.0	1.221	746.46	611.52
Benchmarks.Trace.TraceAnnotationsBenchmark.RunOnMethodBegin‑netcoreapp3.1	1.147	1,029.03	897.12

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`RunOnMethodBegin`	net6.0	747ns	0.383ns	1.48ns	0.00978	696 B
master	`RunOnMethodBegin`	netcoreapp3.1	1.03μs	0.455ns	1.76ns	0.00935	696 B
master	`RunOnMethodBegin`	net472	1.09μs	0.189ns	0.73ns	0.104	658 B
#6117	`RunOnMethodBegin`	net6.0	612ns	0.489ns	1.89ns	0.00975	696 B
#6117	`RunOnMethodBegin`	netcoreapp3.1	896ns	0.731ns	2.83ns	0.00926	696 B
#6117	`RunOnMethodBegin`	net472	1.08μs	0.591ns	2.21ns	0.104	658 B

andrewlock · 2024-10-04T17:31:08Z

Throughput/Crank Report ⚡

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 (6117) (11.115M)   : 0, 11114827
    master (11.067M)   : 0, 11067199
    benchmarks/2.9.0 (11.081M)   : 0, 11080577

    section Automatic
    This PR (6117) (7.367M)   : 0, 7366927
    master (7.314M)   : 0, 7314309
    benchmarks/2.9.0 (7.732M)   : 0, 7732233

    section Trace stats
    master (7.522M)   : 0, 7522105

    section Manual
    master (11.089M)   : 0, 11089039

    section Manual + Automatic
    This PR (6117) (6.826M)   : 0, 6826343
    master (6.818M)   : 0, 6818236

    section DD_TRACE_ENABLED=0
    master (10.233M)   : 0, 10233045

gantt
    title Throughput Linux arm64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (6117) (9.427M)   : 0, 9426881
    master (9.628M)   : 0, 9628028
    benchmarks/2.9.0 (9.798M)   : 0, 9798067

    section Automatic
    This PR (6117) (6.537M)   : 0, 6536952
    master (6.472M)   : 0, 6472350

    section Trace stats
    master (6.828M)   : 0, 6827760

    section Manual
    master (9.756M)   : 0, 9756410

    section Manual + Automatic
    This PR (6117) (6.101M)   : 0, 6100792
    master (6.092M)   : 0, 6091664

    section DD_TRACE_ENABLED=0
    master (9.056M)   : 0, 9056055

gantt
    title Throughput Windows x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (6117) (10.291M)   : 0, 10291462
    master (10.362M)   : 0, 10362363
    benchmarks/2.9.0 (10.067M)   : 0, 10067315

    section Automatic
    This PR (6117) (6.704M)   : 0, 6704131
    master (6.848M)   : 0, 6848211
    benchmarks/2.9.0 (7.552M)   : 0, 7552193

    section Trace stats
    master (7.513M)   : 0, 7513310

    section Manual
    master (10.234M)   : 0, 10233822

    section Manual + Automatic
    This PR (6117) (6.082M)   : 0, 6081729
    master (6.352M)   : 0, 6351972

    section DD_TRACE_ENABLED=0
    master (9.543M)   : 0, 9543014

## Summary of changes Fix failing .NET Core 2.1 Windows integration tests ## Reason for change The .NET Core 2.1 Windows Integration tests are failing ## Implementation details After merging #6117 (to fix a weird issue in the .NET 6 windows integration tests related to procdump), we started getting failures in .NET Core 2.1. This is almost certainly a bug in the runtime, and as it's a CI-only issue, trivially fixing by not setting the variable ## Test coverage [Ran a full test here and all ok](https://dev.azure.com/datadoghq/dd-trace-dotnet/_build/results?buildId=165403&view=results)

andrewlock added 2 commits October 4, 2024 14:32

Add check that the profiler library path is set and exists before cal…

07daa30

…ling it

"fix" the issue

fe1605a

andrewlock added the area:builds project files, build scripts, pipelines, versioning, releases, packages label Oct 4, 2024

andrewlock requested a review from a team as a code owner October 4, 2024 14:02

kevingosse approved these changes Oct 7, 2024

View reviewed changes

andrewlock merged commit 34d8aa3 into master Oct 8, 2024
79 checks passed

andrewlock deleted the andrew/fix-timeouts-in-ssi branch October 8, 2024 18:12

github-actions bot added this to the vNext-v3 milestone Oct 8, 2024

andrewlock mentioned this pull request Oct 9, 2024

Fix crashes on .NET Core 2.1 CI #6139

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

"Fix" timeouts in SSI run #6117

"Fix" timeouts in SSI run #6117

andrewlock commented Oct 4, 2024 •

edited

Loading

datadog-ddstaging bot commented Oct 4, 2024 •

edited

Loading

andrewlock commented Oct 4, 2024

andrewlock commented Oct 4, 2024

Raw results

Raw results

Raw results

Fewer allocations 🎉 in #6117

Raw results

Raw results

Raw results

Raw results

Raw results

Faster 🎉 in #6117

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Faster 🎉 in #6117

Raw results

andrewlock commented Oct 4, 2024

"Fix" timeouts in SSI run #6117

"Fix" timeouts in SSI run #6117

Conversation

andrewlock commented Oct 4, 2024 • edited Loading

Summary of changes

Reason for change

Test coverage

Other details

datadog-ddstaging bot commented Oct 4, 2024 • edited Loading

Datadog Report

andrewlock commented Oct 4, 2024

Execution-Time Benchmarks Report ⏱️

andrewlock commented Oct 4, 2024

Benchmarks Report for tracer 🐌

Benchmark details

Raw results

Raw results

Raw results

Fewer allocations 🎉 in #6117

Raw results

Raw results

Raw results

Raw results

Raw results

Faster 🎉 in #6117

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Faster 🎉 in #6117

Raw results

andrewlock commented Oct 4, 2024

Throughput/Crank Report ⚡

andrewlock commented Oct 4, 2024 •

edited

Loading

datadog-ddstaging bot commented Oct 4, 2024 •

edited

Loading