Vitest hangs tests, close timed out after 1000ms

[InfraK]

Describe the bug

Started encountering our tests hanging with the message close timed out after 1000ms, a google search lead to this issue, tried everything in there with no success, for us is still hit or miss whether we get the error on not.

We get the error on different machines and also CI.

Reproduction

https://stackblitz.com/edit/vitejs-vite-brwl54?file=package.json

System Info

System:
    OS: macOS 12.4
    CPU: (10) arm64 Apple M1 Pro
    Memory: 133.73 MB / 16.00 GB
    Shell: 5.8.1 - /bin/zsh
  Binaries:
    Node: 16.14.0 - ~/.nvm/versions/node/v16.14.0/bin/node
    Yarn: 3.2.0 - ~/.nvm/versions/node/v16.14.0/bin/yarn
    npm: 8.9.0 - ~/.nvm/versions/node/v16.14.0/bin/npm
  Browsers:
    Chrome: 105.0.5195.102
    Firefox: 101.0.1
    Safari: 15.5

Used Package Manager

npm

Validations

• [X] Follow our Code of Conduct
• [X] Read the Contributing Guidelines.
• [X] Read the docs.
• [X] Check that there isn't already an issue that reports the same bug to avoid creating a duplicate.
• [X] Check that this is a concrete bug. For Q&A open a GitHub Discussion or join our Discord Chat Server.
• [X] The provided reproduction is a minimal reproducible example of the bug.

[itsdillon]

I can confirm the same issue but with pnpm and within a windows github action matrix.

[sheremet-va]

Not sure why it happens in this case, but you can increase timeout with test.teardownTimeout option for now.

[InfraK]

@sheremet-va, the timeout makes no difference, we have increased it to really high amounts and still had the same issue.

This is really slowing down our pipeline and our local workflows, is there any way we can help to troubleshoot or debug? Not even sure where to start.

[sheremet-va]

This is really slowing down our pipeline and our local workflows, is there any way we can help to troubleshoot or debug? Not even sure where to start.

It means you start some process and don't end it. Check you websocket/DB/playwright connections.

[InfraK]

@sheremet-va

Not sure what process we could be opening inside that very minimal repo, just using standard libraries for react development, in our real scenario, we are only testing frontend code without any Websockets or DB connections.

I'm attaching the log from process._getActiveHandles() which I included right before the timeout message, you can review it here here. I can't make heads or tails of the log itself, but maybe you can.

Any further guidance on where to look for issues will be greatly appreciated! Thank you for your time and the hard work you are doing here, I really really like vitest.

[sheremet-va]

Not sure what process we could be opening inside that very minimal repo, just using standard libraries for react development

The repro is fixed, if I increase timeout there. You are saying it didn't work for your project.

I can't make heads or tails of the log itself, but maybe you can.

I'm also not sure what it means, but thanks for the way to check it -- I didn't know about this method 😄

[InfraK]

@sheremet-va Still seeing the issue, looking for forward guidance if you have any.

What I've tried so far:

• Saw this issue with Node itself, and upgraded node to v16.17, issue is still persisting.
• Trying to detect open handles, wtfnode library gives this small report (It's the previous log i found, but in more human form"

close timed out after 1000ms
^C[WTF Node?] open handles:
- File descriptors: (note: stdio always exists)
  - fd 1 (tty) (stdio)
  - fd 0 (tty)
  - fd 2 (tty) (stdio)
- Child processes
  - PID 6841
    - Entry point: node:internal/child_process:253
    - STDIO file descriptors: 22

It seems like there is in fact an open child process that didn't exit, however, I'm not sure what could be spawning it, we are using a very small set of libraries, I'm trying to reproduce the same on StackBlitz but no luck so far.

Process list (not sure if this helps or not)

25552 ttys003    0:00.01 sh ./test-forever.sh
25933 ttys003    0:00.26 npm run test
25934 ttys003    0:00.00 sh /var/folders/7v/bfghyq3x19108d32wxqzgc9h0000gn/T/test-479d11ca.sh
25935 ttys003    0:00.05 node /Users/santiagokent/.../node_modules/.bin/vitest run
25936 ttys003    2:22.86 node /Users/santiagokent/.../node_modules/vitest/dist/cli.mjs run
25938 ttys003    0:00.21 /Users/santiagokent/.../node_modules/esbuild-darwin-arm64/bin/esbuild --service=0.15.7 --ping

[InfraK]

After experimenting a little bit more, we found that disabling threads decreases significantly the chances of getting this error, not sure if this can provide guidance as to what could be failing, this is at least some mitigation for our local workflows and pipeline.

We manually need to cleanup after testing-library.

[fengmk2]

Same problem on Github Action with Node.js >= 16 https://github.com/node-modules/urllib/actions/runs/3122054130/jobs/5063741291

[fengmk2]

Same problem on Github Action with Node.js >= 16 https://github.com/node-modules/urllib/actions/runs/3122054130/jobs/5063741291

Add --no-threads can temporary fixes. https://github.com/node-modules/urllib/pull/398/files#diff-7ae45ad102eab3b6d7e7896acd08c427a9b25b346470d7bc6507b6481575d519R53

[matsko]

Any movement on this? Our CI is blocked at the moment.

[sheremet-va]

Any movement on this? Our CI is blocked at the moment.

Zero movement. This is not a global problem, it's not reproducible to everyone. If you get this error even with hight teardownTimeout it means you have a hanging process that needs to be resolved.

[JoshuaToenyes]

We're experiencing the same issue. Setting threads: false in vitest.config.ts solved the issue, as @fengmk2 indicated.

All of our tests are simple unit tests (99% synchronous). There are no open DB/Playwright/websocket processes that could be causing the hang.

[jessekrubin]

@JoshuaToenyes same here! no hanging process for me and get the same error.

[silverwind]

Seeing this "close timed out after 1000ms" message on Drone CI as well. Test run still succeeds, and all tests are very simple unit tests, nothing fancy, nothing that would keep the event loop alive so I assume any open handles must be inside vitest itself.

Does unfortunately not reproduce locally, even with CI variable set.

[vidarc]

Curious if others are also using c8 for coverage reporting? I just recently started getting this while upgrading to node 18. I tried everything I could think of to track it down in my code, but just switching to istanbul for the coverage seems to have fixed/hidden whatever the issue was. Didn't seem to matter which tests I ran or didn't run, always got the time out error and then had to manually stop the process.

[JoshuaToenyes]

Curious if others are also using c8 for coverage reporting? I just recently started getting this while upgrading to node 18. I tried everything I could think of to track it down in my code, but just switching to istanbul for the coverage seems to have fixed/hidden whatever the issue was. Didn't seem to matter which tests I ran or didn't run, always got the time out error and then had to manually stop the process.

@vidarc I don't think it's related to coverage. We use istanbul and still have the issue. Also, we see the timeout even if not running with coverage.

It could be related to the Node.js version, though. I haven't tried with Node.js < 18 or 19.

[silverwind]

For me, it was on Node 18 with no coverage enabled.

[isaac-scarrott]

This is also not working as correct in our Github Action workflow. Some of our tests fail, but the vitest command exits with code 0, therefore the step is successful. Additionally it doesn't output all logs. I was looking in the vitest code and noticed that if the teardownTimeout is exceeded, the process exists with code 0. I believe this is what is causing the false positives in our pipeline. See the code I am referring to here

[iliketomatoes]

Curious if others are also using c8 for coverage reporting? I just recently started getting this while upgrading to node 18. I tried everything I could think of to track it down in my code, but just switching to istanbul for the coverage seems to have fixed/hidden whatever the issue was. Didn't seem to matter which tests I ran or didn't run, always got the time out error and then had to manually stop the process.

@vidarc I don't think it's related to coverage. We use istanbul and still have the issue. Also, we see the timeout even if not running with coverage.

It could be related to the Node.js version, though. I haven't tried with Node.js < 18 or 19.

@vidarc @JoshuaToenyes I'm on Node 16, and I started to have this problem when I added c8 for code coverage. When I switched to instanbul the problem went away.

[silverwind]

I happen to have one case where it reproduces locally, in a around 1 in 10 runs. When it happens, the node process goes to 100% cpu and hangs forever. I managed to hook up the inspector:

processReallyExit is from module signal-exit module which vitest has multiple dependencies on:

[email protected]
├─┬ @antfu/[email protected]
│ └─┬ [email protected]
│   └── [email protected]
├─┬ [email protected]
│ └── [email protected]
└─┬ [email protected]
  └─┬ [email protected]
    └─┬ [email protected]
      └── [email protected]

reallyExit is a undocumented node internal which apparently is being monkey-patched by signal-exit.

[juriadams]

Very good find, @silverwind!

Could you perhaps share how you managed to attach the inspector? I would love to help get to the bottom of this, as it's also blocking my CI.

[silverwind]

Just node --inspect node_modules/.bin/vitest with chrome chrome://inspect/#devices waiting in background, see here. The problem with the method is one needs to be quick with opening the inspector window because once the process stalls, it seems impossible to hook up the inspector.

BTW the tests I reproduced this with are doing a bit fancy stuff like starting/stopping a HTTP server, so I think it's definitely possibly that in this case it's not a bug in vite itself, but it still smells like one because the exact same tests run fine in jest.

[AlexandrHoroshih]

We had a similar problem on our CI - Vitest tests completed successfully, but sometimes the process would not stop after that and the whole job would hang until it closed by timeout.

I made a script like this:

// vitest_ci.mjs
import 'zx/globals';

import psList from 'ps-list';

setTimeout(async () => {
  console.log(await psList())
  $`exit`
}, 2 * 60 * 1000)

try {
  await $`yarn vitest run`;
} catch (p) {
  $`exit ${p.exitCode}`;
}

and used it instead of yarn vitest run.

I then ran the CI several times until I caught the hang. In the list of processes I saw esbuild 🙃

This looks like the problem from this esbuild issue and it was fixed in version 0.16.3 - two weeks ago

The latest version of Vitest uses [email protected] - we've also updated our Vitest version and haven't caught a hang like this on CI in the last few days 👍

UPD: We still see this problem, but much less often than before the update.

[silverwind]

Still seeing it with esbuild 0.16.10, but I guess this issue has multiple potential causes, so the above update may have fixed one, but not all of them.

[capaj]

Yes, I am seeing this issue with esbuild 0.16.10 too.

[felipesere]

I get this issue too on node 19.3. Its hard to gauge how to dig into this one...

[sheremet-va]

Does anyone have a reproduction that I can look into? Repro in the issue doesn't reproduce this error for me.

[capaj]

I am getting it for all my CI builds today, but no luck in reproducing this locally sorry

[sheremet-va]

Please, check if 0.27.1 fixes the issue. I also added hanging-process reporter that should collect all open processes and show them, if Vitest cannot close it:

// vite.config.ts
export default {
  test: {
    reportes: ['default', 'hanging-process']
  }
}

You can also write your own reporter to track all running processes (it doesn't track processes inside a worker):

// vite.config.ts
const reporter = {
  onInit() {
     startTracking()
  },
  onProcessTimeout() {
     displayProcesses()
  }
}
export default {
  test: {
    reportes: ['default', reporter]
  }
}