Closed andrewlock closed 3 months ago
datadog-ddstaging[bot]
commented
3 months ago Branch report: andrew/ci/try-fixing-macos-flake
Commit report: 79b00ae
Test service: dd-trace-dotnet
:white_check_mark: 0 Failed, 345502 Passed, 1541 Skipped, 13h 43m 43.67s Total Time :hourglass: 1 Performance Regression
Baseline - Samples.HttpMessageHandler.windows.netcoreapp31.json.scenarios 284.37ms (+7.72ms, +3%) - Details
andrewlock
commented
3 months ago 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:
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 (5735) - mean (74ms) : 64, 84
. : milestone, 74,
master - mean (70ms) : 68, 72
. : milestone, 70,
section CallTarget+Inlining+NGEN
This PR (5735) - mean (920ms) : 881, 960
. : milestone, 920,
master - mean (912ms) : 891, 934
. : milestone, 912,
gantt
title Execution time (ms) FakeDbCommand (.NET Core 3.1)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (5735) - mean (111ms) : 107, 115
. : milestone, 111,
master - mean (109ms) : 107, 112
. : milestone, 109,
section CallTarget+Inlining+NGEN
This PR (5735) - mean (640ms) : 623, 656
. : milestone, 640,
master - mean (638ms) : 620, 656
. : milestone, 638,
gantt
title Execution time (ms) FakeDbCommand (.NET 6)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (5735) - mean (93ms) : 90, 96
. : milestone, 93,
master - mean (93ms) : 90, 97
. : milestone, 93,
section CallTarget+Inlining+NGEN
This PR (5735) - mean (595ms) : 580, 610
. : milestone, 595,
master - mean (590ms) : 573, 607
. : milestone, 590,
gantt
title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (5735) - mean (191ms) : 189, 194
. : milestone, 191,
master - mean (190ms) : 187, 194
. : milestone, 190,
section CallTarget+Inlining+NGEN
This PR (5735) - mean (1,020ms) : 990, 1050
. : milestone, 1020,
master - mean (1,017ms) : 983, 1051
. : milestone, 1017,
gantt
title Execution time (ms) HttpMessageHandler (.NET Core 3.1)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (5735) - mean (284ms) : 280, 289
. : milestone, 284,
master - mean (276ms) : 271, 280
. : milestone, 276,
section CallTarget+Inlining+NGEN
This PR (5735) - mean (841ms) : 816, 866
. : milestone, 841,
master - mean (824ms) : 791, 857
. : milestone, 824,
gantt
title Execution time (ms) HttpMessageHandler (.NET 6)
dateFormat X
axisFormat %s
todayMarker off
section Baseline
This PR (5735) - mean (271ms) : 266, 275
. : milestone, 271,
master - mean (265ms) : 261, 269
. : milestone, 265,
section CallTarget+Inlining+NGEN
This PR (5735) - mean (817ms) : 780, 853
. : milestone, 817,
master - mean (809ms) : 778, 840
. : milestone, 809,
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 (5735) (11.941M) : 0, 11940962
master (11.716M) : 0, 11716370
benchmarks/2.9.0 (11.959M) : 0, 11959218
section Automatic
This PR (5735) (8.066M) : 0, 8065628
master (8.019M) : 0, 8019217
benchmarks/2.9.0 (8.424M) : 0, 8423539
section Trace stats
master (8.211M) : 0, 8210949
section Manual
This PR (5735) (10.316M) : 0, 10316355
master (10.165M) : 0, 10165125
section Manual + Automatic
This PR (5735) (7.636M) : 0, 7635944
master (7.491M) : 0, 7491415
section Version Conflict
master (6.704M) : 0, 6704048
gantt
title Throughput Linux arm64 (Total requests)
dateFormat X
axisFormat %s
section Baseline
This PR (5735) (9.413M) : 0, 9413356
master (9.678M) : 0, 9677607
benchmarks/2.9.0 (9.647M) : 0, 9646678
section Automatic
This PR (5735) (6.613M) : 0, 6612899
master (6.494M) : 0, 6493916
section Trace stats
master (6.867M) : 0, 6866744
section Manual
This PR (5735) (8.232M) : 0, 8232003
master (8.353M) : 0, 8353119
section Manual + Automatic
This PR (5735) (5.908M) : 0, 5908051
master (6.149M) : 0, 6148874
section Version Conflict
master (5.635M) : 0, 5635422
gantt
title Throughput Windows x64 (Total requests)
dateFormat X
axisFormat %s
section Baseline
This PR (5735) (10.270M) : 0, 10270004
master (10.277M) : 0, 10276790
benchmarks/2.9.0 (10.154M) : 0, 10153990
section Automatic
This PR (5735) (7.333M) : 0, 7333413
master (7.193M) : 0, 7193100
benchmarks/2.9.0 (7.563M) : 0, 7562893
section Trace stats
master (7.542M) : 0, 7542132
section Manual
This PR (5735) (9.033M) : 0, 9032770
master (9.045M) : 0, 9045425
section Manual + Automatic
This PR (5735) (6.992M) : 0, 6991571
master (6.963M) : 0, 6963205
section Version Conflict
master (6.250M) : 0, 6250263
Benchmarks for #5735 compared to master:
The following thresholds were used for comparing the benchmark speeds:
Allocation changes below 0.5% are ignored.
Summary of changes
Updates condition for considering activity a parent
Reason for change
SimpleActivitiesAndSpansTestis super-flaky on macos, especially since we updated tomacos-12. I'm 99.9% sure it's due to the condition inActivityHandlerCommonhere, and I think the fix is OK for production.Implementation details
Macos in a VM has terrible resolution of the clock. So essentially a child span is getting the same start time as the parent span. When we come to do the re-parenting/conversion to datadog spans, we currently decide that this can't be a child, and so don't add it to the same trace. Changing the condition from
<to<=seems to fix it and I believe it's potentialy a valid fix for "in the wild" behaviour?Test coverage
I ran the macos unit tests repeatedly and didn't see any flake, so I'm pretty confident
Other details
Does make me wonder if we should be doing something more deterministic here, e.g. storing the "original" activity traceId in the
TraceContext, and using that to identify the proper parentage here? It requires increasing the size ofTraceContext, but removes this heuristic in place of something deterministic? It's very possible I'm wrong though and that's not possible, so will defer to @zacharycmontoya and @bouwkast here!This required an additional fix:
So now it should do the job 🤞