cleaning pass on HotChocolate instrumentation

[vandonr]

Summary of changes

Follow up on #6248
Some cracks in the nullable analysis were pointed by Andrew, I wanted to fix those, and I also noticed that there were a couple weird things that could be ironed out too.

Reason for change

Implementation details

• add some checks on things that can be null
• remove weird code around NameType

Test coverage

Other details

[vandonr]

the property is defined here: https://github.com/ChilliCream/graphql-platform/blob/c162ca29c23acc69cf81a33155d7384ad4dc9d0f/src/HotChocolate/Core/src/Types/Resolvers/IOperation.cs#L30
It's a struct that looks like a nullable (it has HasValue and Value properties), which is itself a nullable, so there is 2 levels of .Value to get, which explains the initial confusion around this I think.

[andrewlock]

I'm somewhat intrigued and afraid by this, and I'm wondering if we actually have any tests that hit the behaviour 🤔 my concern is because nullable types are really weird 😅 I suspect it is fine in this case, just would be more comfortable if we new we were covering all these paths:

• NameValue is null
• NameValue.Value is null
• NameValue.Value is not null

[andrewlock]

In fact, I'm almost certain this isn't covered, because the behaviour has changed significantly here 🤔

Before, we always created an operation, and then updated the details of the current span. Now you don't do that at all if the operation name is null... That seems like a potentially breaking change?

[vandonr]

how can the .Value be null when they are actual non-nullable struct ?
This is not the latest code that we are commenting on too, it now looks like operation.Name.HasValue ? operation.Name.Value.Value : null
operation is not null/default because we check HasValue before, so here we check name, and then name.Value, any of those can be null.
In any case, we do update the span even if one of those values is null.

[lucaspimentel]

Are we talking about this NameString?

https://github.com/ChilliCream/graphql-platform/blob/12.22.6/src/HotChocolate/Core/src/Abstractions/NameString.cs

If so, this is a custom struct, not a Nullable<T>. And this property is a Nullable<NameString>.

[lucaspimentel]

Just trying to understand the issue :)

[vandonr]

Yes that's right, it's a nullable of a custom struct, but we need a proxy both for the nullable and the NameString struct

[andrewlock]

Before, we always created an operation, and then updated the details of the current span. Now you don't do that at all if the operation name is null

Yeah, ignore this, got my operation vs operation name's confused 😅

I also got confused by the fact there's actually three layers of potential null, IOperationContext.Operation could be null (which is the extra guard you added), and then Operation.NameValue could be null, and Operation.NameValue.Value could be null 😅

[datadog-ddstaging]

Datadog Report

Branch report: vandonr/nit
Commit report: 8300a60
Test service: dd-trace-dotnet

❌ 192 Failed (0 Known Flaky), 541878 Passed, 3557 Skipped, 29h 47m 13.94s Total Time

❌ Failed Tests (192)

This report shows up to 5 failed tests.

• HotChocolateSchemaV0Tests.SubmitsTracesHttp - Datadog.Trace.ClrProfiler.IntegrationTests - Details

  Expand for error

   Results do not match.
   Differences:
   Received: HotChocolateTests.SubmitsTraces.SchemaV0.Pre_13_1_0.received.txt
   Verified: HotChocolateTests.SubmitsTraces.SchemaV0.Pre_13_1_0.verified.txt
   Received Content:
   [
     {
       TraceId: Id_1,
       SpanId: Id_2,
       Name: aspnet_core.request,
   ...
  

• HotChocolateSchemaV0Tests.SubmitsTracesHttp - Datadog.Trace.ClrProfiler.IntegrationTests - Details

  Expand for error

   Results do not match.
   Differences:
   Received: HotChocolateTests.SubmitsTraces.SchemaV0.Pre_13_1_0.received.txt
   Verified: HotChocolateTests.SubmitsTraces.SchemaV0.Pre_13_1_0.verified.txt
   Received Content:
   [
     {
       TraceId: Id_1,
       SpanId: Id_2,
       Name: aspnet_core.request,
   ...
  

• HotChocolateSchemaV0Tests.SubmitsTracesHttp - Datadog.Trace.ClrProfiler.IntegrationTests - Details

  Expand for error

   Results do not match.
   Differences:
   Received: HotChocolateTests.SubmitsTraces.SchemaV0.Pre_13_1_0.received.txt
   Verified: HotChocolateTests.SubmitsTraces.SchemaV0.Pre_13_1_0.verified.txt
   Received Content:
   [
     {
       TraceId: Id_1,
       SpanId: Id_2,
       Name: aspnet_core.request,
   ...
  

• HotChocolateSchemaV0Tests.SubmitsTracesHttp - Datadog.Trace.ClrProfiler.IntegrationTests - Details

  Expand for error

   Results do not match.
   Differences:
   Received: HotChocolateTests.SubmitsTraces.SchemaV0.Pre_13_1_0.received.txt
   Verified: HotChocolateTests.SubmitsTraces.SchemaV0.Pre_13_1_0.verified.txt
   Received Content:
   [
     {
       TraceId: Id_1,
       SpanId: Id_2,
       Name: aspnet_core.request,
   ...
  

• HotChocolateSchemaV0Tests.SubmitsTracesHttp - Datadog.Trace.ClrProfiler.IntegrationTests - Details

  Expand for error

   Results do not match.
   Differences:
   Received: HotChocolateTests.SubmitsTraces.SchemaV0.Pre_13_1_0.received.txt
   Verified: HotChocolateTests.SubmitsTraces.SchemaV0.Pre_13_1_0.verified.txt
   Received Content:
   [
     {
       TraceId: Id_1,
       SpanId: Id_2,
       Name: aspnet_core.request,
   ...
  

[andrewlock]

Execution-Time Benchmarks Report ⏱️

Execution-time results for samples comparing the following branches/commits:

• This PR (6580)
• master

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 (6580) - mean (69ms)  : 67, 72
     .   : milestone, 69,
    master - mean (69ms)  : 66, 72
     .   : milestone, 69,

    section CallTarget+Inlining+NGEN
    This PR (6580) - mean (993ms)  : 970, 1015
     .   : milestone, 993,
    master - mean (990ms)  : 968, 1011
     .   : milestone, 990,

Loading

gantt
    title Execution time (ms) FakeDbCommand (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6580) - mean (103ms)  : 101, 105
     .   : milestone, 103,
    master - mean (103ms)  : 100, 105
     .   : milestone, 103,

    section CallTarget+Inlining+NGEN
    This PR (6580) - mean (673ms)  : 656, 689
     .   : milestone, 673,
    master - mean (674ms)  : 660, 688
     .   : milestone, 674,

Loading

gantt
    title Execution time (ms) FakeDbCommand (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6580) - mean (90ms)  : 88, 92
     .   : milestone, 90,
    master - mean (89ms)  : 88, 91
     .   : milestone, 89,

    section CallTarget+Inlining+NGEN
    This PR (6580) - mean (624ms)  : 610, 638
     .   : milestone, 624,
    master - mean (630ms)  : 616, 644
     .   : milestone, 630,

Loading

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

    section CallTarget+Inlining+NGEN
    This PR (6580) - mean (1,099ms)  : 1065, 1133
     .   : milestone, 1099,
    master - mean (1,097ms)  : 1069, 1125
     .   : milestone, 1097,

Loading

gantt
    title Execution time (ms) HttpMessageHandler (.NET Core 3.1) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6580) - mean (269ms)  : 265, 273
     .   : milestone, 269,
    master - mean (271ms)  : 263, 278
     .   : milestone, 271,

    section CallTarget+Inlining+NGEN
    This PR (6580) - mean (860ms)  : 821, 900
     .   : milestone, 860,
    master - mean (860ms)  : 831, 889
     .   : milestone, 860,

Loading

gantt
    title Execution time (ms) HttpMessageHandler (.NET 6) 
    dateFormat  X
    axisFormat %s
    todayMarker off
    section Baseline
    This PR (6580) - mean (261ms)  : 258, 265
     .   : milestone, 261,
    master - mean (261ms)  : 257, 265
     .   : milestone, 261,

    section CallTarget+Inlining+NGEN
    This PR (6580) - mean (840ms)  : 807, 872
     .   : milestone, 840,
    master - mean (844ms)  : 808, 880
     .   : milestone, 844,

Loading

[andrewlock]

Benchmarks Report for tracer 🐌

Benchmarks for #6580 compared to master:

• 1 benchmarks are faster, with geometric mean 1.125
• 1 benchmarks are slower, with geometric mean 1.120
• 1 benchmarks have more 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.88μs	43ns	247ns	0.0157	0.00783	0	5.61 KB
master	StartStopWithChild	netcoreapp3.1	10μs	50.9ns	233ns	0.0145	0.00484	0	5.8 KB
master	StartStopWithChild	net472	16μs	53.3ns	207ns	1.05	0.307	0.102	6.21 KB
#6580	StartStopWithChild	net6.0	7.88μs	39.2ns	196ns	0.019	0.00761	0	5.62 KB
#6580	StartStopWithChild	netcoreapp3.1	9.92μs	55.8ns	361ns	0.0194	0.0097	0	5.8 KB
#6580	StartStopWithChild	net472	16.1μs	48.7ns	189ns	1.05	0.319	0.104	6.21 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	474μs	295ns	1.06μs	0	0	0	2.7 KB
master	WriteAndFlushEnrichedTraces	netcoreapp3.1	655μs	363ns	1.4μs	0	0	0	2.7 KB
master	WriteAndFlushEnrichedTraces	net472	848μs	359ns	1.39μs	0.422	0	0	3.3 KB
#6580	WriteAndFlushEnrichedTraces	net6.0	473μs	152ns	589ns	0	0	0	2.7 KB
#6580	WriteAndFlushEnrichedTraces	netcoreapp3.1	647μs	272ns	1.02μs	0	0	0	2.7 KB
#6580	WriteAndFlushEnrichedTraces	net472	858μs	725ns	2.81μs	0.425	0	0	3.3 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	128μs	511ns	1.98μs	0.191	0	0	14.47 KB
master	SendRequest	netcoreapp3.1	146μs	380ns	1.47μs	0.216	0	0	17.27 KB
master	SendRequest	net472	0.000795ns	0.000384ns	0.00149ns	0	0	0	0 b
#6580	SendRequest	net6.0	130μs	580ns	2.25μs	0.13	0	0	14.47 KB
#6580	SendRequest	netcoreapp3.1	146μs	287ns	1.11μs	0.215	0	0	17.27 KB
#6580	SendRequest	net472	4.99E‑06ns	4.99E‑06ns	1.87E‑05ns	0	0	0	0 b

Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark - Same speed ✔️ More allocations ⚠️

More allocations ⚠️ in #6580

Benchmark	Base Allocated	Diff Allocated	Change	Change %
Benchmarks.Trace.CIVisibilityProtocolWriterBenchmark.WriteAndFlushEnrichedTraces‑netcoreapp3.1	41.53 KB	41.76 KB	229 B	0.55%

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Gen 2	Allocated
master	WriteAndFlushEnrichedTraces	net6.0	579μs	3.18μs	18.3μs	0.551	0	0	41.68 KB
master	WriteAndFlushEnrichedTraces	netcoreapp3.1	690μs	3.73μs	19.7μs	0.338	0	0	41.53 KB
master	WriteAndFlushEnrichedTraces	net472	839μs	3.07μs	11.1μs	8.39	2.52	0.419	53.3 KB
#6580	WriteAndFlushEnrichedTraces	net6.0	548μs	2.88μs	13.8μs	0.541	0	0	41.54 KB
#6580	WriteAndFlushEnrichedTraces	netcoreapp3.1	641μs	2.77μs	9.99μs	0.324	0	0	41.76 KB
#6580	WriteAndFlushEnrichedTraces	net472	847μs	2.96μs	11.5μs	8.08	2.55	0.425	53.31 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Gen 2	Allocated
master	ExecuteNonQuery	net6.0	1.3μs	1.05ns	4.07ns	0.0143	0	0	1.02 KB
master	ExecuteNonQuery	netcoreapp3.1	1.81μs	1.46ns	5.66ns	0.0136	0	0	1.02 KB
master	ExecuteNonQuery	net472	2.13μs	2.74ns	10.6ns	0.157	0.00107	0	987 B
#6580	ExecuteNonQuery	net6.0	1.22μs	0.861ns	3.1ns	0.0143	0	0	1.02 KB
#6580	ExecuteNonQuery	netcoreapp3.1	1.75μs	1.97ns	7.64ns	0.0138	0	0	1.02 KB
#6580	ExecuteNonQuery	net472	1.98μs	1.81ns	7.01ns	0.156	0.000995	0	987 B

Benchmarks.Trace.ElasticsearchBenchmark - Slower ⚠️ Same allocations ✔️

Slower ⚠️ in #6580

Benchmark	diff/base	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.ElasticsearchBenchmark.CallElasticsearchAsync‑net6.0	1.120	1,293.97	1,449.52

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Gen 2	Allocated
master	CallElasticsearch	net6.0	1.2μs	0.618ns	2.39ns	0.0139	0	0	976 B
master	CallElasticsearch	netcoreapp3.1	1.58μs	0.823ns	3.19ns	0.0134	0	0	976 B
master	CallElasticsearch	net472	2.59μs	2.1ns	8.15ns	0.158	0	0	995 B
master	CallElasticsearchAsync	net6.0	1.29μs	0.474ns	1.84ns	0.0137	0	0	952 B
master	CallElasticsearchAsync	netcoreapp3.1	1.66μs	1.26ns	4.86ns	0.0141	0	0	1.02 KB
master	CallElasticsearchAsync	net472	2.72μs	1.29ns	4.98ns	0.166	0	0	1.05 KB
#6580	CallElasticsearch	net6.0	1.3μs	0.832ns	3.22ns	0.0136	0	0	976 B
#6580	CallElasticsearch	netcoreapp3.1	1.49μs	0.804ns	3.01ns	0.0127	0	0	976 B
#6580	CallElasticsearch	net472	2.51μs	1.32ns	4.94ns	0.157	0	0	995 B
#6580	CallElasticsearchAsync	net6.0	1.45μs	1.04ns	3.91ns	0.0131	0	0	952 B
#6580	CallElasticsearchAsync	netcoreapp3.1	1.6μs	0.75ns	2.8ns	0.0139	0	0	1.02 KB
#6580	CallElasticsearchAsync	net472	2.69μs	1.65ns	6.4ns	0.167	0	0	1.05 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Gen 2	Allocated
master	ExecuteAsync	net6.0	1.34μs	0.698ns	2.52ns	0.0134	0	0	952 B
master	ExecuteAsync	netcoreapp3.1	1.58μs	1.47ns	5.71ns	0.0126	0	0	952 B
master	ExecuteAsync	net472	1.84μs	0.551ns	2.06ns	0.145	0	0	915 B
#6580	ExecuteAsync	net6.0	1.27μs	0.331ns	1.2ns	0.0134	0	0	952 B
#6580	ExecuteAsync	netcoreapp3.1	1.58μs	1.02ns	3.81ns	0.0128	0	0	952 B
#6580	ExecuteAsync	net472	1.85μs	0.497ns	1.92ns	0.145	0	0	915 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	4.41μs	1.63ns	6.09ns	0.0308	0	0	2.31 KB
master	SendAsync	netcoreapp3.1	5.43μs	3.36ns	13ns	0.0381	0	0	2.85 KB
master	SendAsync	net472	7.39μs	2.95ns	11.4ns	0.493	0	0	3.12 KB
#6580	SendAsync	net6.0	4.19μs	1.56ns	5.83ns	0.0313	0	0	2.31 KB
#6580	SendAsync	netcoreapp3.1	5.3μs	4.07ns	14.7ns	0.0372	0	0	2.85 KB
#6580	SendAsync	net472	7.44μs	2.53ns	9.48ns	0.495	0	0	3.12 KB

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Gen 2	Allocated
master	EnrichedLog	net6.0	1.45μs	0.751ns	2.81ns	0.0233	0	0	1.64 KB
master	EnrichedLog	netcoreapp3.1	2.14μs	1.07ns	3.85ns	0.0224	0	0	1.64 KB
master	EnrichedLog	net472	2.43μs	0.734ns	2.75ns	0.249	0	0	1.57 KB
#6580	EnrichedLog	net6.0	1.49μs	0.903ns	3.38ns	0.0231	0	0	1.64 KB
#6580	EnrichedLog	netcoreapp3.1	2.28μs	1.55ns	5.99ns	0.0228	0	0	1.64 KB
#6580	EnrichedLog	net472	2.63μs	1.12ns	4.18ns	0.249	0	0	1.57 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	113μs	90.1ns	325ns	0.0566	0	0	4.28 KB
master	EnrichedLog	netcoreapp3.1	116μs	194ns	753ns	0.058	0	0	4.28 KB
master	EnrichedLog	net472	151μs	140ns	541ns	0.678	0.226	0	4.46 KB
#6580	EnrichedLog	net6.0	113μs	74.2ns	267ns	0.0561	0	0	4.28 KB
#6580	EnrichedLog	netcoreapp3.1	116μs	129ns	499ns	0.0572	0	0	4.28 KB
#6580	EnrichedLog	net472	150μs	131ns	507ns	0.674	0.225	0	4.46 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	3.04μs	1.23ns	4.58ns	0.0304	0	0	2.2 KB
master	EnrichedLog	netcoreapp3.1	4.1μs	1.25ns	4.83ns	0.0287	0	0	2.2 KB
master	EnrichedLog	net472	4.88μs	1.66ns	6.42ns	0.319	0	0	2.02 KB
#6580	EnrichedLog	net6.0	3.03μs	1.32ns	5.13ns	0.0304	0	0	2.2 KB
#6580	EnrichedLog	netcoreapp3.1	4.16μs	1.17ns	4.53ns	0.0289	0	0	2.2 KB
#6580	EnrichedLog	net472	4.92μs	0.803ns	3ns	0.32	0	0	2.02 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.31μs	0.891ns	3.45ns	0.0157	0	0	1.14 KB
master	SendReceive	netcoreapp3.1	1.82μs	1.13ns	4.39ns	0.0155	0	0	1.14 KB
master	SendReceive	net472	2.06μs	0.688ns	2.66ns	0.183	0	0	1.16 KB
#6580	SendReceive	net6.0	1.36μs	1.2ns	4.66ns	0.0157	0	0	1.14 KB
#6580	SendReceive	netcoreapp3.1	1.81μs	0.825ns	3.19ns	0.0154	0	0	1.14 KB
#6580	SendReceive	net472	2.06μs	0.469ns	1.81ns	0.183	0	0	1.16 KB

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

Faster 🎉 in #6580

Benchmark	base/diff	Base Median (ns)	Diff Median (ns)	Modality
Benchmarks.Trace.SerilogBenchmark.EnrichedLog‑net6.0	1.125	2,966.24	2,635.64

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Gen 2	Allocated
master	EnrichedLog	net6.0	2.97μs	0.753ns	2.92ns	0.0222	0	0	1.6 KB
master	EnrichedLog	netcoreapp3.1	3.84μs	2.18ns	8.42ns	0.0211	0	0	1.65 KB
master	EnrichedLog	net472	4.41μs	2.44ns	9.11ns	0.323	0	0	2.04 KB
#6580	EnrichedLog	net6.0	2.64μs	1.56ns	6.03ns	0.0225	0	0	1.6 KB
#6580	EnrichedLog	netcoreapp3.1	3.98μs	1.12ns	4.2ns	0.0219	0	0	1.65 KB
#6580	EnrichedLog	net472	4.5μs	1.75ns	6.8ns	0.323	0	0	2.04 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	420ns	0.632ns	2.45ns	0.00804	0	0	576 B
master	StartFinishSpan	netcoreapp3.1	561ns	0.825ns	3.2ns	0.0078	0	0	576 B
master	StartFinishSpan	net472	575ns	1.49ns	5.78ns	0.0916	0	0	578 B
master	StartFinishScope	net6.0	539ns	0.976ns	3.78ns	0.00964	0	0	696 B
master	StartFinishScope	netcoreapp3.1	804ns	1.28ns	4.95ns	0.00964	0	0	696 B
master	StartFinishScope	net472	871ns	2.4ns	9.29ns	0.104	0	0	658 B
#6580	StartFinishSpan	net6.0	414ns	0.662ns	2.56ns	0.00817	0	0	576 B
#6580	StartFinishSpan	netcoreapp3.1	556ns	0.998ns	3.86ns	0.00782	0	0	576 B
#6580	StartFinishSpan	net472	599ns	1.27ns	4.59ns	0.0915	0	0	578 B
#6580	StartFinishScope	net6.0	540ns	1.17ns	4.54ns	0.00978	0	0	696 B
#6580	StartFinishScope	netcoreapp3.1	779ns	1.03ns	3.97ns	0.00934	0	0	696 B
#6580	StartFinishScope	net472	829ns	1.39ns	5.4ns	0.105	0	0	658 B

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

Raw results

Branch	Method	Toolchain	Mean	StdError	StdDev	Gen 0	Gen 1	Gen 2	Allocated
master	RunOnMethodBegin	net6.0	660ns	0.696ns	2.69ns	0.00991	0	0	696 B
master	RunOnMethodBegin	netcoreapp3.1	933ns	2.35ns	9.1ns	0.00918	0	0	696 B
master	RunOnMethodBegin	net472	1.03μs	1.58ns	6.1ns	0.104	0	0	658 B
#6580	RunOnMethodBegin	net6.0	598ns	0.823ns	3.19ns	0.00982	0	0	696 B
#6580	RunOnMethodBegin	netcoreapp3.1	879ns	1.3ns	5.05ns	0.00918	0	0	696 B
#6580	RunOnMethodBegin	net472	1.06μs	1.56ns	6.05ns	0.104	0	0	658 B

[datadog-ddstaging]

Datadog Report

Branch report: vandonr/nit
Commit report: 70b544d
Test service: dd-trace-dotnet

✅ 0 Failed, 552168 Passed, 4428 Skipped, 32h 20m 12.73s Total Time

[andrewlock]

I'm somewhat intrigued and afraid by this, and I'm wondering if we actually have any tests that hit the behaviour 🤔 my concern is because nullable types are really weird 😅 I suspect it is fine in this case, just would be more comfortable if we new we were covering all these paths:

• NameValue is null
• NameValue.Value is null
• NameValue.Value is not null

[andrewlock]

In fact, I'm almost certain this isn't covered, because the behaviour has changed significantly here 🤔

Before, we always created an operation, and then updated the details of the current span. Now you don't do that at all if the operation name is null... That seems like a potentially breaking change?

[andrewlock]

This one still blows my mind, I'd love to see some tests for it 😅

[vandonr]

I mean there are tests on ducktype here but you mean tests for this specific one ?

[andrewlock]

I really mean as part of the integration test, cases where NameString is null, and/or where NameString.Value is null. I don't know if that's practical, just changing duck types always makes me a bit nervous 😄

[vandonr]

I added a test where the nullable is null (I don't know how to make the NameString have no value though)

[andrewlock]

Hmmm, there's no associated span in the new snapshots though are there? 🤔

[andrewlock]

The comment shows aspnetcore spans, but I don't see any hotchocolate/graphql spans - we'd expect to see one of those wouldn't we? 🤔

[vandonr]

ah, right. I'll double check what is happening

[vandonr]

Yeah you were right to be suspicious, because it doesn't do what I think it would ^^

[vandonr]

ok, it turns out that this query:

dd-trace-dotnet/tracer/test/Datadog.Trace.ClrProfiler.IntegrationTests/HotChocolateTests.cs

Line 126 in 108670c

SubmitGraphqlRequest(url: "/graphql?query=" + WebUtility.UrlEncode("query{book{title author{name}}}"), httpMethod: "GET", graphQlRequestBody: null);

has a null operation name (this is what I was seeing with my breakpoint and I didn't double check). We can see that it has an operation type:

dd-trace-dotnet/tracer/test/snapshots/HotChocolateTests.SubmitsTraces.SchemaV1.Pre_13_1_0.verified.txt

Line 43 in 108670c

graphql.operation.type: Query,

but the operation name field is not filled for that one.
But don't ask me why that is !

I'll remove my extra test case, which was discarded before it reaches the GraphQL execute method, probably by the parser I'd say.

[andrewlock]

Ok cool, so we do already have tests for this, cool, thanks! 🙂

[andrewlock]

Thanks for this and for all the follow up!