Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Tracing support fails with NullPointerException when propagation information is missing #547

Closed
RutgerLubbers opened this issue Nov 25, 2022 · 2 comments
Assignees
Labels
in: core Issues related to config and core support type: bug A general bug
Milestone

Comments

@RutgerLubbers
Copy link

RutgerLubbers commented Nov 25, 2022

Using Spring Boot 3.0.0 and GraphQL 1.1.0 with MVC an NPE occurs.

When calling a controller, a trace-id is generated as expected. The trace shows up in Grafana (etc).
When calling the graphiql endpoint, an NPE is generated.

An example project can be found here: https://github.com/RutgerLubbers/graphql-observability

2022-11-25 16:11:17.504 ERROR 64991 [] --- [nio-8080-exec-2] o.a.c.c.C.[.[.[/].[dispatcherServlet]    : Servlet.service() for servlet [dispatcherServlet] threw exception

java.lang.NullPointerException: Cannot invoke "Object.toString()" because the return value of "java.util.Map.get(Object)" is null
	at org.springframework.graphql.observation.ExecutionRequestObservationContext.lambda$new$0(ExecutionRequestObservationContext.java:35)
	at io.micrometer.tracing.handler.PropagatingReceiverTracingObservationHandler.lambda$onStart$0(PropagatingReceiverTracingObservationHandler.java:59)
	at io.micrometer.tracing.brave.bridge.W3CPropagation.lambda$extractor$1(W3CPropagation.java:249)
	at io.micrometer.tracing.brave.bridge.BravePropagator.extract(BravePropagator.java:59)
	at io.micrometer.tracing.handler.PropagatingReceiverTracingObservationHandler.onStart(PropagatingReceiverTracingObservationHandler.java:58)
	at io.micrometer.tracing.handler.PropagatingReceiverTracingObservationHandler.onStart(PropagatingReceiverTracingObservationHandler.java:35)
	at io.micrometer.observation.ObservationHandler$FirstMatchingCompositeObservationHandler.lambda$onStart$1(ObservationHandler.java:134)
	at java.base/java.util.Optional.ifPresent(Optional.java:178)
	at io.micrometer.observation.ObservationHandler$FirstMatchingCompositeObservationHandler.onStart(ObservationHandler.java:134)
	at io.micrometer.observation.SimpleObservation.lambda$notifyOnObservationStarted$2(SimpleObservation.java:188)
	at java.base/java.util.ArrayDeque.forEach(ArrayDeque.java:888)
	at io.micrometer.observation.SimpleObservation.notifyOnObservationStarted(SimpleObservation.java:188)
	at io.micrometer.observation.SimpleObservation.start(SimpleObservation.java:143)
	at org.springframework.graphql.observation.GraphQlObservationInstrumentation.beginExecution(GraphQlObservationInstrumentation.java:105)
	at graphql.execution.instrumentation.ChainedInstrumentation.lambda$beginExecution$0(ChainedInstrumentation.java:85)
	at graphql.collect.ImmutableKit.mapAndDropNulls(ImmutableKit.java:107)
	at graphql.execution.instrumentation.ChainedInstrumentation.beginExecution(ChainedInstrumentation.java:83)
	at graphql.GraphQL.executeAsync(GraphQL.java:522)
	at org.springframework.graphql.execution.DefaultExecutionGraphQlService.lambda$execute$2(DefaultExecutionGraphQlService.java:82)
	...
@spring-projects-issues spring-projects-issues added the status: waiting-for-triage An issue we've not yet triaged label Nov 25, 2022
@bclozel bclozel self-assigned this Nov 25, 2022
@bclozel bclozel added type: bug A general bug in: core Issues related to config and core support and removed status: waiting-for-triage An issue we've not yet triaged labels Nov 29, 2022
@bclozel bclozel changed the title GraphQL via WebMVC and Observability - NullPointerException Tracing support fails with NullPointerException when propagation information is missing Dec 1, 2022
@bclozel
Copy link
Member

bclozel commented Dec 1, 2022

Thanks @RutgerLubbers for this issue. The instrumentation was not well tested here and we'll use this issue to revisit fix and improve tracing support in general.

This issue shows that when extracting the propagation information from inbound requests, we are only looking at the graphql request extension and failing with an NPE if the extensions map is null...

We should change the instrumentation to first look up the propagation information in the GraphQL context. Developers can use a transport specific interceptor to look up that information in the transport protocol and put it in the graphql context. This is the case if HTTP clients send this information as request headers. We should provide a WebGraphQlInterceptor interceptor that does just that.
If the propagation information is not available in the GraphQL context, we should then fall back to the request extensions and ensure that we don't fail if they are missing.

Since the tracing support is effectively broken, we will also change the contextual name of the observation to better align with other implementations, from graphQL to graphql. Without this change, the name of the observation can be normalized by collectors as graph-q-l and this is unfortunate.

@bclozel
Copy link
Member

bclozel commented Dec 2, 2022

Created #558 to align conventions in a separate issue.

@bclozel bclozel closed this as completed in a43c928 Dec 2, 2022
bclozel added a commit to spring-projects/spring-boot that referenced this issue Dec 19, 2022
As of spring-projects/spring-graphql#547, Spring GraphQL introduced a
`PropagationWebGraphQlInterceptor` that propagates the incoming tracing
information in HTTP request headers into the GraphQL context.

This commit auto-configures the propagation interceptor if the
application exposes a GraphQL HTTP endpoint and if it is configured for
Tracing support.

Fixes gh-33542
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
in: core Issues related to config and core support type: bug A general bug
Projects
None yet
Development

No branches or pull requests

3 participants