Support for Delegate instrumentation #4613

tonyredondo · 2023-09-11T15:44:19Z

Summary of changes

This PR adds support for instrumenting delegates.

Currently supports:

Delegates with signatures similar to Action, Action<T>, Action<T, T2>, Action<T, T2, T3>, Action<T, T2, T3, T4> and Action<T, T2, T3, T4, T5>. Please note that it doesn't require to be exactly these delegates, but the signature needs to be compatible with those.
Delegates with signatures similar to Func<TReturn>, Func<T, TReturn>, Func<T, T2, TReturn>, Func<T, T2, T3, TReturn>, Func<T, T2, T3, T4, TReturn> and Func<T, T2, T3, T4, T5, TReturn>. Please note that it doesn't require to be exactly these delegates, but the signature needs to be compatible with those.
Similar to CallTarget, it supports: OnDelegateBegin, OnDelegateEnd, OnDelegateAsyncEnd and OnException callbacks.
All calltargets must be defined in a readonly struct instance to enable support for zero allocation operations (removing boxing).
There's an easier implementation based on delegates that allocates.

Not supported:

Delegates with more than 5 arguments.
Delegates with ref, in or out keywords.
Async instrumentation on ValueTask or ValueTask<T>
Doesn't support DuckType constraints like CallTarget

Implementation details

Normal `Func<string>` instrumentation with no allocations:

    [Fact]
    public void Func1Test()
    {
        var callbacks = new Func1Callbacks();
        Func<string, int> func = (arg1) =>
        {
            callbacks.Count.Value++;
            return 42;
        };

        // Wrap the current delegate and return another with the same type but instrumented.
        func = func.Instrument(callbacks);

        func("Arg01").Should().Be(43);
        callbacks.Count.Value.Should().Be(3);
    }

    public readonly struct Func1Callbacks : IBegin1Callbacks, IReturnCallback
    {
        public Func1Callbacks()
        {
            Count = new StrongBox<int>(0);
        }

        public StrongBox<int> Count { get; }

        public object OnDelegateBegin<TArg1>(object sender, ref TArg1 arg1)
        {
            arg1.Should().Be("Arg01");
            Count.Value++;
            return null;
        }

        public TReturn OnDelegateEnd<TReturn>(object sender, TReturn returnValue, Exception exception, object state)
        {
            Count.Value++;
            return (TReturn)(object)((int)(object)returnValue + 1);
        }

        public void OnException(object sender, Exception ex)
        {
        }
    }

Delegate based `Func<string>` instrumentation with boxing:

    [Fact]
    public void Func1Test()
    {
        var value = 0;
        CustomFunc<string, int> func2 = (arg1) =>
        {
            Interlocked.Increment(ref value).Should().Be(2);
            return 42;
        };

        // Wrap the current delegate and return another with the same type but instrumented.
        // all arguments and return values are boxed to `object?` because we cannot use generics in this method. 
        func2 = func2.Instrument(new DelegateFunc1Callbacks(
                               (target, arg1) =>
                               {
                                   arg1.Should().Be("Arg01");
                                   Interlocked.Increment(ref value).Should().Be(1);
                                   return null;
                               },
                               (target, returnValue, exception, state) =>
                               {
                                   Interlocked.Increment(ref value).Should().Be(3);
                                   return ((int)returnValue) + 1;
                               }));
        func2("Arg01").Should().Be(43);
        value.Should().Be(3);
    }

Async support and setting continuations:

    [Fact]
    public async Task Async1Test()
    {
        var callbacks = new Async1Callbacks();
        Func<string, Task<int>> func = async (arg1) =>
        {
            callbacks.Count.Value++;
            await Task.Delay(100).ConfigureAwait(false);
            return 42;
        };
        func = func.Instrument(callbacks);
        var result = await func("Arg01").ConfigureAwait(false);
        result.Should().Be(43);
        callbacks.Count.Value.Should().Be(4);

        var value = 0;
        CustomFunc<string, Task<int>> func2 = async (arg1) =>
        {
            Interlocked.Increment(ref value).Should().Be(2);
            await Task.Delay(100).ConfigureAwait(false);
            return 42;
        };
        func2 = func2.Instrument(new DelegateFunc1Callbacks(
                               (target, arg1) =>
                               {
                                   arg1.Should().Be("Arg01");
                                   Interlocked.Increment(ref value).Should().Be(1);
                                   return null;
                               },
                               (target, returnValue, exception, state) =>
                               {
                                   Interlocked.Increment(ref value).Should().Be(3);
                                   return returnValue;
                               },
                               onDelegateAsyncEnd: async (sender, returnValue, exception, state) =>
                               {
                                   Interlocked.Increment(ref value).Should().Be(4);
                                   await Task.Delay(100).ConfigureAwait(false);
                                   return ((int)returnValue) + 1;
                               }));
        result = await func2("Arg01").ConfigureAwait(false);
        result.Should().Be(43);
        value.Should().Be(4);
    }

    public readonly struct Async1Callbacks : IBegin1Callbacks, IReturnCallback, IReturnAsyncCallback
    {
        public Async1Callbacks()
        {
            Count = new StrongBox<int>(0);
        }

        public StrongBox<int> Count { get; }

        public object OnDelegateBegin<TArg1>(object sender, ref TArg1 arg1)
        {
            arg1.Should().Be("Arg01");
            Count.Value++;
            return null;
        }

        public TReturn OnDelegateEnd<TReturn>(object sender, TReturn returnValue, Exception exception, object state)
        {
            Count.Value++;
            return returnValue;
        }

        public Task<TInnerReturn> OnDelegateEndAsync<TInnerReturn>(object sender, TInnerReturn returnValue, Exception exception, object state)
        {
            Count.Value++;
            return (Task<TInnerReturn>)(object)Task.FromResult((int)(object)returnValue + 1);
        }

        public void OnException(object sender, Exception ex)
        {
        }
    }

Test coverage

There's a new suite to test all the supported cases.

andrewlock

This is excellent, thanks!

tracer/src/Datadog.Trace/Util/Delegates/DelegateInstrumentation.cs

andrewlock · 2023-09-12T08:06:35Z

tracer/test/Datadog.Trace.Tests/Util/Delegates/FuncInstrumentationTests.cs

+        func2 = DelegateInstrumentation.Wrap(func2, new DelegateFunc0Callbacks(
+                                                 target =>
+                                                 {
+                                                     Interlocked.Increment(ref value).Should().Be(1);
+                                                     return null;
+                                                 },
+                                                 (target, returnValue, exception, state) =>
+                                                 {
+                                                     Interlocked.Increment(ref value).Should().Be(3);
+                                                     return ((int)returnValue) + 1;
+                                                 }));


I wonder if we should actually include these DelegateFunc0Callbacks etc, or maybe just move them into the test project 🤔 Seems like we'd never want to use them in practice if they add extra allocations?

I find this useful for prototyping or when we actually wants to instrument a delegate that runs only once, where the allocations are not so important.

Fair enough, I was mostly thinking that we have enough complexity with this stuff already, having 2 ways to do things muddies the water, especially as it's not as good perf wise 🤷‍♂️ But I'm not passionate about it

andrewlock · 2023-09-15T12:20:13Z

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 (4613) - mean (71ms)  : 64, 79
     .   : milestone, 71,
    master - mean (69ms)  : 63, 74
     .   : milestone, 69,

    section CallTarget+Inlining+NGEN
    This PR (4613) - mean (1,029ms)  : 1005, 1054
     .   : milestone, 1029,
    master - mean (1,028ms)  : 1011, 1045
     .   : milestone, 1028,

gantt
    title Execution time (ms) FakeDbCommand (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4613) - mean (106ms)  : 97, 115
     .   : milestone, 106,
    master - mean (107ms)  : 94, 120
     .   : milestone, 107,

    section CallTarget+Inlining+NGEN
    This PR (4613) - mean (749ms)  : 731, 766
     .   : milestone, 749,
    master - mean (746ms)  : 732, 760
     .   : milestone, 746,

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

    section CallTarget+Inlining+NGEN
    This PR (4613) - mean (708ms)  : 691, 724
     .   : milestone, 708,
    master - mean (710ms)  : 694, 727
     .   : milestone, 710,

gantt
    title Execution time (ms) HttpMessageHandler (.NET Framework 4.6.2) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4613) - mean (189ms)  : 183, 196
     .   : milestone, 189,
    master - mean (187ms)  : 179, 196
     .   : milestone, 187,

    section CallTarget+Inlining+NGEN
    This PR (4613) - mean (1,140ms)  : 1111, 1168
     .   : milestone, 1140,
    master - mean (1,124ms)  : 1098, 1149
     .   : milestone, 1124,

gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4613) - mean (273ms)  : 264, 283
     .   : milestone, 273,
    master - mean (270ms)  : 261, 280
     .   : milestone, 270,

    section CallTarget+Inlining+NGEN
    This PR (4613) - mean (1,108ms)  : 1077, 1140
     .   : milestone, 1108,
    master - mean (1,104ms)  : 1084, 1125
     .   : milestone, 1104,

gantt
    title Execution time (ms) HttpMessageHandler (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (4613) - mean (260ms)  : 247, 274
     .   : milestone, 260,
    master - mean (260ms)  : 247, 273
     .   : milestone, 260,

    section CallTarget+Inlining+NGEN
    This PR (4613) - mean (1,058ms)  : 1028, 1089
     .   : milestone, 1058,
    master - mean (1,053ms)  : 1024, 1081
     .   : milestone, 1053,

datadog-ddstaging · 2023-09-15T12:45:17Z

Datadog Report

Branch report: tony/delegate-instrumentation
Commit report: 333da1b

✅ dd-trace-dotnet: 0 Failed, 0 New Flaky, 302700 Passed, 1154 Skipped, 21m 57.36s Wall Time

andrewlock · 2023-09-15T13:46:32Z

Benchmarks Report 🐌

Benchmarks for #4613 compared to master:

1 benchmarks are faster, with geometric mean 1.149
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.21μs	41.7ns	225ns	0.0237	0.0119	0	7.29 KB
master	`StartStopWithChild`	netcoreapp3.1	10.3μs	58ns	376ns	0.0258	0.0103	0	7.39 KB
master	`StartStopWithChild`	net472	15.6μs	55.7ns	216ns	1.28	0.308	0.0923	7.66 KB
#4613	`StartStopWithChild`	net6.0	8.14μs	44.9ns	273ns	0.0278	0.0119	0	7.28 KB
#4613	`StartStopWithChild`	netcoreapp3.1	9.93μs	50.3ns	252ns	0.0293	0.00978	0	7.39 KB
#4613	`StartStopWithChild`	net472	15.8μs	47ns	182ns	1.28	0.323	0.108	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	470μs	279ns	1.08μs	0	2.7 KB
master	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	660μs	254ns	951ns	0	2.7 KB
master	`WriteAndFlushEnrichedTraces`	net472	803μs	373ns	1.34μs	0.401	3.3 KB
#4613	`WriteAndFlushEnrichedTraces`	net6.0	476μs	222ns	861ns	0	2.7 KB
#4613	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	650μs	377ns	1.46μs	0	2.7 KB
#4613	`WriteAndFlushEnrichedTraces`	net472	818μs	368ns	1.43μ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	42.8μs	79.7ns	287ns	0.0215	0	1.78 KB
master	`AllCycleSimpleBody`	netcoreapp3.1	45.6μs	84.1ns	315ns	0	0	1.75 KB
master	`AllCycleSimpleBody`	net472	47.9μs	15.7ns	60.7ns	0.283	0	1.82 KB
master	`AllCycleMoreComplexBody`	net6.0	235μs	88.1ns	341ns	0.118	0	9.35 KB
master	`AllCycleMoreComplexBody`	netcoreapp3.1	251μs	368ns	1.43μs	0	0	9.24 KB
master	`AllCycleMoreComplexBody`	net472	261μs	282ns	1.09μs	1.44	0	9.42 KB
master	`ObjectExtractorSimpleBody`	net6.0	116ns	0.0364ns	0.131ns	0.00395	0	280 B
master	`ObjectExtractorSimpleBody`	netcoreapp3.1	175ns	0.178ns	0.691ns	0.00367	0	272 B
master	`ObjectExtractorSimpleBody`	net472	144ns	0.128ns	0.496ns	0.0446	0	281 B
master	`ObjectExtractorMoreComplexBody`	net6.0	2.94μs	0.56ns	2.1ns	0.0543	0	3.88 KB
master	`ObjectExtractorMoreComplexBody`	netcoreapp3.1	4.06μs	1.71ns	6.4ns	0.0508	0	3.78 KB
master	`ObjectExtractorMoreComplexBody`	net472	4.15μs	4.27ns	16ns	0.617	0.00615	3.89 KB
#4613	`AllCycleSimpleBody`	net6.0	42μs	28.9ns	108ns	0.0207	0	1.78 KB
#4613	`AllCycleSimpleBody`	netcoreapp3.1	45.7μs	29.6ns	107ns	0.0231	0	1.75 KB
#4613	`AllCycleSimpleBody`	net472	48.6μs	144ns	557ns	0.266	0	1.82 KB
#4613	`AllCycleMoreComplexBody`	net6.0	238μs	193ns	722ns	0.12	0	9.35 KB
#4613	`AllCycleMoreComplexBody`	netcoreapp3.1	249μs	716ns	2.58μs	0.125	0	9.24 KB
#4613	`AllCycleMoreComplexBody`	net472	262μs	103ns	399ns	1.44	0	9.42 KB
#4613	`ObjectExtractorSimpleBody`	net6.0	123ns	0.0471ns	0.182ns	0.00396	0	280 B
#4613	`ObjectExtractorSimpleBody`	netcoreapp3.1	176ns	0.0829ns	0.31ns	0.00371	0	272 B
#4613	`ObjectExtractorSimpleBody`	net472	146ns	0.0931ns	0.361ns	0.0446	0	281 B
#4613	`ObjectExtractorMoreComplexBody`	net6.0	3.07μs	1.04ns	4.03ns	0.0539	0	3.88 KB
#4613	`ObjectExtractorMoreComplexBody`	netcoreapp3.1	4.09μs	1.49ns	5.79ns	0.0511	0	3.78 KB
#4613	`ObjectExtractorMoreComplexBody`	net472	4.16μs	2.21ns	8.57ns	0.618	0.00624	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	49.5μs	182ns	629ns	0.219	0	16.07 KB
master	`RunWaf(args=NestedMap (10))`	netcoreapp3.1	67.7μs	381ns	2.64μs	0.2	0	16.06 KB
master	`RunWaf(args=NestedMap (10))`	net472	96.1μs	35ns	121ns	2.54	0.0957	16.14 KB
master	`RunWafWithAttack(args=Neste(...)tack) [22])`	net6.0	116μs	38.8ns	145ns	0.291	0	22.42 KB
master	`RunWafWithAttack(args=Neste(...)tack) [22])`	netcoreapp3.1	138μs	527ns	1.9μs	0.276	0	22.37 KB
master	`RunWafWithAttack(args=Neste(...)tack) [22])`	net472	166μs	75ns	291ns	3.54	0.165	22.71 KB
master	`RunWaf(args=NestedMap (100))`	net6.0	126μs	604ns	2.34μs	0.447	0	34.74 KB
master	`RunWaf(args=NestedMap (100))`	netcoreapp3.1	165μs	864ns	4.14μs	0.469	0	35.39 KB
master	`RunWaf(args=NestedMap (100))`	net472	222μs	154ns	596ns	5.73	0.424	36.33 KB
master	`RunWafWithAttack(args=Neste(...)tack) [23])`	net6.0	207μs	1.12μs	6.33μs	0.492	0	41.09 KB
master	`RunWafWithAttack(args=Neste(...)tack) [23])`	netcoreapp3.1	247μs	955ns	3.7μs	0.497	0	41.7 KB
master	`RunWafWithAttack(args=Neste(...)tack) [23])`	net472	311μs	538ns	2.08μs	6.76	0.601	42.89 KB
master	`RunWaf(args=NestedMap (1000))`	net6.0	130μs	110ns	426ns	0.471	0	34.74 KB
master	`RunWaf(args=NestedMap (1000))`	netcoreapp3.1	170μs	613ns	2.38μs	0.414	0	35.39 KB
master	`RunWaf(args=NestedMap (1000))`	net472	213μs	65ns	252ns	5.76	0.427	36.34 KB
master	`RunWafWithAttack(args=Neste(...)tack) [24])`	net6.0	204μs	185ns	718ns	0.52	0	41.09 KB
master	`RunWafWithAttack(args=Neste(...)tack) [24])`	netcoreapp3.1	250μs	975ns	3.78μs	0.488	0	41.69 KB
master	`RunWafWithAttack(args=Neste(...)tack) [24])`	net472	306μs	1.04μs	4.03μs	6.79	0.453	42.9 KB
#4613	`RunWaf(args=NestedMap (10))`	net6.0	51.2μs	68.1ns	264ns	0.216	0	16.07 KB
#4613	`RunWaf(args=NestedMap (10))`	netcoreapp3.1	70μs	56ns	202ns	0.193	0	16.06 KB
#4613	`RunWaf(args=NestedMap (10))`	net472	96.8μs	498ns	2.44μs	2.53	0.0936	16.14 KB
#4613	`RunWafWithAttack(args=Neste(...)tack) [22])`	net6.0	122μs	297ns	1.11μs	0.306	0	22.42 KB
#4613	`RunWafWithAttack(args=Neste(...)tack) [22])`	netcoreapp3.1	142μs	770ns	4.15μs	0.282	0	22.37 KB
#4613	`RunWafWithAttack(args=Neste(...)tack) [22])`	net472	166μs	81.3ns	293ns	3.6	0.164	22.71 KB
#4613	`RunWaf(args=NestedMap (100))`	net6.0	119μs	104ns	402ns	0.452	0	34.74 KB
#4613	`RunWaf(args=NestedMap (100))`	netcoreapp3.1	166μs	889ns	4.62μs	0.404	0	35.4 KB
#4613	`RunWaf(args=NestedMap (100))`	net472	223μs	130ns	503ns	5.74	0.442	36.34 KB
#4613	`RunWafWithAttack(args=Neste(...)tack) [23])`	net6.0	199μs	333ns	1.29μs	0.593	0	41.09 KB
#4613	`RunWafWithAttack(args=Neste(...)tack) [23])`	netcoreapp3.1	245μs	919ns	3.56μs	0.485	0	41.7 KB
#4613	`RunWafWithAttack(args=Neste(...)tack) [23])`	net472	311μs	149ns	578ns	6.69	0.466	42.89 KB
#4613	`RunWaf(args=NestedMap (1000))`	net6.0	130μs	604ns	2.34μs	0.484	0	34.75 KB
#4613	`RunWaf(args=NestedMap (1000))`	netcoreapp3.1	168μs	893ns	4.89μs	0.469	0	35.39 KB
#4613	`RunWaf(args=NestedMap (1000))`	net472	216μs	302ns	1.17μs	5.67	0.436	36.34 KB
#4613	`RunWafWithAttack(args=Neste(...)tack) [24])`	net6.0	208μs	257ns	997ns	0.519	0	41.09 KB
#4613	`RunWafWithAttack(args=Neste(...)tack) [24])`	netcoreapp3.1	258μs	1.28μs	5.43μs	0.509	0	41.7 KB
#4613	`RunWafWithAttack(args=Neste(...)tack) [24])`	net472	307μs	1.46μs	5.67μs	6.76	0.451	42.9 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendRequest`	net6.0	169μs	88.3ns	342ns	0.254	18.09 KB
master	`SendRequest`	netcoreapp3.1	189μs	327ns	1.27μs	0.189	20.25 KB
master	`SendRequest`	net472	0.000182ns	0.000101ns	0.000391ns	0	0 b
#4613	`SendRequest`	net6.0	170μs	178ns	691ns	0.253	18.09 KB
#4613	`SendRequest`	netcoreapp3.1	189μs	134ns	502ns	0.188	20.25 KB
#4613	`SendRequest`	net472	0.000552ns	0.000228ns	0.000883ns	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	537μs	2.4μs	9.28μs	0.519	0	0	41.46 KB
master	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	624μs	1.7μs	5.9μs	0.316	0	0	41.77 KB
master	`WriteAndFlushEnrichedTraces`	net472	815μs	3.81μs	17.9μs	8.58	2.45	0.408	53.26 KB
#4613	`WriteAndFlushEnrichedTraces`	net6.0	521μs	389ns	1.4μs	0.536	0	0	41.5 KB
#4613	`WriteAndFlushEnrichedTraces`	netcoreapp3.1	629μs	860ns	3.33μs	0.316	0	0	41.98 KB
#4613	`WriteAndFlushEnrichedTraces`	net472	771μs	2.87μs	10.7μs	8.25	2.36	0.393	53.25 KB

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

Faster 🎉 in #4613

Benchmark	base/diff	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.DbCommandBenchmark.ExecuteNonQuery‑net6.0	1.149	1,174.96	1,022.15

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`ExecuteNonQuery`	net6.0	1.18μs	0.715ns	2.77ns	0.0106	768 B
master	`ExecuteNonQuery`	netcoreapp3.1	1.35μs	0.616ns	2.39ns	0.0101	768 B
master	`ExecuteNonQuery`	net472	1.63μs	0.372ns	1.44ns	0.116	730 B
#4613	`ExecuteNonQuery`	net6.0	1.02μs	0.323ns	1.25ns	0.0107	768 B
#4613	`ExecuteNonQuery`	netcoreapp3.1	1.34μs	0.462ns	1.73ns	0.0107	768 B
#4613	`ExecuteNonQuery`	net472	1.61μs	2.66ns	10.3ns	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.2μs	1.37ns	5.32ns	0.0138	0	992 B
master	`CallElasticsearch`	netcoreapp3.1	1.46μs	0.463ns	1.79ns	0.0131	0	992 B
master	`CallElasticsearch`	net472	2.23μs	0.631ns	2.36ns	0.159	0.00112	1 KB
master	`CallElasticsearchAsync`	net6.0	1.31μs	1.64ns	6.12ns	0.0137	0	968 B
master	`CallElasticsearchAsync`	netcoreapp3.1	1.51μs	0.815ns	3.05ns	0.0143	0	1.04 KB
master	`CallElasticsearchAsync`	net472	2.49μs	0.776ns	3ns	0.167	0	1.06 KB
#4613	`CallElasticsearch`	net6.0	1.32μs	1.19ns	4.61ns	0.0139	0	992 B
#4613	`CallElasticsearch`	netcoreapp3.1	1.4μs	0.559ns	2.17ns	0.0133	0	992 B
#4613	`CallElasticsearch`	net472	2.21μs	0.757ns	2.73ns	0.158	0.00111	1 KB
#4613	`CallElasticsearchAsync`	net6.0	1.3μs	1.2ns	4.64ns	0.0136	0	968 B
#4613	`CallElasticsearchAsync`	netcoreapp3.1	1.57μs	0.888ns	3.32ns	0.0143	0	1.04 KB
#4613	`CallElasticsearchAsync`	net472	2.41μs	0.579ns	2.17ns	0.168	0.0012	1.06 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Allocated
master	`ExecuteAsync`	net6.0	1.34μs	0.695ns	2.6ns	0.0129	0	912 B
master	`ExecuteAsync`	netcoreapp3.1	1.41μs	0.595ns	2.22ns	0.0121	0	912 B
master	`ExecuteAsync`	net472	1.73μs	1.34ns	5.19ns	0.139	0.000862	875 B
#4613	`ExecuteAsync`	net6.0	1.25μs	3.41ns	13.2ns	0.013	0	912 B
#4613	`ExecuteAsync`	netcoreapp3.1	1.47μs	0.599ns	2.24ns	0.0123	0	912 B
#4613	`ExecuteAsync`	net472	1.81μs	1.03ns	3.98ns	0.138	0	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.8μs	1.7ns	6.35ns	0.0267	1.94 KB
master	`SendAsync`	netcoreapp3.1	4.33μs	2.17ns	8.39ns	0.0325	2.48 KB
master	`SendAsync`	net472	7.23μs	4.65ns	18ns	0.482	3.05 KB
#4613	`SendAsync`	net6.0	3.84μs	1.35ns	5.24ns	0.0269	1.94 KB
#4613	`SendAsync`	netcoreapp3.1	4.45μs	4.28ns	16ns	0.0333	2.48 KB
#4613	`SendAsync`	net472	7.13μs	2.3ns	8.61ns	0.482	3.05 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`EnrichedLog`	net6.0	1.34μs	3.19ns	12.4ns	0.0231	1.62 KB
master	`EnrichedLog`	netcoreapp3.1	2.01μs	0.971ns	3.63ns	0.0221	1.62 KB
master	`EnrichedLog`	net472	2.38μs	4.33ns	16.8ns	0.244	1.54 KB
#4613	`EnrichedLog`	net6.0	1.48μs	0.574ns	2.15ns	0.0223	1.62 KB
#4613	`EnrichedLog`	netcoreapp3.1	1.98μs	1.11ns	4.16ns	0.0217	1.62 KB
#4613	`EnrichedLog`	net472	2.32μs	1.22ns	4.57ns	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	114μs	192ns	742ns	0.0571	0	4.21 KB
master	`EnrichedLog`	netcoreapp3.1	118μs	179ns	669ns	0	0	4.21 KB
master	`EnrichedLog`	net472	150μs	159ns	594ns	0.671	0.224	4.38 KB
#4613	`EnrichedLog`	net6.0	112μs	118ns	457ns	0	0	4.21 KB
#4613	`EnrichedLog`	netcoreapp3.1	118μs	119ns	462ns	0	0	4.21 KB
#4613	`EnrichedLog`	net472	148μs	202ns	784ns	0.67	0.223	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.96μs	1ns	3.75ns	0.0298	2.18 KB
master	`EnrichedLog`	netcoreapp3.1	3.77μs	1.09ns	4.07ns	0.0282	2.18 KB
master	`EnrichedLog`	net472	4.59μs	2.28ns	8.84ns	0.314	1.99 KB
#4613	`EnrichedLog`	net6.0	2.85μs	1.28ns	4.79ns	0.0296	2.18 KB
#4613	`EnrichedLog`	netcoreapp3.1	3.79μs	1.7ns	6.35ns	0.0284	2.18 KB
#4613	`EnrichedLog`	net472	4.63μs	1.89ns	7.33ns	0.316	1.99 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`SendReceive`	net6.0	1.24μs	0.844ns	3.16ns	0.0162	1.16 KB
master	`SendReceive`	netcoreapp3.1	1.62μs	2.34ns	8.1ns	0.0155	1.16 KB
master	`SendReceive`	net472	2.12μs	2.2ns	8.53ns	0.185	1.16 KB
#4613	`SendReceive`	net6.0	1.34μs	0.622ns	2.41ns	0.0164	1.16 KB
#4613	`SendReceive`	netcoreapp3.1	1.6μs	0.85ns	3.18ns	0.0152	1.16 KB
#4613	`SendReceive`	net472	2.06μs	1.43ns	5.36ns	0.185	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.62μs	1.77ns	6.86ns	0.0209	1.53 KB
master	`EnrichedLog`	netcoreapp3.1	3.66μs	1.16ns	4.33ns	0.0201	1.58 KB
master	`EnrichedLog`	net472	3.97μs	3.62ns	13.5ns	0.309	1.96 KB
#4613	`EnrichedLog`	net6.0	2.48μs	0.735ns	2.65ns	0.0212	1.53 KB
#4613	`EnrichedLog`	netcoreapp3.1	3.72μs	1.82ns	7.07ns	0.0204	1.58 KB
#4613	`EnrichedLog`	net472	4.12μs	3.35ns	13ns	0.309	1.96 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`StartFinishSpan`	net6.0	441ns	0.694ns	2.69ns	0.00751	536 B
master	`StartFinishSpan`	netcoreapp3.1	575ns	0.192ns	0.693ns	0.00721	536 B
master	`StartFinishSpan`	net472	621ns	0.285ns	1.07ns	0.0852	538 B
master	`StartFinishScope`	net6.0	551ns	0.176ns	0.657ns	0.00916	656 B
master	`StartFinishScope`	netcoreapp3.1	773ns	0.459ns	1.78ns	0.00888	656 B
master	`StartFinishScope`	net472	847ns	0.321ns	1.24ns	0.098	618 B
#4613	`StartFinishSpan`	net6.0	461ns	0.225ns	0.841ns	0.00747	536 B
#4613	`StartFinishSpan`	netcoreapp3.1	558ns	0.227ns	0.879ns	0.0073	536 B
#4613	`StartFinishSpan`	net472	656ns	0.617ns	2.39ns	0.0854	538 B
#4613	`StartFinishScope`	net6.0	537ns	0.209ns	0.782ns	0.0092	656 B
#4613	`StartFinishScope`	netcoreapp3.1	751ns	0.635ns	2.46ns	0.00902	656 B
#4613	`StartFinishScope`	net472	775ns	0.303ns	1.17ns	0.0981	618 B

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Allocated
master	`RunOnMethodBegin`	net6.0	563ns	0.244ns	0.946ns	0.00937	656 B
master	`RunOnMethodBegin`	netcoreapp3.1	811ns	0.538ns	2.01ns	0.00888	656 B
master	`RunOnMethodBegin`	net472	887ns	0.283ns	1.02ns	0.098	618 B
#4613	`RunOnMethodBegin`	net6.0	513ns	0.172ns	0.665ns	0.00918	656 B
#4613	`RunOnMethodBegin`	netcoreapp3.1	803ns	4.04ns	17.1ns	0.00874	656 B
#4613	`RunOnMethodBegin`	net472	927ns	0.212ns	0.82ns	0.0978	618 B

kevingosse

It's always a bit scary to see that much copy/pasting, I wonder if at some point in the future we should try using source generators for those

tonyredondo · 2023-09-15T15:25:58Z

It's always a bit scary to see that much copy/pasting, I wonder if at some point in the future we should try using source generators for those

That’s actually a nice idea for a future PR

zacharycmontoya · 2023-09-28T19:19:39Z

tracer/test/Datadog.Trace.Tests/Util/Delegates/FuncInstrumentationTests.cs

+        public TReturn OnDelegateEnd<TReturn>(object sender, TReturn returnValue, Exception exception, object state)
+        {
+            Count.Value++;
+            return (TReturn)(object)((int)(object)returnValue + 1);


The number of casts 😂

zacharycmontoya · 2023-09-28T19:25:49Z

tracer/src/Datadog.Trace/Util/Delegates/DelegateInstrumentation.cs

+#region Action 0 Argument
+
+    private class Action0Wrapper<TDelegate, TCallbacks> : Wrapper<TDelegate, TCallbacks>
+        where TCallbacks : struct, IBegin0Callbacks, IVoidReturnCallback


These generic constraints :chefs-kiss:

zacharycmontoya

I'm a little late to reviewing this but this is amazing. Nice work!

tonyredondo added 9 commits September 8, 2023 18:30

Action support for delegate instrumentation.

e89e803

Func instrumentation and test suite.

3a0e234

Improvements

fea4ed5

change

0a99dd0

changes

67333cb

Add Default actions

f882ac3

Changes.

429c984

Remove <Delegate>.DynamicInvoke call

bd7fdb6

Improvements

69d3623

tonyredondo self-assigned this Sep 11, 2023

Merge branch 'master' into tony/delegate-instrumentation

f686dfe

tonyredondo marked this pull request as ready for review September 11, 2023 16:00

tonyredondo requested a review from a team as a code owner September 11, 2023 16:00

tonyredondo added 2 commits September 12, 2023 00:30

Add support for preserve the async context.

0b3f1db

Add extension methods

951abf4

DataDog deleted a comment from andrewlock Sep 11, 2023

DataDog deleted a comment from datadog-ddstaging bot Sep 11, 2023

DataDog deleted a comment from andrewlock Sep 11, 2023

This was referenced Sep 12, 2023

[DSM ] - Lag metrics support #4574

Merged

[Serverless] Support tracing top-level statements for AWS Lambda #4535

Merged

andrewlock approved these changes Sep 12, 2023

View reviewed changes

Adds target delegate null support

1f23f39

DataDog deleted a comment from andrewlock Sep 12, 2023

DataDog deleted a comment from datadog-ddstaging bot Sep 12, 2023

DataDog deleted a comment from andrewlock Sep 12, 2023

tonyredondo added 3 commits September 13, 2023 00:20

Add Cache layer to the wrapper types.

c0dcb26

Cached ActivatorHelper instance.

03b76a6

Merge branch 'master' into tony/delegate-instrumentation

7cac22f

DataDog deleted a comment from datadog-ddstaging bot Sep 15, 2023

DataDog deleted a comment from andrewlock Sep 15, 2023

Add support for ValueWithType<TDelegate> struct

0243196

kevingosse approved these changes Sep 15, 2023

View reviewed changes

Merge branch 'master' into tony/delegate-instrumentation

333da1b

tonyredondo merged commit c8ce511 into master Sep 15, 2023

tonyredondo deleted the tony/delegate-instrumentation branch September 15, 2023 19:17

github-actions bot added this to the vNext milestone Sep 15, 2023

andrewlock mentioned this pull request Sep 19, 2023

Skip flaky Waf Memory Tests #4641

Merged

zacharycmontoya reviewed Sep 28, 2023

View reviewed changes

Support for Delegate instrumentation #4613

Support for Delegate instrumentation #4613

Uh oh!

Conversation

tonyredondo commented Sep 11, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Summary of changes

Implementation details

Normal Func<string> instrumentation with no allocations:

Delegate based Func<string> instrumentation with boxing:

Async support and setting continuations:

Test coverage

Uh oh!

andrewlock left a comment

Choose a reason for hiding this comment

Uh oh!

Uh oh!

andrewlock Sep 12, 2023

Choose a reason for hiding this comment

Uh oh!

tonyredondo Sep 12, 2023

Choose a reason for hiding this comment

Uh oh!

andrewlock Sep 14, 2023

Choose a reason for hiding this comment

Uh oh!

andrewlock commented Sep 15, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Execution-Time Benchmarks Report ⏱️

Uh oh!

datadog-ddstaging bot commented Sep 15, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Datadog Report

Uh oh!

andrewlock commented Sep 15, 2023 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Benchmarks Report 🐌

Benchmark details

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Faster 🎉 in #4613

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Raw results

Uh oh!

kevingosse left a comment

Choose a reason for hiding this comment

Uh oh!

tonyredondo commented Sep 15, 2023

Uh oh!

zacharycmontoya Sep 28, 2023

Choose a reason for hiding this comment

Uh oh!

zacharycmontoya Sep 28, 2023

Choose a reason for hiding this comment

Uh oh!

zacharycmontoya left a comment

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

5 participants

tonyredondo commented Sep 11, 2023 •

edited

Loading

Normal `Func<string>` instrumentation with no allocations:

Delegate based `Func<string>` instrumentation with boxing:

andrewlock commented Sep 15, 2023 •

edited

Loading

datadog-ddstaging bot commented Sep 15, 2023 •

edited

Loading

andrewlock commented Sep 15, 2023 •

edited

Loading