Open
Description
openedon Sep 23, 2020
Describe the bug
We noticed a significant increase in response times for GraphQL queries that produce large payloads after we enabled dd-trace for our project.
Here's what we've seen:
| Date | Node Version | dd-trace Version | scope Setting |
Response Size | Response Time without dd-trace |
Response Time with dd-trace |
Percentage Increase |
|---|---|---|---|---|---|---|---|
| 8/12/2020 | 13.14.0 | 0.20.3 | async_hooks |
~1.8MB | 2.8s | 30s | 971.4% |
| 8/12/2020 | 14.8.0 | 0.24.0 | async_local_storage |
~1.8MB | 2.7s | 7.4s | 174.1% |
| 8/12/2020 | 14.8.0 | 0.24.0 | async_local_storage |
~150kb | 140ms | 220ms | 57.1% |
| 9/23/2020 | 14.8.0 | 0.26.0 | async_local_storage |
~3.2MB | 3.7s | 8.7s | 135.1% |
| 9/23/2020 | 14.8.0 | 0.26.0 | noop |
~3.2MB | 3.7s | 3.8s | 2.7% |
| 9/23/2020 | 14.8.0 | async_resource branch |
async_resource |
~3.2MB | 3.7s | 9.9s | 167.6% |
| 9/23/2020 | 14.8.0 | N/A (disabled) const { createHook } = require('async_hooks'); createHook({ init() {} }).enable(); |
N/A (disabled) | ~3.2MB | 3.7s | 7.4s | 100% |
As you can see, it looks like async_hooks are the primary reason we see the slowdown, and not necessarily anything specific to dd-trace.
The logic that triggers this especially pronounced behavior uses the following:
- Joist ORM, which uses dataloader under the hood
- TypeScript transpiled code, targetting ES2019, meaning we're using
async/awaitvs.Promise
The query itself produces many promises (I'm unsure of the exact number, but probably in the thousands), which we believe is exacerbating the problem.
I was working synchronously with @rochdev and @stephenh on this issue via the Datadog Slack. He mentioned that he'll add some additional detail to this issue.
Environment
- Operation system: Docker -
node:14.8.0image running on macOS host - Node version: 14.8.0
- Tracer version: 0.26.0
- Agent version: 7.22.0
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment