Skip to content

Conversation

@joeyzhao2018
Copy link
Contributor

@joeyzhao2018 joeyzhao2018 commented Aug 21, 2023

Reason for change

Fixes #3345 to support tracing top-level statements in AWS Lambda runtimes.

Summary of changes

  1. This PR adds auto-instrumentation for top-level statements cases for AWS Lambda
  2. Because the solution is to auto-instrument Amazon.Lambda.RuntimeSupport library (which is included and used by AWS Lambda dotnet runtimes), to avoid duplicated instrumentations, this PR also deprecates the current serverless instrumentation.

Implementation details

  • This PR's main change is located at one file: tracer/src/Datadog.Trace/ClrProfiler/AutoInstrumentation/AWS/Lambda/HandlerWrapperSetHandlerIntegration.cs.
    • This takes the advantage of the Delegate wrapper utils developed by @tonyredondo [PR Support for Delegate instrumentation #4613 ]
    • Amazon.Lambda.RuntimeSupport library has a HandlerWrapper class (link), which wraps the user-provided handler into a LambdaBootstrapHandler delegate (link)
    • This auto-instrumentation is to further wrap that delegate by instrumenting the setter of the Handler property of the HandlerWrapper (therefore the name HandlerWrapperSetHandlerIntegration). Basically, we auto-instrument the setter to tell it to wrap the user's handler by adding some before and after actions around it.
    • The before and after actions are essentially the same as the current serverless instrumentation, that is, communicate with the datadog extension (datadog agent in aws lambdas cases). More details can be found in this doc.
    • (More details on how we found this solution can be found in this doc)

Test coverage

  1. A new sample project "Samples.Amazon.Lambda.RuntimeSupport" was added. However, its integration test is actually following the existing style of IntegrationTests.Serverless. This is hard to run on an M1 machine so I largely relied on the pipelines to indicate it's working. Please comment to suggest any change on this.
  2. Since the old instrumentation is removed, the existing serverless integration tests are essentially using the new auto-instrumentation.
  3. I have been using the new auto-instrumentation for many testing cases. And so far they all have worked. For example:
  • AspnetCoreMinimalApi case
Screenshot 2023-07-24 at 11 21 01 AM
  • directly using top-level statement case (same as the sample app)
Screenshot 2023-07-21 at 10 09 23 PM
  • sns->sqs propagation case
Screenshot 2023-09-25 at 6 30 44 PM
  • Please feel free to comment on other cases you'd like to test

Other details

Topic expert @lucaspimentel
Delegate wrapper expert @tonyredondo
Serverless instrumentation and testing experts @andrewlock @maxday

@andrewlock
Copy link
Member

andrewlock commented Aug 21, 2023

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 (4535) - mean (68ms)  : 67, 69
     .   : milestone, 68,
    master - mean (72ms)  : 59, 84
     .   : milestone, 72,

    section CallTarget+Inlining+NGEN
    This PR (4535) - mean (1,010ms)  : 989, 1030
     .   : milestone, 1010,
    master - mean (1,012ms)  : 983, 1041
     .   : milestone, 1012,

Loading
gantt
    title Execution time (ms) FakeDbCommand (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4535) - mean (106ms)  : 104, 109
     .   : milestone, 106,
    master - mean (106ms)  : 103, 109
     .   : milestone, 106,

    section CallTarget+Inlining+NGEN
    This PR (4535) - mean (713ms)  : 690, 736
     .   : milestone, 713,
    master - mean (713ms)  : 697, 729
     .   : milestone, 713,

Loading
gantt
    title Execution time (ms) FakeDbCommand (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4535) - mean (90ms)  : 87, 92
     .   : milestone, 90,
    master - mean (90ms)  : 83, 97
     .   : milestone, 90,

    section CallTarget+Inlining+NGEN
    This PR (4535) - mean (673ms)  : 647, 698
     .   : milestone, 673,
    master - mean (679ms)  : 653, 705
     .   : milestone, 679,

Loading
gantt
    title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4535) - mean (189ms)  : 186, 191
     .   : milestone, 189,
    master - mean (187ms)  : 185, 189
     .   : milestone, 187,

    section CallTarget+Inlining+NGEN
    This PR (4535) - mean (1,130ms)  : 1105, 1155
     .   : milestone, 1130,
    master - mean (1,125ms)  : 1106, 1144
     .   : milestone, 1125,

Loading
gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4535) - mean (272ms)  : 269, 274
     .   : milestone, 272,
    master - mean (271ms)  : 265, 277
     .   : milestone, 271,

    section CallTarget+Inlining+NGEN
    This PR (4535) - mean (1,090ms)  : 1064, 1117
     .   : milestone, 1090,
    master - mean (1,090ms)  : 1069, 1111
     .   : milestone, 1090,

Loading
gantt
    title Execution time (ms) HttpMessageHandler (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4535) - mean (261ms)  : 257, 264
     .   : milestone, 261,
    master - mean (260ms)  : 256, 264
     .   : milestone, 260,

    section CallTarget+Inlining+NGEN
    This PR (4535) - mean (1,057ms)  : 1033, 1080
     .   : milestone, 1057,
    master - mean (1,049ms)  : 1020, 1078
     .   : milestone, 1049,

Loading

@andrewlock
Copy link
Member

andrewlock commented Aug 21, 2023

Benchmarks Report 🐌

Benchmarks for #4535 compared to master:

  • 1 benchmarks are faster, with geometric mean 1.126
  • 4 benchmarks are slower, with geometric mean 1.136
  • 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.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.14μs 44.4ns 243ns 0.0242 0.0121 0 7.29 KB
master StartStopWithChild netcoreapp3.1 9.86μs 53ns 275ns 0.0234 0.00935 0 7.38 KB
master StartStopWithChild net472 15.6μs 37.9ns 147ns 1.3 0.327 0.114 7.67 KB
#4535 StartStopWithChild net6.0 8.21μs 46.6ns 320ns 0.047 0.0171 0.00428 7.29 KB
#4535 StartStopWithChild netcoreapp3.1 10.2μs 55ns 301ns 0.0247 0.00987 0 7.39 KB
#4535 StartStopWithChild net472 15.7μs 40.9ns 158ns 1.27 0.326 0.101 7.65 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 489ns 1.83μs 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 621μs 257ns 963ns 0 0 0 2.7 KB
master WriteAndFlushEnrichedTraces net472 796μs 233ns 902ns 0.398 0 0 3.3 KB
#4535 WriteAndFlushEnrichedTraces net6.0 483μs 352ns 1.27μs 0 0 0 2.7 KB
#4535 WriteAndFlushEnrichedTraces netcoreapp3.1 636μs 2.24μs 8.68μs 0 0 0 2.7 KB
#4535 WriteAndFlushEnrichedTraces net472 786μs 401ns 1.55μs 0.391 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.7μs 28ns 108ns 0.0215 0 0 2.03 KB
master AllCycleSimpleBody netcoreapp3.1 45.9μs 230ns 1.05μs 0.0224 0 0 2.01 KB
master AllCycleSimpleBody net472 47.1μs 30.8ns 115ns 0.329 0 0 2.08 KB
master AllCycleMoreComplexBody net6.0 230μs 174ns 673ns 0.115 0 0 8.63 KB
master AllCycleMoreComplexBody netcoreapp3.1 235μs 143ns 554ns 0.117 0 0 8.52 KB
master AllCycleMoreComplexBody net472 267μs 1.37μs 6.44μs 1.37 0 0 8.7 KB
master ObjectExtractorSimpleBody net6.0 121ns 0.0767ns 0.287ns 0.00392 0 0 280 B
master ObjectExtractorSimpleBody netcoreapp3.1 171ns 0.108ns 0.418ns 0.00363 0 0 272 B
master ObjectExtractorSimpleBody net472 145ns 0.0904ns 0.35ns 0.0446 0 0 281 B
master ObjectExtractorMoreComplexBody net6.0 3.06μs 2.02ns 7.3ns 0.0535 0 0 3.88 KB
master ObjectExtractorMoreComplexBody netcoreapp3.1 4.12μs 2.02ns 7.55ns 0.0515 0 0 3.78 KB
master ObjectExtractorMoreComplexBody net472 4.15μs 2.83ns 11ns 0.617 0.00619 0 3.89 KB
#4535 AllCycleSimpleBody net6.0 45μs 77.7ns 301ns 0.0231 0 0 2.03 KB
#4535 AllCycleSimpleBody netcoreapp3.1 45.4μs 115ns 447ns 0.0227 0 0 2.01 KB
#4535 AllCycleSimpleBody net472 46.9μs 18.7ns 72.3ns 0.327 0 0 2.08 KB
#4535 AllCycleMoreComplexBody net6.0 238μs 177ns 684ns 0.115 0 0 8.63 KB
#4535 AllCycleMoreComplexBody netcoreapp3.1 236μs 92.2ns 357ns 0.117 0 0 8.52 KB
#4535 AllCycleMoreComplexBody net472 240μs 139ns 537ns 1.31 0 0 8.7 KB
#4535 ObjectExtractorSimpleBody net6.0 127ns 0.0483ns 0.181ns 0.00396 0 0 280 B
#4535 ObjectExtractorSimpleBody netcoreapp3.1 179ns 0.197ns 0.763ns 0.0037 0 0 272 B
#4535 ObjectExtractorSimpleBody net472 145ns 0.106ns 0.412ns 0.0446 0 0 281 B
#4535 ObjectExtractorMoreComplexBody net6.0 3.09μs 1.33ns 5.13ns 0.0543 0 0 3.88 KB
#4535 ObjectExtractorMoreComplexBody netcoreapp3.1 4.17μs 2.04ns 7.89ns 0.0521 0 0 3.78 KB
#4535 ObjectExtractorMoreComplexBody net472 4.15μs 3.96ns 14.3ns 0.617 0.00625 0 3.89 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 12.8μs 4.52ns 16.9ns 0.128 0 0 9.42 KB
master RunWaf(args=NestedMap (10)) netcoreapp3.1 19.9μs 3.34ns 12.5ns 0.128 0 0 9.42 KB
master RunWaf(args=NestedMap (10)) net472 28μs 8.1ns 31.4ns 1.5 0 0 9.48 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) net6.0 78.4μs 21.4ns 82.9ns 0.192 0 0 15.77 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) netcoreapp3.1 86.3μs 110ns 427ns 0.174 0 0 15.72 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) net472 97.5μs 46.1ns 173ns 2.53 0 0 16.04 KB
master RunWaf(args=NestedMap (100)) net6.0 23.9μs 6.96ns 27ns 0.276 0 0 19.66 KB
master RunWaf(args=NestedMap (100)) netcoreapp3.1 37.9μs 14ns 54.4ns 0.265 0 0 20.42 KB
master RunWaf(args=NestedMap (100)) net472 54.2μs 16.6ns 64.4ns 3.25 0.0271 0 20.63 KB
master RunWafWithAttack(args=Neste(...)tack) [23]) net6.0 92.8μs 54.4ns 204ns 0.368 0 0 26.01 KB
master RunWafWithAttack(args=Neste(...)tack) [23]) netcoreapp3.1 110μs 146ns 567ns 0.33 0 0 26.72 KB
master RunWafWithAttack(args=Neste(...)tack) [23]) net472 132μs 52.2ns 202ns 4.26 0.0665 0 27.19 KB
master RunWaf(args=NestedMap (20)) net6.0 24μs 4.59ns 16.6ns 0.266 0 0 19.4 KB
master RunWaf(args=NestedMap (20)) netcoreapp3.1 38μs 8.54ns 30.8ns 0.265 0 0 19.84 KB
master RunWaf(args=NestedMap (20)) net472 55μs 17.2ns 64.5ns 3.16 0.0549 0 20.04 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) net6.0 92.8μs 53.3ns 206ns 0.324 0 0 25.74 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) netcoreapp3.1 109μs 80.9ns 303ns 0.327 0 0 26.14 KB
master RunWafWithAttack(args=Neste(...)tack) [22]) net472 131μs 149ns 536ns 4.18 0.0654 0 26.6 KB
#4535 RunWaf(args=NestedMap (10)) net6.0 12.7μs 3.23ns 12.1ns 0.133 0 0 9.42 KB
#4535 RunWaf(args=NestedMap (10)) netcoreapp3.1 19.4μs 4.59ns 17.2ns 0.126 0 0 9.42 KB
#4535 RunWaf(args=NestedMap (10)) net472 28.2μs 11.5ns 44.7ns 1.49 0 0 9.48 KB
#4535 RunWafWithAttack(args=Neste(...)tack) [22]) net6.0 76.5μs 105ns 405ns 0.191 0 0 15.77 KB
#4535 RunWafWithAttack(args=Neste(...)tack) [22]) netcoreapp3.1 87.3μs 189ns 681ns 0.173 0 0 15.72 KB
#4535 RunWafWithAttack(args=Neste(...)tack) [22]) net472 98.1μs 151ns 584ns 2.53 0 0 16.04 KB
#4535 RunWaf(args=NestedMap (100)) net6.0 24.3μs 6.8ns 25.4ns 0.268 0 0 19.66 KB
#4535 RunWaf(args=NestedMap (100)) netcoreapp3.1 38μs 10.5ns 39.1ns 0.266 0 0 20.42 KB
#4535 RunWaf(args=NestedMap (100)) net472 54.8μs 26.5ns 99.1ns 3.25 0.0293 0 20.63 KB
#4535 RunWafWithAttack(args=Neste(...)tack) [23]) net6.0 92.8μs 52.3ns 203ns 0.371 0 0 26.01 KB
#4535 RunWafWithAttack(args=Neste(...)tack) [23]) netcoreapp3.1 110μs 150ns 582ns 0.329 0 0 26.72 KB
#4535 RunWafWithAttack(args=Neste(...)tack) [23]) net472 132μs 64.3ns 249ns 4.31 0.0644 0 27.19 KB
#4535 RunWaf(args=NestedMap (20)) net6.0 24.1μs 8.23ns 31.9ns 0.265 0 0 19.4 KB
#4535 RunWaf(args=NestedMap (20)) netcoreapp3.1 37.6μs 11.3ns 42.2ns 0.263 0 0 19.84 KB
#4535 RunWaf(args=NestedMap (20)) net472 54.4μs 20.3ns 78.5ns 3.17 0.0542 0 20.04 KB
#4535 RunWafWithAttack(args=Neste(...)tack) [22]) net6.0 92μs 48.3ns 187ns 0.364 0 0 25.74 KB
#4535 RunWafWithAttack(args=Neste(...)tack) [22]) netcoreapp3.1 110μs 129ns 465ns 0.325 0 0 26.14 KB
#4535 RunWafWithAttack(args=Neste(...)tack) [22]) net472 132μs 83.7ns 324ns 4.22 0.0659 0 26.6 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 134ns 518ns 0.172 0 0 18.04 KB
master SendRequest netcoreapp3.1 190μs 422ns 1.64μs 0.192 0 0 20.2 KB
master SendRequest net472 0.00177ns 0.000227ns 0.000848ns 0 0 0 0 b
#4535 SendRequest net6.0 169μs 111ns 431ns 0.169 0 0 18.04 KB
#4535 SendRequest netcoreapp3.1 188μs 251ns 970ns 0.186 0 0 20.2 KB
#4535 SendRequest net472 0.0009ns 0.000465ns 0.00174ns 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 538μs 300ns 1.12μs 0.543 0 0 41.72 KB
master WriteAndFlushEnrichedTraces netcoreapp3.1 662μs 979ns 3.79μs 0.332 0 0 41.79 KB
master WriteAndFlushEnrichedTraces net472 829μs 4.03μs 17.6μs 8.17 2.45 0.408 53.28 KB
#4535 WriteAndFlushEnrichedTraces net6.0 559μs 466ns 1.8μs 0.558 0 0 41.89 KB
#4535 WriteAndFlushEnrichedTraces netcoreapp3.1 664μs 626ns 2.34μs 0.331 0 0 41.92 KB
#4535 WriteAndFlushEnrichedTraces net472 870μs 3.66μs 14.2μs 8.19 2.59 0.431 53.26 KB
Benchmarks.Trace.DbCommandBenchmark - Slower ⚠️ Same allocations ✔️

Slower ⚠️ in #4535

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.DbCommandBenchmark.ExecuteNonQuery‑net6.0 1.129 1,019.78 1,151.53

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteNonQuery net6.0 1.02μs 0.286ns 1.11ns 0.0108 0 0 768 B
master ExecuteNonQuery netcoreapp3.1 1.32μs 0.835ns 3.24ns 0.00993 0 0 768 B
master ExecuteNonQuery net472 1.6μs 0.277ns 0.961ns 0.116 0 0 730 B
#4535 ExecuteNonQuery net6.0 1.15μs 0.656ns 2.54ns 0.0109 0 0 768 B
#4535 ExecuteNonQuery netcoreapp3.1 1.35μs 0.606ns 2.35ns 0.0101 0 0 768 B
#4535 ExecuteNonQuery net472 1.67μs 0.549ns 2.05ns 0.116 0 0 730 B
Benchmarks.Trace.ElasticsearchBenchmark - Slower ⚠️ Same allocations ✔️

Slower ⚠️ in #4535

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.ElasticsearchBenchmark.CallElasticsearch‑netcoreapp3.1 1.114 1,380.56 1,538.52

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master CallElasticsearch net6.0 1.15μs 0.441ns 1.71ns 0.0134 0 0 936 B
master CallElasticsearch netcoreapp3.1 1.38μs 0.562ns 2.18ns 0.0124 0 0 936 B
master CallElasticsearch net472 2.45μs 0.987ns 3.82ns 0.152 0 0 955 B
master CallElasticsearchAsync net6.0 1.24μs 0.768ns 2.88ns 0.0124 0 0 912 B
master CallElasticsearchAsync netcoreapp3.1 1.54μs 0.664ns 2.39ns 0.0131 0 0 984 B
master CallElasticsearchAsync net472 2.51μs 0.432ns 1.56ns 0.16 0 0 1.01 KB
#4535 CallElasticsearch net6.0 1.18μs 0.59ns 2.28ns 0.013 0 0 936 B
#4535 CallElasticsearch netcoreapp3.1 1.54μs 0.871ns 3.37ns 0.0123 0 0 936 B
#4535 CallElasticsearch net472 2.34μs 1.35ns 5.21ns 0.151 0 0 955 B
#4535 CallElasticsearchAsync net6.0 1.22μs 1.24ns 4.63ns 0.0128 0 0 912 B
#4535 CallElasticsearchAsync netcoreapp3.1 1.6μs 0.872ns 3.26ns 0.0127 0 0 984 B
#4535 CallElasticsearchAsync net472 2.5μs 1.38ns 5.34ns 0.16 0 0 1.01 KB
Benchmarks.Trace.GraphQLBenchmark - Slower ⚠️ Same allocations ✔️

Slower ⚠️ in #4535

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.GraphQLBenchmark.ExecuteAsync‑net6.0 1.133 1,117.15 1,265.50

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master ExecuteAsync net6.0 1.12μs 0.864ns 3.23ns 0.0124 0 0 912 B
master ExecuteAsync netcoreapp3.1 1.46μs 0.797ns 3.09ns 0.0125 0 0 912 B
master ExecuteAsync net472 1.73μs 0.721ns 2.7ns 0.139 0 0 875 B
#4535 ExecuteAsync net6.0 1.27μs 1.11ns 4.31ns 0.0125 0 0 912 B
#4535 ExecuteAsync netcoreapp3.1 1.53μs 0.902ns 3.49ns 0.0123 0 0 912 B
#4535 ExecuteAsync net472 1.76μs 0.434ns 1.68ns 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 3.78μs 1.92ns 7.44ns 0.0265 0 0 1.9 KB
master SendAsync netcoreapp3.1 4.5μs 2.05ns 7.94ns 0.0336 0 0 2.43 KB
master SendAsync net472 7.03μs 2.54ns 9.85ns 0.472 0 0 2.99 KB
#4535 SendAsync net6.0 3.93μs 2.32ns 8.69ns 0.0256 0 0 1.9 KB
#4535 SendAsync netcoreapp3.1 4.45μs 1.74ns 6.52ns 0.0336 0 0 2.43 KB
#4535 SendAsync net472 7.12μs 1.79ns 6.71ns 0.474 0 0 2.99 KB
Benchmarks.Trace.ILoggerBenchmark - Faster 🎉 Same allocations ✔️

Faster 🎉 in #4535

Benchmark base/diff Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.ILoggerBenchmark.EnrichedLog‑netcoreapp3.1 1.126 2,087.09 1,854.32

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master EnrichedLog net6.0 1.39μs 0.805ns 2.79ns 0.0221 0 0 1.57 KB
master EnrichedLog netcoreapp3.1 2.09μs 0.993ns 3.71ns 0.021 0 0 1.57 KB
master EnrichedLog net472 2.37μs 2.1ns 8.15ns 0.237 0 0 1.49 KB
#4535 EnrichedLog net6.0 1.41μs 0.515ns 1.93ns 0.0219 0 0 1.57 KB
#4535 EnrichedLog netcoreapp3.1 1.85μs 1.54ns 5.75ns 0.0215 0 0 1.57 KB
#4535 EnrichedLog net472 2.28μs 1.83ns 7.07ns 0.237 0 0 1.49 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 112μs 84.7ns 317ns 0.0558 0 0 4.21 KB
master EnrichedLog netcoreapp3.1 118μs 205ns 793ns 0 0 0 4.21 KB
master EnrichedLog net472 150μs 59.2ns 221ns 0.675 0.225 0 4.38 KB
#4535 EnrichedLog net6.0 112μs 68.6ns 257ns 0.0562 0 0 4.21 KB
#4535 EnrichedLog netcoreapp3.1 117μs 127ns 493ns 0.0585 0 0 4.21 KB
#4535 EnrichedLog net472 147μs 91.7ns 343ns 0.658 0.219 0 4.38 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.91μs 1.16ns 4.35ns 0.029 0 0 2.13 KB
master EnrichedLog netcoreapp3.1 4.02μs 1.42ns 5.52ns 0.0281 0 0 2.13 KB
master EnrichedLog net472 4.54μs 1.87ns 7.24ns 0.307 0 0 1.93 KB
#4535 EnrichedLog net6.0 2.81μs 1.21ns 4.51ns 0.0295 0 0 2.13 KB
#4535 EnrichedLog netcoreapp3.1 3.95μs 1.4ns 5.44ns 0.0296 0 0 2.13 KB
#4535 EnrichedLog net472 4.65μs 1.42ns 5.5ns 0.307 0 0 1.93 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.34μs 1.42ns 5.51ns 0.0153 0 0 1.1 KB
master SendReceive netcoreapp3.1 1.58μs 4.65ns 18ns 0.0147 0 0 1.1 KB
master SendReceive net472 2.02μs 2.65ns 10.3ns 0.176 0 0 1.12 KB
#4535 SendReceive net6.0 1.28μs 1.21ns 4.7ns 0.0154 0 0 1.1 KB
#4535 SendReceive netcoreapp3.1 1.62μs 0.68ns 2.63ns 0.0147 0 0 1.1 KB
#4535 SendReceive net472 2.01μs 1.73ns 6.46ns 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.59μs 0.596ns 2.31ns 0.0208 0 0 1.53 KB
master EnrichedLog netcoreapp3.1 3.59μs 1.78ns 6.68ns 0.0215 0 0 1.58 KB
master EnrichedLog net472 4.14μs 3.17ns 11.9ns 0.309 0 0 1.96 KB
#4535 EnrichedLog net6.0 2.51μs 0.636ns 2.29ns 0.0214 0 0 1.53 KB
#4535 EnrichedLog netcoreapp3.1 3.47μs 1.59ns 5.97ns 0.0208 0 0 1.58 KB
#4535 EnrichedLog net472 3.97μs 1.63ns 6.3ns 0.311 0 0 1.96 KB
Benchmarks.Trace.SpanBenchmark - Same speed ✔️ Same allocations ✔️

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master StartFinishSpan net6.0 385ns 0.0656ns 0.237ns 0.00746 0 0 536 B
master StartFinishSpan netcoreapp3.1 561ns 3.1ns 19.4ns 0.00722 0 0 536 B
master StartFinishSpan net472 687ns 0.368ns 1.43ns 0.0852 0 0 538 B
master StartFinishScope net6.0 522ns 0.171ns 0.661ns 0.00909 0 0 656 B
master StartFinishScope netcoreapp3.1 731ns 0.3ns 1.12ns 0.00875 0 0 656 B
master StartFinishScope net472 816ns 0.277ns 1.07ns 0.0978 0 0 618 B
#4535 StartFinishSpan net6.0 389ns 0.127ns 0.476ns 0.00758 0 0 536 B
#4535 StartFinishSpan netcoreapp3.1 577ns 0.316ns 1.18ns 0.00727 0 0 536 B
#4535 StartFinishSpan net472 645ns 0.421ns 1.63ns 0.0853 0 0 538 B
#4535 StartFinishScope net6.0 530ns 0.111ns 0.429ns 0.00924 0 0 656 B
#4535 StartFinishScope netcoreapp3.1 765ns 0.36ns 1.35ns 0.00891 0 0 656 B
#4535 StartFinishScope net472 858ns 0.427ns 1.65ns 0.0978 0 0 618 B
Benchmarks.Trace.TraceAnnotationsBenchmark - Slower ⚠️ Same allocations ✔️

Slower ⚠️ in #4535

Benchmark diff/base Base Median (ns) Diff Median (ns) Modality
Benchmarks.Trace.TraceAnnotationsBenchmark.RunOnMethodBegin‑net6.0 1.167 558.82 652.32

Raw results

Branch Method Toolchain Mean StdError StdDev Gen 0 Gen 1 Gen 2 Allocated
master RunOnMethodBegin net6.0 559ns 0.134ns 0.517ns 0.00933 0 0 656 B
master RunOnMethodBegin netcoreapp3.1 790ns 1.45ns 5.62ns 0.00878 0 0 656 B
master RunOnMethodBegin net472 1.03μs 0.19ns 0.735ns 0.0979 0 0 618 B
#4535 RunOnMethodBegin net6.0 652ns 0.153ns 0.593ns 0.00908 0 0 656 B
#4535 RunOnMethodBegin netcoreapp3.1 782ns 0.461ns 1.72ns 0.00911 0 0 656 B
#4535 RunOnMethodBegin net472 953ns 0.475ns 1.84ns 0.098 0 0 618 B

@duncanista duncanista added the area:automatic-instrumentation Automatic instrumentation managed C# code (Datadog.Trace.ClrProfiler.Managed) label Aug 21, 2023
@datadog-ddstaging
Copy link

datadog-ddstaging bot commented Aug 21, 2023

Datadog Report

Branch report: joey/toplevel-statements
Commit report: dbf91a2

dd-trace-dotnet: 25 Failed (0 Known Flaky), 0 New Flaky, 179344 Passed, 995 Skipped, 21m 26.46s Wall Time

❌ Failed Tests (25)

This report shows up to 5 failed tests.

  • PublicApiHasNotChanged - Datadog.Trace.Tests.PublicApiTests.DatadogTraceTests - Details

    Expand for error
     String has differences from expected value because Public API should match the verified API. Update verified snapshot when the public API changes as appropriate. Diff:
     +173:namespace Datadog.Trace.ClrProfiler.AutoInstrumentation.AWS.Lambda
     +174:{
     +175:    public class HandlerWrapperSetHandlerIntegration
     +176:    {
     +177:        public HandlerWrapperSetHandlerIntegration() { }
     +178:    }
     +179:}
    
  • PublicApiHasNotChanged - Datadog.Trace.Tests.PublicApiTests.DatadogTraceTests - Details

    Expand for error
     String has differences from expected value because Public API should match the verified API. Update verified snapshot when the public API changes as appropriate. Diff:
     +173:namespace Datadog.Trace.ClrProfiler.AutoInstrumentation.AWS.Lambda
     +174:{
     +175:    public class HandlerWrapperSetHandlerIntegration
     +176:    {
     +177:        public HandlerWrapperSetHandlerIntegration() { }
     +178:    }
     +179:}
    
  • PublicApiHasNotChanged - Datadog.Trace.Tests.PublicApiTests.DatadogTraceTests - Details

    Expand for error
     String has differences from expected value because Public API should match the verified API. Update verified snapshot when the public API changes as appropriate. Diff:
     +173:namespace Datadog.Trace.ClrProfiler.AutoInstrumentation.AWS.Lambda
     +174:{
     +175:    public class HandlerWrapperSetHandlerIntegration
     +176:    {
     +177:        public HandlerWrapperSetHandlerIntegration() { }
     +178:    }
     +179:}
    
  • PublicApiHasNotChanged - Datadog.Trace.Tests.PublicApiTests.DatadogTraceTests - Details

    Expand for error
     String has differences from expected value because Public API should match the verified API. Update verified snapshot when the public API changes as appropriate. Diff:
     +173:namespace Datadog.Trace.ClrProfiler.AutoInstrumentation.AWS.Lambda
     +174:{
     +175:    public class HandlerWrapperSetHandlerIntegration
     +176:    {
     +177:        public HandlerWrapperSetHandlerIntegration() { }
     +178:    }
     +179:}
    
  • PublicApiHasNotChanged - Datadog.Trace.Tests.PublicApiTests.DatadogTraceTests - Details

    Expand for error
     String has differences from expected value because Public API should match the verified API. Update verified snapshot when the public API changes as appropriate. Diff:
     +173:namespace Datadog.Trace.ClrProfiler.AutoInstrumentation.AWS.Lambda
     +174:{
     +175:    public class HandlerWrapperSetHandlerIntegration
     +176:    {
     +177:        public HandlerWrapperSetHandlerIntegration() { }
     +178:    }
     +179:}
    

@andrewlock
Copy link
Member

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 (4535) (11.269M)   : 0, 11268749
    master (11.599M)   : 0, 11599108
    benchmarks/2.35.0 (11.286M)   : 0, 11286124
    benchmarks/2.9.0 (11.340M)   : 0, 11340003

    section Automatic
    This PR (4535) (7.899M)   : 0, 7898997
    master (8.210M)   : 0, 8209835
    benchmarks/2.35.0 (7.896M)   : 0, 7895806
    benchmarks/2.9.0 (8.046M)   : 0, 8045589

    section Trace stats
    master (8.324M)   : 0, 8324285
    benchmarks/2.35.0 (8.094M)   : 0, 8094160

    section Manual
    This PR (4535) (9.977M)   : 0, 9976724
    master (10.433M)   : 0, 10432715
    benchmarks/2.35.0 (10.040M)   : 0, 10039503

    section Manual + Automatic
    This PR (4535) (7.500M)   : crit ,0, 7500454
    master (7.900M)   : 0, 7899883
    benchmarks/2.35.0 (7.802M)   : 0, 7801816

    section Version Conflict
    master (7.221M)   : 0, 7220750
    benchmarks/2.35.0 (7.049M)   : 0, 7048949

Loading
gantt
    title Throughput Linux arm64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (4535) (9.605M)   : 0, 9605008
    master (9.585M)   : 0, 9585099
    benchmarks/2.35.0 (9.501M)   : 0, 9501288
    benchmarks/2.9.0 (9.551M)   : 0, 9551441

    section Automatic
    This PR (4535) (6.855M)   : 0, 6855223
    master (6.673M)   : 0, 6673018
    benchmarks/2.35.0 (6.767M)   : 0, 6766575

    section Trace stats
    master (6.748M)   : 0, 6748068
    benchmarks/2.35.0 (6.661M)   : 0, 6660561

    section Manual
    This PR (4535) (8.398M)   : 0, 8397643
    master (8.436M)   : 0, 8436132
    benchmarks/2.35.0 (8.558M)   : 0, 8558254

    section Manual + Automatic
    This PR (4535) (6.426M)   : 0, 6426303
    master (6.576M)   : 0, 6575639
    benchmarks/2.35.0 (6.400M)   : 0, 6399958

    section Version Conflict
    master (5.939M)   : 0, 5938843
    benchmarks/2.35.0 (5.919M)   : 0, 5918638

Loading
gantt
    title Throughput Windows x64 (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (4535) (10.468M)   : 0, 10468100
    master (10.142M)   : 0, 10142184
    benchmarks/2.35.0 (10.347M)   : 0, 10346803
    benchmarks/2.9.0 (10.227M)   : 0, 10227003

    section Automatic
    This PR (4535) (7.527M)   : 0, 7526699
    master (7.491M)   : 0, 7490757
    benchmarks/2.35.0 (7.511M)   : 0, 7510624
    benchmarks/2.9.0 (7.513M)   : 0, 7512506

    section Trace stats
    master (7.401M)   : 0, 7401348
    benchmarks/2.35.0 (7.458M)   : 0, 7458340

    section Manual
    This PR (4535) (9.379M)   : 0, 9379033
    master (9.421M)   : 0, 9420636
    benchmarks/2.35.0 (9.236M)   : 0, 9235560

    section Manual + Automatic
    This PR (4535) (7.356M)   : 0, 7355822
    master (7.238M)   : 0, 7237643
    benchmarks/2.35.0 (7.270M)   : 0, 7270256

    section Version Conflict
    master (6.698M)   : 0, 6697964
    benchmarks/2.35.0 (6.716M)   : 0, 6715616

Loading
gantt
    title Throughput Linux x64 (ASM) (Total requests) 
    dateFormat  X
    axisFormat %s
    section Baseline
    This PR (4535) (7.456M)   : 0, 7456083
    master (7.371M)   : 0, 7370702
    benchmarks/2.35.0 (7.577M)   : 0, 7576613
    benchmarks/2.9.0 (7.821M)   : 0, 7821144

    section No attack
    This PR (4535) (2.165M)   : 0, 2164901
    master (2.114M)   : 0, 2114280
    benchmarks/2.35.0 (2.140M)   : 0, 2140072
    benchmarks/2.9.0 (3.238M)   : 0, 3238074

    section Attack
    This PR (4535) (1.680M)   : 0, 1679697
    master (1.675M)   : 0, 1674856
    benchmarks/2.35.0 (1.831M)   : 0, 1830708
    benchmarks/2.9.0 (2.533M)   : 0, 2532806

    section Blocking
    This PR (4535) (3.223M)   : 0, 3223332
    master (3.104M)   : 0, 3104161
    benchmarks/2.35.0 (3.696M)   : 0, 3696195

Loading

@joeyzhao2018 joeyzhao2018 force-pushed the joey/toplevel-statements branch from dbf91a2 to e3f8d45 Compare August 25, 2023 18:13
@joeyzhao2018 joeyzhao2018 force-pushed the joey/toplevel-statements branch 2 times, most recently from b478ec9 to 3d5776c Compare October 1, 2023 18:34
@datadog-ddstaging
Copy link

datadog-ddstaging bot commented Oct 1, 2023

Datadog Report

Branch report: joey/toplevel-statements
Commit report: fc7835f

dd-trace-dotnet: 100 Failed (0 Known Flaky), 0 New Flaky, 186712 Passed, 1088 Skipped, 22m 41.69s Wall Time

❌ Failed Tests (100)

This report shows up to 5 failed tests.

  • PublicApiHasNotChanged - Datadog.Trace.Tests.PublicApiTests.DatadogTraceTests - Details

    Expand for error
     PublicApi has differences from expected value because Public API should match the verified API. Update verified snapshot when the public API changes as appropriate. Diff:
     +173:namespace Datadog.Trace.ClrProfiler.AutoInstrumentation.AWS.Lambda
     +174:{
     +175:    public class HandlerWrapperSetHandlerIntegration
     +176:    {
     +177:        public HandlerWrapperSetHandlerIntegration() { }
     +178:    }
     +179:}
     +180:namespace Datadog.Trace.ClrProfiler.AutoInstrumentation.AWS.SDK
     +181:{
     ...
    
  • PublicApiHasNotChanged - Datadog.Trace.Tests.PublicApiTests.DatadogTraceTests - Details

    Expand for error
     String has differences from expected value because Public API should match the verified API. Update verified snapshot when the public API changes as appropriate. Diff:
     +173:namespace Datadog.Trace.ClrProfiler.AutoInstrumentation.AWS.SDK
     +174:{
     +175:    public interface IClientContext
     +176:    {
     +177:        System.Collections.Generic.IDictionary<string, string> Custom { get; }
     +178:    }
     +179:    public interface IInvocationRequest : System.IDisposable
     +180:    {
     +181:        System.IO.Stream InputStream { get; }
     ...
    
  • PublicApiHasNotChanged - Datadog.Trace.Tests.PublicApiTests.DatadogTraceTests - Details

    Expand for error
     String has differences from expected value because Public API should match the verified API. Update verified snapshot when the public API changes as appropriate. Diff:
     +173:namespace Datadog.Trace.ClrProfiler.AutoInstrumentation.AWS.SDK
     +174:{
     +175:    public interface IClientContext
     +176:    {
     +177:        System.Collections.Generic.IDictionary<string, string> Custom { get; }
     +178:    }
     +179:    public interface IInvocationRequest : System.IDisposable
     +180:    {
     +181:        System.IO.Stream InputStream { get; }
     ...
    
  • PublicApiHasNotChanged - Datadog.Trace.Tests.PublicApiTests.DatadogTraceTests - Details

    Expand for error
     String has differences from expected value because Public API should match the verified API. Update verified snapshot when the public API changes as appropriate. Diff:
     +173:namespace Datadog.Trace.ClrProfiler.AutoInstrumentation.AWS.Lambda
     +174:{
     +175:    public class HandlerWrapperSetHandlerIntegration
     +176:    {
     +177:        public HandlerWrapperSetHandlerIntegration() { }
     +178:    }
     +179:}
     +180:namespace Datadog.Trace.ClrProfiler.AutoInstrumentation.AWS.SDK
     +181:{
     ...
    
  • PublicApiHasNotChanged - Datadog.Trace.Tests.PublicApiTests.DatadogTraceTests - Details

    Expand for error
     String has differences from expected value because Public API should match the verified API. Update verified snapshot when the public API changes as appropriate. Diff:
     +173:namespace Datadog.Trace.ClrProfiler.AutoInstrumentation.AWS.SDK
     +174:{
     +175:    public interface IClientContext
     +176:    {
     +177:        System.Collections.Generic.IDictionary<string, string> Custom { get; }
     +178:    }
     +179:    public interface IInvocationRequest : System.IDisposable
     +180:    {
     +181:        System.IO.Stream InputStream { get; }
     ...
    

@joeyzhao2018 joeyzhao2018 force-pushed the joey/toplevel-statements branch from 32319a1 to 7577668 Compare October 2, 2023 11:04
@joeyzhao2018 joeyzhao2018 force-pushed the joey/toplevel-statements branch from fc7835f to 68c96f7 Compare October 11, 2023 19:35
@datadog-ddstaging
Copy link

datadog-ddstaging bot commented Oct 11, 2023

Datadog Report

Branch report: joey/toplevel-statements
Commit report: ab01e0f

dd-trace-dotnet: 0 Failed, 0 New Flaky, 307530 Passed, 1156 Skipped, 30m 51.66s Wall Time

@joeyzhao2018 joeyzhao2018 force-pushed the joey/toplevel-statements branch 3 times, most recently from 29863ab to ac08fa6 Compare October 13, 2023 16:25
@joeyzhao2018 joeyzhao2018 changed the title support toplevel statements in aws lambda initial commit support tracing toplevel statements in aws lambda Oct 17, 2023
@joeyzhao2018 joeyzhao2018 changed the title support tracing toplevel statements in aws lambda [Serverless] Support tracing top-level statements for AWS Lambda Oct 17, 2023
@joeyzhao2018 joeyzhao2018 marked this pull request as ready for review October 17, 2023 02:57
@joeyzhao2018 joeyzhao2018 requested review from a team as code owners October 17, 2023 02:57
@joeyzhao2018 joeyzhao2018 requested review from a team and tonyredondo October 17, 2023 02:57
@joeyzhao2018 joeyzhao2018 force-pushed the joey/toplevel-statements branch from 419f505 to 4915222 Compare October 20, 2023 17:45
@joeyzhao2018 joeyzhao2018 merged commit 61abf67 into master Oct 21, 2023
@joeyzhao2018 joeyzhao2018 deleted the joey/toplevel-statements branch October 21, 2023 01:00
@github-actions github-actions bot added this to the vNext milestone Oct 21, 2023
Comment on lines +111 to +116
LambdaCommon.EndInvocationAsync(string.Empty, exception, ((CallTargetState)state!).Scope, RequestBuilder).ConfigureAwait(false);
}
else
{
var jsonString = ConvertPayloadStream(proxyInstance.OutputStream);
LambdaCommon.EndInvocationAsync(jsonString, exception, ((CallTargetState)state!).Scope, RequestBuilder).ConfigureAwait(false);
Copy link
Member

Choose a reason for hiding this comment

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

Why the calls to EndInvocationAsync are not awaited?

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Good catch! I totally missed it. I was previously using a sync version of this method. Also made a newbie mistake ... I didn't realize that I could just mark the method async. 🤦
#4752
☝️ trying to fix it here.

}

LambdaCommon.Log("DelegateWrapper FINISHED Running OnDelegateEndAsync");
return Task.FromResult(returnValue);
Copy link
Member

Choose a reason for hiding this comment

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

If the calls to EndInvocationAsync are awaited then you don't need Task.FromResult

Copy link
Contributor Author

Choose a reason for hiding this comment

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

area:automatic-instrumentation Automatic instrumentation managed C# code (Datadog.Trace.ClrProfiler.Managed) area:serverless

Projects

None yet

Development

Successfully merging this pull request may close these issues.

AWS Lambda Top Level Statement Support

5 participants