Timeout - Async callback was not invoked within the 5000ms timeout not showing where it failed

[evandrocoan]

Bug Report

Jest is not showing which on which line the timeout is happening.

To Reproduce

https://repl.it/@evandrocoan/AttractiveShabbyBusinesses

const sum = require('./sum');

test('Timeout on the wrong place...', async () => {
  expect(sum(1, 2)).toBe(3);
  await new Promise(function(resolve) {});
});

test.each([
  [`Timeout on the wrong place...`, 1],
  [`Tests passing normally now on forwards...`, 2],
])(
  `%s`,
  async function(name, index) {
    expect(sum(1, 2)).toBe(3);
    if(index === 1) {
      await new Promise(function(resolve) {});      
    }
  }
);

Actual behavior

  ● Timeout on the wrong place...

    : Timeout - Async callback was not invoked within the 5000ms timeout specified 
by jest.setTimeout.Timeout - Async callback was not invoked within the 5000ms timeout 
specified by jest.setTimeout.Error:

      1 | const sum = require('./sum');
      2 | 
    > 3 | test('Timeout on the wrong place...', async () => {
        | ^
      4 |   expect(sum(1, 2)).toBe(3);
      5 |   await new Promise(function(resolve) {});
      6 | });

      at new Spec (node_modules/jest-jasmine2/build/jasmine/Spec.js:116:22)
      at Object.<anonymous> (sum.test.js:3:1)

Expected behavior

  ● Timeout on the wrong place...

    : Timeout - Async callback was not invoked within the 5000ms timeout specified by 
jest.setTimeout.Timeout - Async callback was not invoked within the 5000ms timeout 
specified by jest.setTimeout.Error:

      3 | test('Timeout on the wrong place...', () => {
      4 |   expect(sum(1, 2)).toBe(3);
    > 5 |   await new Promise(function(resolve) {});
        |   ^
      6 | });
      7 | 
      8 | test.each([

envinfo

 npx envinfo --preset jest
npx: installed 1 in 3.299s

  System:
    OS: Linux 4.15 Debian GNU/Linux 9 (stretch) 9 (stretch)
    CPU: (4) x64 Intel(R) Xeon(R) CPU @ 2.30GHz
  Binaries:
    Node: 12.16.2 - /usr/local/bin/node
    Yarn: 1.22.4 - /usr/local/bin/yarn
    npm: 6.14.4 - /usr/local/bin/npm
  npmPackages:
    jest: ^24.9.0 => 24.9.0 

Related:

1. Asynchronous operations not stopped in tests? #7817 - Asynchronous operations not stopped in tests?
2. Async callback was not invoked within the 5000ms timeout - Error Message Improvement #8384 - Async callback was not invoked within the 5000ms timeout - Error Message Improvement
3. before handlers timing out looks like the test timing out #8284 - before handlers timing out looks like the test timing out
4. beforeAll() executed in parallel with test case in case of timeout #9527 - beforeAll() executed in parallel with test case in case of timeout

[anitawoodruff]

For anyone experiencing the same issue with jest puppeteer tests, I found a workaround to make the failure message display the line where it's timing out:

1. Increase the global default Jest timeout to something large (anywhere in the test):

jest.setTimeout(30000);

2. Then, inside the test, set an explicit shorter timeout duration on the waitFor line which is timing out:

await page.waitForSelector('.Foo', { timeout: 5000 });

Now, my failure message looks like this:

    TimeoutError: waiting for selector ".Foo" failed: timeout 5000ms exceeded

      42 | 
      43 |              // wait for the Foo button
    > 44 |              await page.waitForSelector('.Foo', { timeout: 5000 });
         |                         ^
      45 |              await page.click('.Foo');
      46 | 

Note, the timeout duration inside the test has to be a shorter than the global timeout, otherwise it has no effect.

Edit: Caveat - this seems to work for page.waitForSelector but not page.goto in my experience

[darekkay]

Here are some related issues:

• Puppeteer cannot start chrome storybookjs/storybook#3110
• Puppeteer fails to connect to Chromium on Windows 10 puppeteer/puppeteer#3681

[fernanndosenna]

Just put setTimeout (function () {}, 5000) around in the code, this solved my problem

[evandrocoan]

@fernanndosenna , can you give an example? I am not sure how I would use it.

[agentdon]

Does anyone know if there's been any progress resolving this issue? We're hitting timeouts in some React Testing Library tests and it would be really nice to be able to see how far we got before the tests timed out. @SimenB if you're able to point me in the right direction, I'm interested in taking a swing at fixing this. I just need to know where to start. (Also, long time no see @SimenB! 👋 Glad to see Jest still has you on the team. 👌 Hope you're doing well.)

[SimenB]

Jest cannot know which await was the one to time out - all Jest knows is that the promise returned from your function never resolved (or rejected). Only option is something similar to #9785, if anyone wants to try (I don't even know if inspector can give us this information, or if it's feasible to add such overhead to tests).

We could at some point add proper tracking to e.g. expect calls, and know which was the last executed or something, but that's a huge change.

Either way, this is not a bug, simply the way JavaScript works. Feel free to open a feature request for tracking expect calls or some such (OTTOMH we could store "last assertion" on the test state object and point to that on timeout. sounds ugly, tho, but happy to consider a concrete suggestion (or even better, a PR!). sorta similar to expect.hasAssertions etc..).

---

Workaround would be to add timeouts to your own promises, like the puppeteer example in #9881 (comment) - but note that this is a promise that rejects after a timeout, it's not hanging indefinitely.

I thought RTL already did something similar (timing out a bit lower than Jest's timeout), but that probably falls apart if there are multiple awaits

[agentdon]

Got it. That makes sense. So, is the plan in #9881 to wire up an inspector so that folks can use it to profile the test to see where the time is being spent in the test?

[SimenB]

If you mean #9785, then the plan would be for Jest to point to last where a promise never resolved, like it would point to where an infinite loop happens 🙂

I'd suggest increasing test timeout and reducing (or adding if missing) a timeout to promises created

[agentdon]

Sounds great. Thanks Simen! 🙂

[github-actions]

This issue has been automatically locked since there has not been any recent activity after it was closed. Please open a new issue for related bugs.
Please note this issue tracker is not a help forum. We recommend using StackOverflow or our discord channel for questions.