Fix DataFetcher observations hierarchy

Prior to this commit, the `GraphQlObservationInstrumentation` would
organize the parent/child relationship between data fetcher observations
by setting the current observation under a well-known key in the global
GraphQL context.

In some cases, the order of execution and the scheduling of operations
does not reflect the actual operation hierarchy as defined by the
GraphQL `ExecutionStepInfo`. This would result in traces where data
fetching operations are set with incorrect parent/child relationships.

This commit ensures that data fetcher observations have their parent set
with the expected one, by keeping track of active observations and using
the `ExecutionStepInfo` path as a key.

Fixes gh-676
This commit is contained in:
Brian Clozel
2023-04-24 22:51:24 +02:00
parent 4e5aaeddab
commit a56ff6e58d

View File

@@ -16,10 +16,9 @@
package org.springframework.graphql.observation; package org.springframework.graphql.observation;
import java.util.concurrent.CompletionStage;
import graphql.ExecutionResult; import graphql.ExecutionResult;
import graphql.GraphQLContext; import graphql.execution.ExecutionStepInfo;
import graphql.execution.ResultPath;
import graphql.execution.instrumentation.InstrumentationContext; import graphql.execution.instrumentation.InstrumentationContext;
import graphql.execution.instrumentation.InstrumentationState; import graphql.execution.instrumentation.InstrumentationState;
import graphql.execution.instrumentation.SimpleInstrumentation; import graphql.execution.instrumentation.SimpleInstrumentation;
@@ -30,6 +29,10 @@ import graphql.execution.instrumentation.parameters.InstrumentationFieldFetchPar
import graphql.schema.DataFetcher; import graphql.schema.DataFetcher;
import io.micrometer.observation.Observation; import io.micrometer.observation.Observation;
import io.micrometer.observation.ObservationRegistry; import io.micrometer.observation.ObservationRegistry;
import io.micrometer.observation.contextpropagation.ObservationThreadLocalAccessor;
import java.util.concurrent.CompletionStage;
import java.util.concurrent.ConcurrentHashMap;
/** /**
* {@link SimpleInstrumentation} that creates {@link Observation observations} * {@link SimpleInstrumentation} that creates {@link Observation observations}
@@ -50,8 +53,6 @@ import io.micrometer.observation.ObservationRegistry;
*/ */
public class GraphQlObservationInstrumentation extends SimpleInstrumentation { public class GraphQlObservationInstrumentation extends SimpleInstrumentation {
private static final String OBSERVATION_KEY = "micrometer.observation";
private static final ExecutionRequestObservationConvention DEFAULT_REQUEST_CONVENTION = private static final ExecutionRequestObservationConvention DEFAULT_REQUEST_CONVENTION =
new DefaultExecutionRequestObservationConvention(); new DefaultExecutionRequestObservationConvention();
@@ -101,11 +102,10 @@ public class GraphQlObservationInstrumentation extends SimpleInstrumentation {
InstrumentationState state) { InstrumentationState state) {
if (state instanceof RequestObservationInstrumentationState instrumentationState) { if (state instanceof RequestObservationInstrumentationState instrumentationState) {
ExecutionRequestObservationContext observationContext = new ExecutionRequestObservationContext(parameters.getExecutionInput()); ExecutionRequestObservationContext observationContext = new ExecutionRequestObservationContext(parameters.getExecutionInput());
Observation parentObservation = parameters.getGraphQLContext().get(OBSERVATION_KEY); Observation parentObservation = parameters.getGraphQLContext().get(ObservationThreadLocalAccessor.KEY);
Observation requestObservation = instrumentationState.createRequestObservation(this.requestObservationConvention, Observation requestObservation = instrumentationState.createRequestObservation(this.requestObservationConvention,
observationContext, this.observationRegistry); observationContext, this.observationRegistry);
requestObservation.parentObservation(parentObservation); requestObservation.parentObservation(parentObservation);
parameters.getGraphQLContext().put(OBSERVATION_KEY, requestObservation);
requestObservation.start(); requestObservation.start();
return new SimpleInstrumentationContext<>() { return new SimpleInstrumentationContext<>() {
@Override @Override
@@ -115,7 +115,6 @@ public class GraphQlObservationInstrumentation extends SimpleInstrumentation {
requestObservation.error(exc); requestObservation.error(exc);
} }
requestObservation.stop(); requestObservation.stop();
instrumentationState.restoreParentObservation(parameters.getGraphQLContext(), parentObservation);
} }
}; };
} }
@@ -128,13 +127,8 @@ public class GraphQlObservationInstrumentation extends SimpleInstrumentation {
if (!parameters.isTrivialDataFetcher() if (!parameters.isTrivialDataFetcher()
&& state instanceof RequestObservationInstrumentationState instrumentationState) { && state instanceof RequestObservationInstrumentationState instrumentationState) {
return (environment) -> { return (environment) -> {
GraphQLContext graphQLContext = parameters.getExecutionContext().getGraphQLContext();
Observation parentObservation = graphQLContext.get(OBSERVATION_KEY);
DataFetcherObservationContext observationContext = new DataFetcherObservationContext(parameters.getEnvironment()); DataFetcherObservationContext observationContext = new DataFetcherObservationContext(parameters.getEnvironment());
Observation dataFetcherObservation = instrumentationState.createDataFetcherObservation( Observation dataFetcherObservation = instrumentationState.createDataFetcherObservation(this.dataFetcherObservationConvention, observationContext, this.observationRegistry);
this.dataFetcherObservationConvention, observationContext, this.observationRegistry);
dataFetcherObservation.parentObservation(parentObservation);
graphQLContext.put(OBSERVATION_KEY, dataFetcherObservation);
dataFetcherObservation.start(); dataFetcherObservation.start();
try { try {
Object value = dataFetcher.get(environment); Object value = dataFetcher.get(environment);
@@ -145,20 +139,17 @@ public class GraphQlObservationInstrumentation extends SimpleInstrumentation {
dataFetcherObservation.error(error); dataFetcherObservation.error(error);
} }
dataFetcherObservation.stop(); dataFetcherObservation.stop();
instrumentationState.restoreParentObservation(graphQLContext, parentObservation);
}); });
} }
else { else {
observationContext.setValue(value); observationContext.setValue(value);
dataFetcherObservation.stop(); dataFetcherObservation.stop();
instrumentationState.restoreParentObservation(graphQLContext, parentObservation);
return value; return value;
} }
} }
catch (Throwable throwable) { catch (Throwable throwable) {
dataFetcherObservation.error(throwable); dataFetcherObservation.error(throwable);
dataFetcherObservation.stop(); dataFetcherObservation.stop();
instrumentationState.restoreParentObservation(graphQLContext, parentObservation);
throw throwable; throw throwable;
} }
}; };
@@ -169,25 +160,28 @@ public class GraphQlObservationInstrumentation extends SimpleInstrumentation {
static class RequestObservationInstrumentationState implements InstrumentationState { static class RequestObservationInstrumentationState implements InstrumentationState {
private Observation requestObservation;
private final ConcurrentHashMap<ResultPath, Observation> activeObservations = new ConcurrentHashMap<>(8);
Observation createRequestObservation(ExecutionRequestObservationConvention convention, Observation createRequestObservation(ExecutionRequestObservationConvention convention,
ExecutionRequestObservationContext context, ObservationRegistry registry) { ExecutionRequestObservationContext context, ObservationRegistry registry) {
return GraphQlObservationDocumentation.EXECUTION_REQUEST.observation(convention, Observation observation = GraphQlObservationDocumentation.EXECUTION_REQUEST.observation(convention,
DEFAULT_REQUEST_CONVENTION, () -> context, registry); DEFAULT_REQUEST_CONVENTION, () -> context, registry);
this.requestObservation = observation;
return observation;
} }
Observation createDataFetcherObservation(DataFetcherObservationConvention convention, Observation createDataFetcherObservation(DataFetcherObservationConvention convention,
DataFetcherObservationContext context, ObservationRegistry registry) { DataFetcherObservationContext context, ObservationRegistry registry) {
return GraphQlObservationDocumentation.DATA_FETCHER.observation(convention, ExecutionStepInfo executionStepInfo = context.getEnvironment().getExecutionStepInfo();
Observation observation = GraphQlObservationDocumentation.DATA_FETCHER.observation(convention,
DEFAULT_DATA_FETCHER_CONVENTION, () -> context, registry); DEFAULT_DATA_FETCHER_CONVENTION, () -> context, registry);
} Observation parentObservation = (executionStepInfo.hasParent()) ? this.activeObservations.getOrDefault(executionStepInfo.getParent().getPath(), this.requestObservation)
: this.requestObservation;
void restoreParentObservation(GraphQLContext context, Observation parentObservation) { observation.parentObservation(parentObservation);
if (parentObservation != null) { this.activeObservations.put(executionStepInfo.getPath(), observation);
context.put(OBSERVATION_KEY, parentObservation); return observation;
}
else {
context.delete(OBSERVATION_KEY);
}
} }
} }