Dd-trace-js: Improve GraphQL error monitoring

[vecerek]

This issue is not really a feature request nor a bug report. It's just a question for the community. Maybe someone more experienced will have an answer for me 🙂

Apollo Server provides a collection of predefined errors: AuthenticationError, ForbiddenError, UserInputError and a generic one. Once these errors are thrown, they will produce an error object in the GraphQL response and dd-trace will mark the GraphQL execution span with the error flag. However, these errors are expected (for example: the user input error). The traces will be then reported as erroneous. These create a lot of noise in monitors built around errors:

The picture above shows that 9 out of 12 requests were errors but in reality it is just users sending bad requests. Is it possible to improve on error monitoring inside this tool or a totally different approach needs to be taken?

[rochdev]

This makes a lot of sense. It's very similar to the default we have for HTTP, where only 500s are errors on the server and only 400s are errors on the client (by default). Something similar should definitely be added to the graphql plugin, or to a new apollo-server plugin.

[vecerek]

I have two ideas how this could be accomplished:

1. There could be a configuration option for the graphql plugin that would take a list of allowed codes (extensions). One thing to take into account is that the extensions field is optional and its shape can be anything. If the code is allowed, the span should not be marked as an error. The disadvantage of this approach is that a list of handled errors has to be known at the time of initialization.

2. The distinction between an internal error and a client error could be figured out at runtime given a specific structure to extensions. The raised GraphQL error would have to contain a statusCode field which could map to one of the well-known HTTP status codes. Anything in the range 400-499 would not be marked as an erroneous span.
   Disadvantage: no graphql library produces errors that would provide statusCode fields in extensions to my knowledge. This means that all errors produced during the graphql document validation step would still be marked with the error flag unless the libraries implemented this "standard".

{
  "errors": [
    {
      "message": "Name for character with ID 1002 could not be fetched.",
      "locations": [ { "line": 6, "column": 7 } ],
      "path": [ "hero", "heroFriends", 1, "name" ],
      "extensions": {
        "statusCode": 418
      }
    }
  ]
}

Unfortunately, I don't see any other way to make this distinction between an internal server error and a client error. Any ideas/feedback?

[rochdev]

I think option 1 is the safest one to start. It would be a non-breaking change and would allow to filter errors with the most flexibility. For example, some users may want to keep the current behavior.

We also already have the concept of span hooks, which are executed right before a request finishes. Right now there are only implemented for HTTP but it could make sense to implement them to GraphQL as well.

For example, in Express you could do something like this to change the error status based on any condition:

tracer.use('express', {
  hooks: {
    request: (span, req, res) {
      if (somethingWentWrong) {
        span.setTag('error', true)
      }
    }
  }
})

The advantage of the hook is any condition could be used to mark as error or not, but it comes at the cost of additional complexity to write code instead of just adding a configuration. Both are not mutually exclusive however.

[vecerek]

I like the idea of hooks because the client has the absolute control over what span is marked as an error. So, the graphql plugin wraps 3 things: execute, parse and validate. Would then there be 3 corresponding hooks through which a client could modify the behavior of the plugin?

[rochdev]

Yes, but I would probably focus on execute to start. The difficult part of hooks is to figure out what to provide as parameters, other than the span. For Web framework it's easy since you always have a request and a response, but for other types of module it's not always obvious.

[vecerek]

We could take your express hook as an example: (span, req, res) => {}. In GraphQL land req could be represented by the arguments passed to graphql:

graphql(
  schema: GraphQLSchema,
  requestString: string,
  rootValue?: ?any,
  contextValue?: ?any,
  variableValues?: ?{[key: string]: any},
  operationName?: ?string
): Promise<GraphQLResult>

However, for most of the use cases I would expect (span, res) => {} to be enough and I'd consider it as a very good starting point 😄It's debatable whether context, variables or the operationName could play a large role in the somethingWentWrong condition.

I think the most relevant information would already be encoded in the errors object of res anyway.

[rochdev]

However, for most of the use cases I would expect (span, res) => {}

Is res the GraphQLResult?

[vecerek]

Yes.

[rochdev]

The library has an alternative syntax where it accepts all the options as a single parameter. I wonder if it would be relevant to pass that as well, so it would look something like (span, args, result) => {}.

Definition is here

[vecerek]

Hmm... maybe. People put different things into context, e.g. accountId, product information, etc. It can be really anything. Would it make sense to consider certain responses as errors for one customer/product/etc. and not for another? 🤷‍♂I think it makes sense to pass it down for the sake of completeness. Probably someone would request it some time after anyway.

[rochdev]

I was thinking outside the realm of errors, since hooks can apply for all sorts of use cases. For example, maybe you want to add the account ID as a tag on the span, or manually keep/drop traces based on certain conditions.

[vecerek]

I think it would be very useful to add parts of the context as tags to the execution span. But isn't it already made possible through TraceOptions and/or manual instrumentation? I have more experience with the ruby implementation of dd-trace, so I'm not really sure 😅

[rochdev]

But isn't it already made possible through TraceOptions and/or manual instrumentation?

Yes when using manual instrumentation, but in this case it's an existing span created by our auto-instrumentation. There could be the argument that you can just add metadata to the current active span on the scope, but this only works if you are guaranteed that it will always be the execute span, which is not the case, especially since in most cases you would be in the context of a resolve span instead. Using hooks guarantees that the code always runs with the execute span.

[rochdev]

In Ruby the common pattern for this would be to grab the root span, but in this case it doesn't work either because the root is Express and not GraphQL.

[vecerek]

Makes complete sense! Thanks for explaining. (span, args, result) => {} seems to be the right and obvious choice then 🙂

[adamthalhammer]

Wonderful to see this discussion, and the proposed solution looks reasonable 🙏

Two questions:

• Are there any known workarounds?
• How can I help?

[rochdev]

Are there any known workarounds?

It would be possible to work around the issue, but it would most likely rely on internal APIs that may change without notice. In general I'd say it would be better to instead implement the hook. The only thing I'm still not sure about is the args parameter. After looking a bit more into it, it looks like it's converted to an ExecutionContext and that is what is passed around within graphql. I feel like using this context may be closer to what we do in other hooks. The ExecutionContext and ExecutionResult are roughly equivalent for example to the request and response objects for an HTTP request.

How can I help?

Describing your use case would also definitely help understand how the hook would be used to validate the approach mentioned above. We also do welcome community contributions if you're willing to submit a PR :)

[vecerek]

I've just opened a PR. Any feedback would be much appreciated 🙂cc @adamthalhammer

[adamthalhammer]

Sorry, I had a response typed out but must have closed the tab before posting it 😞

Describing your use case would also definitely help understand how the hook would be used to validate the approach mentioned above.

In essence, we want the ability to distinguish between expected and unexpected errors.

1. expected errors occur when our software behaves as designed. Examples of this include input validation errors, authorization errors, etc. They are not the result of a fault and should not be attached to the span, as there is nothing we can or should do to fix them.

2. unexpected errors occur when our software does not behave as designed. For example, if our code throws TypeError: 'undefined' is not an object or an API call to an upstream service fails. These errors are the result of a fault, so they should be attached to the span so that they can be monitored and investigated.

It sounds like the proposed hook will allow us to achieve this. Beyond that, I think it's worth considering ergonomics and sensible defaults:

• Which errors should be attached to the span by default? All (current behaviour)? None? Based on a blacklist (e.g. UserInputError should probably never be attached)?

• Maybe the default can be provided as a hook, so that it can be overridden rather than having to un-do its effects (i.e. "remove" an already attached error from a span)

• What information should be provided to the hook?

[rochdev]

One thing that I'm starting to wonder is which spans exactly should be in error and which should not. Is the issue only with the root graphql.execution span causing the entire trace to be marked as error, or each individual resolver span should also be configurable?

It sounds like the proposed hook will allow us to achieve this. Beyond that, I think it's worth considering ergonomics and sensible defaults

I think the first step is to add the span hook, which is the most flexible option since it allows altering any span metadata including but not limited to errors. Then there could be improvements to handle the errors specifically in a simpler way. For example, in the http plugin there is currently a validateStatus function that can be configured to determine if the request should be marked as an error based on the status code. Something similar to this could be added to graphql, maybe validateResponse?

[vecerek]

@rochdev In GraphQL, if there's an error on a field, that will also be represented in response.errors. That said, I'm not entirely sure if the problem can be fixed by only removing the error tag from the graphql.execute span. I don't know enough about the internals of Datadog's error monitoring/reporting.

The idea I had to allow the removal of specific field errors from span was to use a resolve hook which would have been run in finishResolvers which is called in createWrapExecute.

Considering your proposal with a generic span hook, how would that work in conjunction with other hooks, e.g. the execute hook? Which hook would be called first? Could that lead to weird and hard to reason about misbehavior? For example one hook setting a tag and another one removing/overwriting it in certain cases? But I see that this would probably be consumer-side issue of the plugin. Nevertheless, the behavior needs to be well described.

[rochdev]

Considering your proposal with a generic span hook, how would that work in conjunction with other hooks, e.g. the execute hook?

Right now errors thrown from resolvers are added the span of that resolver. If any errors reaches the execution, then it will be added to the execution span. Since that is the root span, it will mark the trace as being in error.

The reasoning is to know exactly which resolver had an error, and which error, but also to know if the request itself was in error, and thus the trace. For example, if the error was handled and is not in the execution callback, the resolver still error'd, but it was handled and is thus successful from the client perspective.

This can be confusing in cases where errors are used even though from the application perspective there is no error. However, I think the default behavior is correct, at least for the resolvers so that the error information is not lost. In that sense, just removing the error flag from the execution should be enough for the trace to not be marked as error so that it won't show up in the service errors.

If that's not enough in your case and the resolver spans should also not contain the errors, then a resolver hook would definitely be needed. At that point there will be complete flexibility on how to handle this for each individual use cases. This would be a bit advanced however, so I think there should also be some kind of configuration to determine what should be considered an actual error. That configuration could apply to both the execution and the resolvers, so for most cases using the hooks would not be needed. I still prefer to focus on the hooks even if they are more complex than the configuration simply because they offer the most flexibility, making it impossible to forget about a use case. However, if you feel that the configuration option is better for your use case, definitely go for it.

Which hook would be called first?

Each hook is called right before the span is finished for the corresponding operation, so it would be in that order. In general it follows the hierarchy of the trace from left to right.

Could that lead to weird and hard to reason about misbehavior? For example one hook setting a tag and another one removing/overwriting it in certain cases?

This already happens a lot internally in the tracer when information is either not known in advance or turns out to be wrong later in the lifecycle of the span. The setTag and addTags methods are meant to be able to update tags as well, so in that sense it's the expected behavior.

In some of our other tracers, we even have a functionality to outright remove spans from the trace completely. The idea is that it can be very difficult to predict exactly how the tracer will be used and what may be considered useless or even undesirable.

It's also worth noting that there may be use cases for a lot of permutations that can be hard to think of in advance. Maybe one user wants the error only at the execution level, and another user only at the resolver level, and another user wants to move it to a custom span that wraps the whole thing. I think being as flexible as possible, even if less intuitive, is necessary for this.

[vecerek]

just removing the error flag from the execution should be enough for the trace to not be marked as error

This is exactly the desired behavior. With this, there's no need for a resolve hook for our use case.

[vecerek]

@rochdev should this issue be closed since https://github.com/DataDog/dd-trace-js/pull/909 has already been merged?

[rochdev]

@vecerek I would say yes. Hooks are the most configurable way to change the metadata on spans, and to do it automatically it would probably make more sense to add a new plugin for Apollo specifically.

[rochdev]

Closing as mentioned above.