Skip to content

dd-trace 2.13.0 and 3.0.0 cause jest memory leak #2297

Closed
Closed
dd-trace 2.13.0 and 3.0.0 cause jest memory leak#2297
Labels
bugSomething isn't working

Description

@blimmer
blimmer
opened on Aug 17, 2022

Expected behaviour

When upgrading between versions of dd-trace < 2.13.0 to 2.13.0 or 3.0.0, I didn't expect any impact on the memory usage of my jest test suite.

Actual behaviour

When I opened a PR updating dd-trace from 2.5.0 to 3.0.0, I noticed that my jest test suite started using lots more memory. This caused the test suite to hang forever, causing CI failures.

Steps to reproduce

I created a repository to reproduce this error: https://github.com/blimmer/dd-trace-express-app. It's a simple express application I created using their generator (npx express-generator). I have a GitHub Actions workflow to run a dummy test suite that simply imports the app.js file and checks that it's not undefined: https://github.com/blimmer/dd-trace-express-app/blob/main/__tests__/1.test.js. I then copied this file 2,000 times to show the issue: https://github.com/blimmer/dd-trace-express-app/tree/main/__tests__

Test Suite Without dd-trace installed

https://github.com/blimmer/dd-trace-express-app/runs/7888638293?check_suite_focus=true

Max Heap Size: 1132 MB
Runtime: 335.825s

Test Suite with dd-trace 2.12.1

blimmer/dd-trace-express-app@b588f37 (#2)

https://github.com/blimmer/dd-trace-express-app/runs/7888648042?check_suite_focus=true

Max Heap Size: 1292 MB
Runtime: 651.54 s

Just by introducing dd-trace in 2.12.1 resulted in a 94% increase in runtime. I'm not even initializing the tracer, just require-ing it, so this is very unexpected. These are single runs on GitHub actions, so it might not be as dramatic as this makes it seem, but something to look into, for sure.

Test Suite With dd-trace 3.0.0

blimmer/dd-trace-express-app@8d7c9f6 (#1)

https://github.com/blimmer/dd-trace-express-app/runs/7888646563?check_suite_focus=true

Max Heap Size: 1661 MB
Runtime: ? (OOM Error)

Environment

  • Operation system: GitHub actions (Linux)
  • Node.js version: 16.16.0
  • Tracer version: 2.13.0 and 3.0.0 (see above)
  • Agent version: N/A
  • Relevant library versions: See package.json of sample project linked above

Activity

  1. blimmer
    added
    bugSomething isn't working
    on Aug 17, 2022
  2. juan-fernandez
    self-assigned this
    on Aug 18, 2022
  3. juan-fernandez
    added
    ci-app
    on Aug 18, 2022

  4. juan-fernandez commented on Aug 18, 2022

    @juan-fernandez
    juan-fernandez
    on Aug 18, 2022
    Collaborator

    hi @blimmer ! Thanks for reporting this and creating a reproducible case. I'm currently working on a PR that should hopefully fix this. I'll keep you updated

  5. juan-fernandez commented on Aug 18, 2022

    @juan-fernandez
    juan-fernandez
    on Aug 18, 2022
    Collaborator

    hi @blimmer ! I jumped to a conclusion too early. I thought this was an issue with the jest plugin but it isn't. The plugin does not start in the example.

    We've identified the actual issue though. While we find a solution there's a workaround that fixes the memory leak. You may set the testEnvironment config parameter (https://jestjs.io/docs/configuration#testenvironment-string) to this file:

    // testEnvironment.js
require('dd-trace')
module.exports = require('jest-environment-node') // this is jest's default but you may have something else! (like jsdom)

    This testEnvironment can be passed as a cli parameter like:

    jest --testEnvironment=./testEnvironment.js --no-cache --logHeapUsage --maxWorkers 1

    With testEnvironment.js being on the root of the project.

    This should stop 'dd-trace' from being instantiated on every test.

    We'll let you know once we fix the issue! 😄

  6. juan-fernandez
    removed their assignment
    on Aug 18, 2022
  7. juan-fernandez
    removed
    ci-app
    on Aug 18, 2022

  8. rochdev commented on Aug 19, 2022

    @rochdev
    rochdev
    on Aug 19, 2022
    Member

    I looked into this a bit more and the problem is that Jest runs tests somewhat in isolation, so the tracer is re-imported on every test. This was already true before, but with the new plugin manager that is based on diagnostics_channel, it means that we keep registering new subscribers for each module we instrument, and these are never removed since Jest keeps built-in modules untouched by default. This is not the root cause however and is just exposing the actual issue more.

    The main issue in fixing this is that we're basically fighting Jest. Since we can't rely on global actually being global, we'd need to store the tracer elsewhere, for example in a built-in module since these are actually global even with Jest. However, Jest is also able to mock those, which would yet again break the tracer. The same is true for any other module that the tracer relies on, especially since we patch the internals that may not be correct if mocked.

    The best way to handle this right now is to make sure the tracer is loaded before Jest, so instead of loading dd-trace programatically it should be loaded with NODE_OPTIONS='-r dd-trace/init' (or NODE_OPTIONS='-r dd-trace/ci/init' when using CI Visibility. This will ensure that dd-trace is loaded before Jest and the same instance is included in every test.

    @juan-fernandez This is not something that we can realistically handle since multiple instances of the tracer will always be problematic. Should we instead disable tracing completely when the load order is incorrect?

  9. juan-fernandez commented on Aug 19, 2022

    @juan-fernandez
    juan-fernandez
    on Aug 19, 2022
    Collaborator

    @juan-fernandez This is not something that we can realistically handle since multiple instances of the tracer will always be problematic. Should we instead disable tracing completely when the load order is incorrect?

    how would we know it's incorrect? Checking if we're in jest and global._ddtrace is undefined?

  10. rochdev commented on Aug 19, 2022

    @rochdev
    rochdev
    on Aug 19, 2022
    Member

    how would we know it's incorrect? Checking if we're in jest and global._ddtrace is undefined?

    @juan-fernandez Yes, when running inside of a Jest runner there is a global jest variable available, and when we are imported before Jest then it's not there and Jest copies existing globals including dd-trace to all workers.

  11. juan-fernandez commented on Aug 29, 2022

    @juan-fernandez
    juan-fernandez
    on Aug 29, 2022
    Collaborator

    this should be fixed in #2316. Pinging @rochdev to confirm.

    @blimmer there's going to be a release soon for you to check this 😄

  12. rochdev commented on Aug 29, 2022

    @rochdev
    rochdev
    on Aug 29, 2022
    Member

    This is now fixed in the latest release. The tracer is now a no-op in Jest workers unless it was required at the process level to avoid it being re-initialized many times.

  13. rochdev
    closed this as completedon Aug 29, 2022

  14. blimmer commented on Aug 29, 2022

    @blimmer
    blimmer
    on Aug 29, 2022
    ContributorAuthor

    I just re-ran it on my sample repo and it looks like the runtime is back down to 374.427 s, which is what I'd expect! We'll test on our real application as well, thank you!

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    bugSomething isn't working

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions