DataDog
Missing GraphQL Field spans?
Describe the bug
Any idea why field spans wouldn't be showing up while graphql.execute does?
I believe there should be more purple spans below that graphql.execute span.
Environment
I'm using Apollo GraphQL with Express. It's written in TypeScript and compiled using webpack. As you can see, I've figured out all of the "externals" business to make sure things are auto-instrumented, but maybe somehow the field resolvers are getting left out?
- Operation system: Linux 4.14
- Node version: 10.19
- Tracer version: 0.24.2
- Agent version:
Integrations loaded:
"[email protected]",
"http",
"https",
"net",
"dns",
"fs",
"[email protected]",
"[email protected]"
Is this something you can reproduce with a small snippet that you could share? Webpack configurations can greatly differ and there are many things that could go wrong, but it's difficult to know what without looking into actual code.
@dandean We've recently found out that there was a bug in the graphql plugin that caused graphql.resolve spans to have a duration of 0. While they would still show up in the Span List tab, they wouldn't be visible in the flame graph since they would be too small. Can you confirm if you are seeing the missing spans in the list? If that's the case then the fix will be in the next release.
@dandean Were you able to validate if the issue is fixed with the latest version of the tracer and/or replicate with a snippet you can share?
Hi @rochdev - unfortunately I've been absolutely slammed with other things so I haven't had a chance to look yet.
I'm seeing something similar, using apollo-server and dd-trace 0.30.5
We're only seeing spans for top-level fields, while everything else seems to finish nearly instantaneously (including fields with resolvers that are definitely asynchronous).
Stepping through with a debugger, it looks like these 3 lines may be the culprit. For some reason, it looks like Apollo may call execute several times per query – however, because of that conditional, only the first invocation of execute actually gets a wrapped/instrumented fieldResolver.
@schmod We're going to be working on Apollo support soon, but the main issue we've been having is that we are lacking knowledge of how it's used in the wild. Is there some example application we can look at that is representative of how it's generally used and would replicate this kind of issue?
We're not doing anything fancy with Apollo (ie. no schema-stitching or federation), but we are using wrapSchema and addSchemaLevelResolver from graphql-tools. At the end of the day, I'm pretty sure that the "normal" graphql-js library is doing about 95% of the heavy-lifting in our case.
While we can't release our source-code, I can throw together a basic example if you'd like. However, I have a feeling that it will look extremely similar to a GraphQL boilerplate application.
FWIW, Apollo have made some fairly significant changes to their architecture recommendations over the years, which may complicate this discussion somewhat. Federation is still fairly new, and I'm not sure that it's seen much adoption.
While we can't release our source-code, I can throw together a basic example if you'd like. However, I have a feeling that it will look extremely similar to a GraphQL boilerplate application.
That would definitely be appreciated, especially if you can also describe how you would expect the trace to look like so that we know what the final goal is. If you can point to an existing example that would allow us to see the issue that would also work.
Is this still an issue to anyone in this thread? If so, we'd still need more information about the expected behaviour in order to fix the issue. If not, please let us know so that we can close this issue.
@rochdev thank you for checking back! This is working for me:
package.json:
"dd-trace": "^0.29.1",
I can confirm this is still an issue.
In our app we have an endpoint that returns 1000 "rows" (an array of objects). We see one span for each field in the object (so 33 spans), rather than seeing one span per each field & row (33,000 spans).
On the other hand, once the bug is fixed we will most likely not want 33,000 spans per request. Relevant https://xkcd.com/1172/
@joshribakoff-sm This is actually the expected behaviour for arrays as we combine all items as a single span to avoid generating too many resolve spans, and also because it's unlikely that only one of the items would cause performance problems or errors. You can disable this with tracer.use('graphql', { collapse: false }), but as you pointed out that may result in too many spans that would probably not be useful in the first place.
Makes sense, yeah the durations all seem correct then, and all spans are present in our traces 👍
