Skip to content

Latest commit

 

History

1 Commit

Folders and files

NameName
Last commit message
Last commit date
 
 
 
 
 
 
 
 

Repository files navigation

HotChocolate multi-schema AddInstrumentation bug — minimal reproduction

AddInstrumentation registers IServerDiagnosticEventListener and IDataLoaderDiagnosticEventListener in the app-wide DI container with AddSingleton (not TryAddSingleton). When two GraphQL schemas each call .AddInstrumentation(...), the registrations accumulate, and HC's AggregateServerDiagnosticEventListener ends up wrapping two references to the same singleton listener — invoking it twice per HTTP request.

The visible effect: every HTTP GraphQL request emits two ExecuteHttpRequest, two ParseHttpRequest, two FormatHttpResponse activities, with broken parent linkage for execution-scope activities (ResolveFieldValue, ValidateDocument, CompileOperation) underneath.

Run

dotnet run

In another terminal:

curl -s -X POST http://localhost:5099/graphql \
  -H 'Content-Type: application/json' \
  --data '{"query":"{ hello }"}'

Bug output (both schemas have AddInstrumentation)

Console exporter prints, ordered by hierarchy:

POST /graphql/{**slug}             SpanId=01f8...                   (ASP.NET)
└── GraphQL HTTP POST              SpanId=4fd0...   Parent=01f8...  (HC ExecuteHttpRequest #1, never renamed)
    └── query { hello }            SpanId=1eb8...   Parent=4fd0...  (HC ExecuteHttpRequest #2 — renamed by EnrichExecuteRequest)
        └── Parse HTTP Request     SpanId=bad6...   Parent=1eb8...  (HC ParseHttpRequest #1)
            ├── Parse HTTP Request SpanId=d4ee...   Parent=bad6...  (HC ParseHttpRequest #2)
            ├── Validate Document  SpanId=499a...   Parent=bad6...  ← should be Parent=1eb8 (query)
            ├── Compile Operation  SpanId=b9a2...   Parent=bad6...  ← should be Parent=1eb8
            ├── /hello             SpanId=7497...   Parent=bad6...  ← ResolveFieldValue, should be Parent=1eb8
            └── Format HTTP Response SpanId=d08c... Parent=bad6...
                └── Format HTTP Response SpanId=356d... Parent=d08c...

Three things to notice:

  1. Duplicate ExecuteHttpRequest activitiesGraphQL HTTP POST and query { hello } are different SpanIds, the second renamed by EnrichExecuteRequest.
  2. Duplicate ParseHttpRequest and FormatHttpResponse activities, nested inside themselves.
  3. Execution-scope activities (ValidateDocument, CompileOperation, ResolveFieldValue) end up with the first ParseHttpRequest activity as parent — instead of the renamed query { hello } activity. That's because the duplicate firing leaves Activity.Current set to ParseHttpRequest #1 when execution begins, and the parent linkage cascades from there.

Expected (one schema, one AddInstrumentation call)

Comment out the .AddInstrumentation(...) call on the Admin schema in Program.cs and re-run:

POST /graphql/{**slug}             SpanId=e7e7...                   (ASP.NET)
└── query { hello }                SpanId=40a0...   Parent=e7e7...  (HC, single activity, renamed in place)
    ├── Parse HTTP Request         SpanId=0b25...   Parent=40a0...
    ├── Validate Document          SpanId=a4e9...   Parent=40a0...
    ├── Compile Operation          SpanId=75fa...   Parent=40a0...
    ├── /hello                     SpanId=ea64...   Parent=40a0...  (ResolveFieldValue)
    └── Format HTTP Response       SpanId=c821...   Parent=40a0...

Single HC activity per request, all execution-scope activities correctly parented under it.

Why this matters in production

Downstream OpenTelemetry processors that drop or filter activities based on parent timing (e.g. ones that check data.Parent.IsEnded()) misbehave because the inner duplicate's lifetime is owned by ExecuteRequestScope.Dispose (mid-pipeline) while the outer one is held alive by AggregateActivityScope until the HTTP response completes. Per-resolver ResolveFieldValue activities created against the inner duplicate during pipeline execution end up with parent linkage that breaks downstream — in our deployment they stopped reaching the trace store entirely (the parent SpanId pointed at an activity that the export filter had already dropped).

Root cause

HotChocolate.Execution.RequestExecutorBuilderExtensions.AddDiagnosticEventListener<T>(builder, factory):

// IExecutionDiagnosticEventListener — schema-scoped, fine
if (typeof(IExecutionDiagnosticEventListener).IsAssignableFrom(typeof(T)))
{
    builder.ConfigureSchemaServices(s =>
        s.AddSingleton<IExecutionDiagnosticEventListener>(sp =>
            (IExecutionDiagnosticEventListener)factory(sp.GetCombinedServices())));
}
// IDataLoaderDiagnosticEventListener — app-wide AddSingleton, accumulates
else if (typeof(IDataLoaderDiagnosticEventListener).IsAssignableFrom(typeof(T)))
{
    builder.Services.AddSingleton<IDataLoaderDiagnosticEventListener>(sp =>
        (IDataLoaderDiagnosticEventListener)factory(sp));
}
// DiagnosticEventSourceAttribute — app-wide AddSingleton, accumulates
else
{
    builder.Services.TryAddSingleton<T>();
    foreach (var attr in typeof(T).GetCustomAttributes<DiagnosticEventSourceAttribute>(true))
        builder.Services.AddSingleton(attr.Listener, sp => sp.GetRequiredService<T>());
}

Both branches that target app-wide DI use AddSingleton. Calling AddInstrumentation once per schema leaves N descriptors per listener type, all resolving to the same singleton. HotChocolate.AspNetCore.HttpServiceCollectionExtensions then composes IServerDiagnosticEvents via:

var array = sp.GetServices<IServerDiagnosticEventListener>().ToArray();
return array.Length switch
{
    0 => new NoopServerDiagnosticEventListener(),
    1 => array[0],
    _ => new AggregateServerDiagnosticEventListener(array),  // ← wraps duplicates
};

AggregateServerDiagnosticEventListener iterates the array and invokes every entry — both pointing at the same listener instance, so the listener fires twice per event.

Suggested fix

Use TryAddSingleton for the attribute-based mapping, and a guard for the DataLoader factory mapping. Or dedupe by reference inside AggregateServerDiagnosticEventListener so even if duplicate registrations slip through, only one listener fires per event.

Versions tested

  • HotChocolate.AspNetCore 15.0.3 and 15.1.10 — both reproduce
  • HotChocolate.Diagnostics 15.0.3 and 15.1.10 — both reproduce
  • .NET 9 (this repro), .NET 10 (original)
  • OpenTelemetry 1.10.x

Workaround

Only call .AddInstrumentation(...) on one schema. The IExecutionDiagnosticEventListener registration is per-schema (via ConfigureSchemaServices), so this leaves the second schema without resolver- level instrumentation — but the alternative (calling it on both) silently breaks the first schema's instrumentation as shown above.

About

Bug reproduction Repo

Resources

Stars

0 stars

Watchers

0 watching

Forks

Releases

Packages

Contributors

Languages