dd-trace-dotnet icon indicating copy to clipboard operation
dd-trace-dotnet copied to clipboard

Small build tidy up - improve log file checking

Open andrewlock opened this issue 3 years ago • 2 comments

Summary of changes

  • Automatically run BuildNativeLoader as part of BuildTracerHome
  • Split the checks we do for build logs vs smoke test logs
  • Add log checking for native loader log files
  • Rename incorrect named Nuke targets (e.g. PublishNativeProfiler -> PublishNativeTracer)

Reason for change

Automatically run BuildNativeLoader as part of BuildTracerHome We always need to run this locally for testing, and we always run them together in CI, so simplifies local dev slightly

Split the checks we do for build logs vs smoke test logs The build logs intentionally check some error conditions, so we expect to see some logs and warnings in there. By splitting the checks in two, we can be more conservative with those checks, while for the smoke tests we can fail on errors and warnings, and we can insist that the logs definitely exist.

We still need to exclude some expected errors/warnings:

  • AppSec always complains when loading on alpine
  • Profiler isn't yet supported on Arm64

Add log checking for native loader log files We should be checking these logs, for example they will describe issues calling the native libraries etc

Rename incorrectly named Nuke targets Historically we called the "tracer" the "profiler", but that's more confusing now we have the continuous profiler, so updated those targets

Implementation details

Test coverage

I'm running the full set of smoke tests here to confirm they're not broken.

Other details

GitHub makes a real mess of the diff in the CheckBuildLogs target, it hasn't changed significantly!

andrewlock avatar Aug 12 '22 09:08 andrewlock

Benchmarks Report :snail:

Benchmarks for #3071 compared to master:

  • 3 benchmarks are faster, with geometric mean 1.235
  • All benchmarks have the same allocations

The following thresholds were used for comparing the benchmark speeds:

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

Allocation changes below 0.5% are ignored.

Benchmark details

Benchmarks.Trace.AgentWriterBenchmark - Faster :tada: Same allocations :heavy_check_mark:

Faster :tada: in #3071

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.AgentWriterBenchmark.WriteAndFlushEnrichedTraces‑netcoreapp3.1 1.141 527,143.46 462,040.41

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master WriteAndFlushEnrichedTraces net472 792μs 4.32μs 24.4μs 0.391 0 0 3.18 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 529μs 3.02μs 22.6μs 0 0 0 2.58 KB
#3071 WriteAndFlushEnrichedTraces net472 728μs 194ns 724ns 0.363 0 0 3.18 KB
#3071 WriteAndFlushEnrichedTraces netcoreapp3.1 462μs 172ns 642ns 0 0 0 2.59 KB
Benchmarks.Trace.AppSecBodyBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master AllCycleSimpleBody net472 205ns 0.137ns 0.493ns 0.0676 0 0 425 B
master AllCycleSimpleBody netcoreapp3.1 234ns 0.27ns 1.05ns 0.00594 0 0 424 B
master AllCycleMoreComplexBody net472 182ns 0.151ns 0.566ns 0.0638 0 0 401 B
master AllCycleMoreComplexBody netcoreapp3.1 236ns 0.314ns 1.22ns 0.00542 0 0 400 B
master BodyExtractorSimpleBody net472 259ns 0.152ns 0.549ns 0.0574 0 0 361 B
master BodyExtractorSimpleBody netcoreapp3.1 216ns 0.355ns 1.37ns 0.0038 0 0 272 B
master BodyExtractorMoreComplexBody net472 14.2μs 9.8ns 37.9ns 1.21 0.0215 0 7.62 KB
master BodyExtractorMoreComplexBody netcoreapp3.1 12.5μs 20.2ns 72.8ns 0.0933 0 0 6.75 KB
#3071 AllCycleSimpleBody net472 187ns 0.486ns 1.82ns 0.0675 0 0 425 B
#3071 AllCycleSimpleBody netcoreapp3.1 234ns 0.254ns 0.951ns 0.00579 0 0 424 B
#3071 AllCycleMoreComplexBody net472 183ns 0.2ns 0.773ns 0.0637 0 0 401 B
#3071 AllCycleMoreComplexBody netcoreapp3.1 236ns 0.202ns 0.783ns 0.00549 0 0 400 B
#3071 BodyExtractorSimpleBody net472 265ns 0.427ns 1.66ns 0.0574 0 0 361 B
#3071 BodyExtractorSimpleBody netcoreapp3.1 232ns 0.304ns 1.18ns 0.00363 0 0 272 B
#3071 BodyExtractorMoreComplexBody net472 14.3μs 8.15ns 29.4ns 1.21 0.0214 0 7.62 KB
#3071 BodyExtractorMoreComplexBody netcoreapp3.1 12.2μs 15.9ns 61.4ns 0.0915 0 0 6.75 KB
Benchmarks.Trace.AspNetCoreBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendRequest net472 0.0624ns 0.0151ns 0.0918ns 0 0 0 0 b
master SendRequest netcoreapp3.1 189μs 77.1ns 267ns 0.188 0 0 20.33 KB
#3071 SendRequest net472 0ns 0ns 0ns 0 0 0 0 b
#3071 SendRequest netcoreapp3.1 178μs 157ns 608ns 0.178 0 0 20.33 KB
Benchmarks.Trace.DbCommandBenchmark - Faster :tada: Same allocations :heavy_check_mark:

Faster :tada: in #3071

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.DbCommandBenchmark.ExecuteNonQuery‑netcoreapp3.1 1.471 1,762.88 1,198.07 bimodal

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteNonQuery net472 1.69μs 9.36ns 54.6ns 0.126 0.000827 0 794 B
master ExecuteNonQuery netcoreapp3.1 1.77μs 15.2ns 152ns 0.0112 0 0 824 B
#3071 ExecuteNonQuery net472 1.52μs 0.536ns 2.08ns 0.126 0.000759 0 794 B
#3071 ExecuteNonQuery netcoreapp3.1 1.2μs 0.488ns 1.83ns 0.0109 0 0 824 B
Benchmarks.Trace.ElasticsearchBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master CallElasticsearch net472 2.17μs 0.518ns 1.87ns 0.159 0 0 1 KB
master CallElasticsearch netcoreapp3.1 1.4μs 0.68ns 2.64ns 0.0131 0 0 984 B
master CallElasticsearchAsync net472 2.28μs 4.84ns 18.8ns 0.181 0 0 1.14 KB
master CallElasticsearchAsync netcoreapp3.1 1.43μs 0.529ns 1.98ns 0.015 0 0 1.1 KB
#3071 CallElasticsearch net472 2.16μs 1.21ns 4.68ns 0.159 0 0 1 KB
#3071 CallElasticsearch netcoreapp3.1 1.39μs 0.503ns 1.95ns 0.0131 0 0 984 B
#3071 CallElasticsearchAsync net472 2.28μs 0.403ns 1.51ns 0.18 0 0 1.14 KB
#3071 CallElasticsearchAsync netcoreapp3.1 1.44μs 0.372ns 1.39ns 0.0145 0 0 1.1 KB
Benchmarks.Trace.GraphQLBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteAsync net472 2.48μs 3.1ns 12ns 0.2 0 0 1.26 KB
master ExecuteAsync netcoreapp3.1 1.56μs 1.66ns 6.2ns 0.0163 0 0 1.22 KB
#3071 ExecuteAsync net472 2.48μs 3.72ns 14.4ns 0.199 0 0 1.26 KB
#3071 ExecuteAsync netcoreapp3.1 1.61μs 2.66ns 9.97ns 0.0169 0 0 1.22 KB
Benchmarks.Trace.HttpClientBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendAsync net472 5.06μs 6.98ns 26.1ns 0.392 0 0 2.48 KB
master SendAsync netcoreapp3.1 3.3μs 4.05ns 15.7ns 0.031 0 0 2.36 KB
#3071 SendAsync net472 4.88μs 8.68ns 33.6ns 0.394 0 0 2.48 KB
#3071 SendAsync netcoreapp3.1 3.23μs 3.7ns 14.3ns 0.0322 0 0 2.36 KB
Benchmarks.Trace.ILoggerBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net472 2.83μs 0.751ns 2.81ns 0.263 0 0 1.66 KB
master EnrichedLog netcoreapp3.1 2.29μs 0.476ns 1.72ns 0.0231 0 0 1.73 KB
#3071 EnrichedLog net472 2.73μs 1.2ns 4.63ns 0.264 0 0 1.66 KB
#3071 EnrichedLog netcoreapp3.1 2.36μs 0.746ns 2.79ns 0.0236 0 0 1.73 KB
Benchmarks.Trace.Log4netBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net472 149μs 77.9ns 302ns 0.675 0.225 0 4.5 KB
master EnrichedLog netcoreapp3.1 113μs 107ns 399ns 0.0566 0 0 4.38 KB
#3071 EnrichedLog net472 148μs 227ns 879ns 0.67 0.223 0 4.5 KB
#3071 EnrichedLog netcoreapp3.1 116μs 257ns 995ns 0.0576 0 0 4.38 KB
Benchmarks.Trace.NLogBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net472 5.62μs 8.3ns 32.1ns 0.545 0.00281 0 3.43 KB
master EnrichedLog netcoreapp3.1 4.31μs 5.04ns 19.5ns 0.0514 0 0 3.8 KB
#3071 EnrichedLog net472 5.28μs 12.5ns 48.3ns 0.544 0.00263 0 3.43 KB
#3071 EnrichedLog netcoreapp3.1 4.22μs 5.53ns 21.4ns 0.0507 0 0 3.8 KB
Benchmarks.Trace.RedisBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master SendReceive net472 1.99μs 1.03ns 4ns 0.193 0 0 1.22 KB
master SendReceive netcoreapp3.1 1.73μs 0.707ns 2.65ns 0.0165 0 0 1.21 KB
#3071 SendReceive net472 1.94μs 0.295ns 1.1ns 0.194 0 0 1.22 KB
#3071 SendReceive netcoreapp3.1 1.63μs 0.687ns 2.57ns 0.0163 0 0 1.21 KB
Benchmarks.Trace.SerilogBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net472 4.66μs 1.38ns 5.33ns 0.329 0 0 2.08 KB
master EnrichedLog netcoreapp3.1 4.09μs 2ns 7.73ns 0.0226 0 0 1.69 KB
#3071 EnrichedLog net472 4.64μs 1.17ns 4.23ns 0.329 0 0 2.08 KB
#3071 EnrichedLog netcoreapp3.1 4.02μs 1.79ns 6.93ns 0.022 0 0 1.69 KB
Benchmarks.Trace.SpanBenchmark - Faster :tada: Same allocations :heavy_check_mark:

Faster :tada: in #3071

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.SpanBenchmark.StartFinishScope‑netcoreapp3.1 1.121 929.93 829.67

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartFinishSpan net472 832ns 0.252ns 0.944ns 0.104 0 0 658 B
master StartFinishSpan netcoreapp3.1 776ns 1.78ns 6.88ns 0.00885 0 0 648 B
master StartFinishScope net472 1.01μs 0.27ns 1.05ns 0.117 0 0 738 B
master StartFinishScope netcoreapp3.1 930ns 0.337ns 1.26ns 0.0102 0 0 768 B
#3071 StartFinishSpan net472 876ns 0.632ns 2.45ns 0.105 0 0 658 B
#3071 StartFinishSpan netcoreapp3.1 735ns 0.533ns 1.92ns 0.00877 0 0 648 B
#3071 StartFinishScope net472 1.04μs 0.4ns 1.55ns 0.117 0 0 738 B
#3071 StartFinishScope netcoreapp3.1 830ns 0.228ns 0.822ns 0.0104 0 0 768 B
Benchmarks.Trace.TraceAnnotationsBenchmark - Same speed :heavy_check_mark: Same allocations :heavy_check_mark:

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master RunOnMethodBegin net472 1.22μs 0.858ns 3.32ns 0.117 0 0 738 B
master RunOnMethodBegin netcoreapp3.1 1.01μs 0.329ns 1.19ns 0.0102 0 0 768 B
#3071 RunOnMethodBegin net472 1.29μs 0.938ns 3.63ns 0.117 0 0 738 B
#3071 RunOnMethodBegin netcoreapp3.1 998ns 0.801ns 3.1ns 0.0105 0 0 768 B

andrewlock avatar Aug 12 '22 10:08 andrewlock

Code Coverage Report :bar_chart:

:heavy_check_mark: Merging #3071 into master will not change line coverage :heavy_check_mark: Merging #3071 into master will not change branch coverage :heavy_check_mark: Merging #3071 into master will not change complexity

master #3071 Change
Lines 16774 / 23114 16843 / 23114
Lines % 73% 73% 0% :heavy_check_mark:
Branches 10031 / 14310 10072 / 14310
Branches % 70% 70% 0% :heavy_check_mark:
Complexity 15381 15381 0 :heavy_check_mark:

View the full report for further details:

Datadog.Trace Breakdown :heavy_check_mark:

master #3071 Change
Lines % 73% 73% 0% :heavy_check_mark:
Branches % 70% 70% 0% :heavy_check_mark:
Complexity 15381 15381 0 :heavy_check_mark:

The following classes have significant coverage changes.

File Line coverage change Branch coverage change Complexity change
Datadog.Trace.Ci.CIVisibility 5% :heavy_check_mark: 6% :heavy_check_mark: 0 :heavy_check_mark:

View the full reports for further details:

andrewlock avatar Aug 12 '22 10:08 andrewlock