vitest
vitest copied to clipboard
vitest-dev
testTimeout is not fully respected: `Error: [vitest-worker]: Timeout calling "onTaskUpdate"`
Describe the bug
Error: [vitest-worker]: Timeout calling "onTaskUpdate"
Following on https://github.com/vitest-dev/vitest/issues/4497
I'm using vitest to run integration tests.
I have the following configuration for my integration tests:
import { defineConfig } from 'vitest/config';
export default defineConfig({
test: {
include: ['integration-tests/**/*.it.ts'],
environment: 'node',
globals: true,
testTimeout: 1000 * 60 * 2,
},
});
Note that the timeout is set to 2 minutes.
The following error is displayed when one of the individual tests takes longer than 60 seconds to run.
Error: [vitest-worker]: Timeout calling "onTaskUpdate"
❯ Object.onTimeoutError node_modules/vitest/dist/chunks/rpc.Iovn4oWe.js:56:10
❯ Timeout._onTimeout node_modules/vitest/dist/chunks/index.CJ0plNrh.js:60:62
❯ listOnTimeout node:internal/timers:588:17
❯ processTimers node:internal/timers:523:7
It appears that https://github.com/vitest-dev/vitest/blob/main/packages/vitest/src/runtime/workers/forks.ts
simply passes v8 from 'node:v8' to createForksRpcOptions,
this in turn goes to https://github.com/antfu/birpc/blob/3a78f95f7e7f04b3d7b111540ff4ba41ea1a010f/src/index.ts#L192
v8 does not seem to have timeout and consequently createBirpc uses DEFAULT_TIMEOUT which is 60 seconds.
This causes Timeout calling "onTaskUpdate" to be displayed even though the testTimeout is set to 2 minutes and the test actually passes.
The test in trouble
https://github.com/andruhon/gaunt-sloth-assistant/blob/eda76fa89dab2f87d8c5f6078e60e38044e5dd7e/integration-tests/prCommand.it.ts
The test attempts to do a GitHub PR review and check it against GitHub issue as requirements. Test uses real LLM, and at some times of a day LLMs are quite slow to respond, and the test sometimes takes a bit more than a minute.
As you can see in the output below, due to testTimeout the test actually passes, but the error is displayed.
✓ integration-tests/prCommand.it.ts (2 tests) 75517ms
✓ PR Command Integration Tests > should approve PR #39 with issue #23 64763ms
✓ PR Command Integration Tests > should reject PR #1 10754ms
⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯ Unhandled Errors ⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯
Vitest caught 1 unhandled error during the test run.
This might cause false positive tests. Resolve unhandled errors to make sure your tests are not affected.
⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯ Unhandled Error ⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯⎯
Error: [vitest-worker]: Timeout calling "onTaskUpdate"
❯ Object.onTimeoutError node_modules/vitest/dist/chunks/rpc.Iovn4oWe.js:53:10
❯ Timeout._onTimeout node_modules/vitest/dist/chunks/index.CJ0plNrh.js:57:62
❯ listOnTimeout node:internal/timers:588:17
❯ processTimers node:internal/timers:523:7
I can potentially create a PR improving that, or will be happy to take advice if I am misusing vitest.
Reproduction
- set timeout to 2 minutes
- create test which runs a bit longer than a minute
- run test
- observe error
Particular test in trouble https://github.com/andruhon/gaunt-sloth-assistant/blob/eda76fa89dab2f87d8c5f6078e60e38044e5dd7e/integration-tests/prCommand.it.ts
Runner command: https://github.com/andruhon/gaunt-sloth-assistant/blob/eda76fa89dab2f87d8c5f6078e60e38044e5dd7e/integration-tests/support/commandRunner.ts
(updated to point to old unfixed commit using exec sync)
System Info
(observed the same on Windows, WSL, Mac and Linux)
System:
OS: Linux 5.15 Ubuntu 24.04.2 LTS 24.04.2 LTS (Noble Numbat)
CPU: (22) x64 Intel(R) Core(TM) Ultra 7 155H
Memory: 14.10 GB / 15.36 GB
Container: Yes
Shell: 5.2.21 - /bin/bash
Binaries:
Node: 22.15.0 - ~/.nvm/versions/node/v22.15.0/bin/node
npm: 11.4.1 - ~/.nvm/versions/node/v22.15.0/bin/npm
npmPackages:
vitest: ^3.2.3 => 3.2.3
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.
You can avoid this by replacing execSync (https://github.com/andruhon/gaunt-sloth-assistant/blob/main/integration-tests/support/commandRunner.ts) with asynchronous variant such as exec, which would probably look like:
import { exec } from 'child_process';
import { promisify } from 'util';
import path from 'path';
const execAsync = promisify(exec);
export async function runCommandInTestDir(command: string): Promise<string> {
const testDir = path.resolve('./integration-tests');
try {
const { stdout } = await execAsync(command, {
...
Blocking a main thread for such a long time should be avoided in general.
Blocking a main thread for such a long time should be avoided in general.
This is actually blocking the test runner thread, and prevents it from receiving update from main thread.
Looking at the reproduction, I think we can improve the error message here to include the blocking test filename. And also extend birpc timeout if testTimeout exceeds it.
This is actually blocking the test runner thread, and prevents it from receiving update from main thread.
Ah sorry. Yeah, that's what I meant. I'd imagined the author's execSync would run in their main thread logic 😅
Yes, indeed, this error is gone when I switched to async command execution with spawn. Thank you!
(there was a bit of trap using exec, because somehow it was swhitching to pipe input and the app was expecting for a stream, which I din't figure out how to turn off with exec, so I used spawn with stdio: ['ignore', 'pipe', 'pipe'], )
Looking at the reproduction, I think we can improve the error message here to include the blocking test filename.
That would be really appreciated and helpful. Locally everything works just fine for me, but in CI something is failing, and I have no clue what or why.
I created a draft PR. I never contributed before, so I'm not sure what is the way to proceed.
Locally everything works just fine for me, but in CI something is failing, and I have no clue what or why.
@manuel3108 aren't your tests also blocking the thread with execSync? For example, if this execSync('docker ... takes longer than 60s, it will trigger this error. https://github.com/sveltejs/cli/blob/4a77117302b69f70c3ba107cd77e0218e335e02e/packages/addons/_tests/drizzle/test.ts#L20
Try replacing those with non-blocking methods like mentioned in https://github.com/vitest-dev/vitest/issues/8164#issuecomment-2974748890.
They are, but rewriting them to be non blocking is a non trivial task in that case, as I'm relying on the output of that command.
In one of the different discussions and issues regarding that issue, I also mentioned that this was introduced at a specific, non major version number. For me, and apparently lots of other people, this is a breaking regression.
They are, but rewriting them to be non blocking is a non trivial task in that case, as I'm relying on the output of that command.
In one of the different discussions and issues regarding that issue, I also mentioned that this was introduced at a specific, non major version number. For me, and apparently lots of other people, this is a breaking regression.
@manuel3108 this solved my problem, I also needed to get something from command output:
import { spawn } from 'child_process';
import path from 'path';
import { platform } from 'node:os';
/**
* Runs a command in the integration-tests directory using spawn
* This prevents stdin from being treated as a pipe
* @param command - The main command to run
* @param args - The command arguments
* @param endOutput - Output which will terminate the execution
* @returns The command output as a string
*/
export async function runCommandWithArgs(
command: string,
args: string[],
endOutput?: string
): Promise<string> {
const testDir = path.resolve('./integration-tests');
return new Promise((resolve, reject) => {
let stdout = '';
let stderr = '';
const childProcess = spawn(command, args, {
cwd: testDir,
env: {
...process.env,
},
shell: platform().includes('win'),
// Explicitly ignore stdin, otherwise the app switches to pipe mode
stdio: ['ignore', 'pipe', 'pipe'],
});
childProcess.stdout.on('data', (data) => {
stdout += data.toString();
if (endOutput && data.toString().includes(endOutput)) {
childProcess.kill();
resolve(stdout.trim());
return;
}
});
childProcess.stderr.on('data', (data) => {
stderr += data.toString();
});
childProcess.on('close', (code) => {
if (code === 0) {
resolve(stdout.trim());
} else {
reject(new Error(`Command failed with code ${code}\n${stderr}`));
}
});
});
}
also mentioned that this was introduced at a specific, non major version number.
This kind of bugs shouldn't be introduced no matter what the version number is.
@hi-ogawa this seems to be related to https://github.com/vitest-dev/vitest/pull/7700. Resetting branch to that commit and then reverting it fixes the bug. Any ideas what could cause it? Were the final runner.onTaskUpdate rejections ignored previously?
Thank you, will try this out at a later point.
There is already a pr that supposedly fixes this: https://github.com/vitest-dev/vitest/pull/8227, coming out of this discussion that i mentioned in my earlier comment.
Edit to quote myself from the other discussion:
Can confirm that downgrading to 3.0.9 fixes it for me as well. All other comments here did not help me resolve this issue