Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

beforeAll() executed in parallel with test case in case of timeout #9527

Open
aalexgabi opened this issue Feb 6, 2020 · 36 comments
Open

beforeAll() executed in parallel with test case in case of timeout #9527

aalexgabi opened this issue Feb 6, 2020 · 36 comments

Comments

@aalexgabi
Copy link

🐛 Bug Report

Test case is executed even if beforeAll did not finish.

To Reproduce

This test file:

beforeAll(async () => new Promise((resolve, reject) => {
  // Never resolves
}));

test('test case', async () => {
  console.log('should never be executed');
});

Displays this:

% npx jest t.spec.js
 FAIL  ./t.spec.js (5.415s)
  ✕ test case (8ms)

  ● test case

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

      at mapper (node_modules/jest-jasmine2/build/queueRunner.js:25:45)

  console.log t.spec.js:6
    should never be executed

Test Suites: 1 failed, 1 total
Tests:       1 failed, 1 total
Snapshots:   0 total
Time:        5.436s, estimated 6s
Ran all test suites matching /t.spec.js/i.

Expected behavior

Test case code should never be executed because beforeAll() did not finish. The error message should be at the beforeAll level and not at the test case level. This is very confusing as you may think that the test case itself failed when in reality it has nothing to do with the test case.

Link to repl or repo (highly encouraged)

https://repl.it/repls/KindlyAutomaticLocation

envinfo

% npx envinfo --preset jest
npx: installed 1 in 0.645s

  System:
    OS: Linux 5.3 Manjaro Linux
    CPU: (12) x64 Intel(R) Core(TM) i7-9750H CPU @ 2.60GHz
  Binaries:
    Node: 13.7.0 - /usr/bin/node
    Yarn: 1.21.1 - /usr/bin/yarn
    npm: 6.13.6 - /usr/bin/npm
  npmPackages:
    jest: ^24.9.0 => 24.9.0 
@dfleury
Copy link

dfleury commented Feb 20, 2020

Still occuring with jest 25.1.0.
I'm starting a http server and waiting the server.listen() callback to be called to resolve the promise and ensure the server is able to receive requests. However, the testcase is running before the server is up and running because the runner isn't waiting beforeAll finish their job, just like @aalexgabi reported.

@dfleury
Copy link

dfleury commented Feb 27, 2020

Seems I've found a workaround here. Since I wrapped my test case and hooks with a describe function, seems that jest is now respecting the async beforeAll.

@aalexgabi
Copy link
Author

@dfleury I do not observe the same behaviour:

% cat test/t.spec.js 
describe('main', () => {
  beforeAll(async () => new Promise((resolve, reject) => {
    // Never resolves
  }));

  test('test case', async () => {
    console.log('should never be executed');
  });
});

% npx jest test/t.spec.js 
 FAIL  test/t.spec.js (5.296s)
  main
    ✕ test case (5ms)

  ● main › test case

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

      at mapper (node_modules/jest-jasmine2/build/queueRunner.js:25:45)

  console.log test/t.spec.js:7
    should never be executed

Test Suites: 1 failed, 1 total
Tests:       1 failed, 1 total
Snapshots:   0 total
Time:        5.646s, estimated 6s
Ran all test suites matching /test\/t.spec.js/i.

% npx envinfo --preset jest
npx: installed 1 in 0.727s

  System:
    OS: Linux 5.3 Manjaro Linux
    CPU: (12) x64 Intel(R) Core(TM) i7-9750H CPU @ 2.60GHz
  Binaries:
    Node: 13.7.0 - /usr/bin/node
    Yarn: 1.22.0 - /usr/bin/yarn
    npm: 6.13.6 - /usr/bin/npm
  npmPackages:
    jest: ^25.1.0 => 25.1.0 

@dfleury
Copy link

dfleury commented Mar 2, 2020

I guess the problem in your example is you're never resolving the promise and the global timeout is firing because of that.
What I've catched here is similar but different since my test case was running in parallel with beforeAll even I'm respecting the 5s limit and, a variable that might be defined by beforeAll was being used before it was ready. That way, my test case failed saying that variable X wasn't defined.
In a tweet, I think the issue here is jest isn't respecting the execution order of a global beforeAll (out of any scope).

@fvbrennan
Copy link

fvbrennan commented Mar 20, 2020

We have been bitten by this unexpected behaviour as well, here is a simple repro case where the log output will show the improper sequencing

//Keeping default jest timeout of 5s

beforeAll(async () => {
  console.log("In beforeAll, starting sleep");
  await sleep(12);
  console.log("beforeAll finally finished sleeping");
});

describe("outerDescribe", () => {
  beforeEach(async () => {
    console.log("In beforeEach, starting sleep");
    await sleep(6);
    console.log("beforeEach finally finished sleeping");
  });
  describe("innerDescribe", () => {
    it("Does absolutely nothing useful", () => {
      console.log("Executing testcase 1");
    });
    it("Also does nothing useful", () => {
      console.log("Executing testcase 2");
    });
  });
});

function sleep(seconds) {
  return new Promise(resolve => setTimeout(resolve, seconds * 1000));
}

Output:
In beforeAll, starting sleep
In beforeEach, starting sleep
Executing testcase 1
Error: Timeout - Async callback was not invoked within the 5000ms timeout specified by jest.setTimeout.
console.log app/tests/test.js:9
In beforeEach, starting sleep
beforeEach finally finished sleeping
beforeAll finally finished sleeping
Executing testcase 2
Error: Timeout - Async callback was not invoked within the 5000ms timeout specified by

@thernstig
Copy link
Contributor

Same with using beforeEach().

@albert-schilling
Copy link

I have the same issue. Planned on using a deleteAllEntries() function to clean my collection in db before tests and placed the function in beforeAll(), but apparently other test functions are already adding entries to the db, while deleteAllEntries() has not yet finished.

The parallel execution of beforeAll() and afterAll() with the tests somehow defies their inherent purpose?

Anyone found a good solution to this?

@mateuspiresl
Copy link

I'm facing this issue.
Agree with @albert-schilling. There is no point in testing being run before preparation (beforeAll and beforeEach) is complete.

@eps1lon
Copy link
Contributor

eps1lon commented Jan 2, 2021

Am I understanding this correctly that jest is basically telling that you shouldn't share context between tests at all? For example, with puppeteer/playwright it's commonly documented to do

describe.each(["chromium", "firefox"])("%s", (browserType) => {
	let browser;
	let page;

	beforeAll(async () => {
		browser = await playwright[browserType].launch();
	});

	afterAll(async () => {
		await browser.close();
	});

	beforeEach(async () => {
		page = await browser.newPage();
	});

	afterEach(async () => {
		await page.close();
	});

  it('first test', async () => {
    //  do something with `page`
  });

  it('second test', () => {
    // do something with a new `page` that doesn't interfere with the first test
  });
});

With jest that doesn't seem possible since an afterEach which closes the page could run during one of the test because jest doesn't wait for before*/after* to finish?

It's not a blocker since I can create a new browser and page per test but then what is the point of before* and after hooks?

@wanton7
Copy link

wanton7 commented Jan 18, 2021

Our company lost 4 man-days of development because of this bug. Please fix this so others don't suffer the same fate. Return proper error for this and don't run test if beforeAll etc timeouts. So they know that they need to put bigger timeout as second argument for beforeAll and afterAll etc.

@hananmalka
Copy link

Anyone found any workaround for this?
At least until it will be fixed?

I'm facing the same issue in beforEach() when running playwright tests

@wanton7
Copy link

wanton7 commented Jan 18, 2021

@hananmalka Use bigger timeout. beforeEach should also support timeout in milliseconds as second argument. So example beforeEach(function {...}, 60000); for 1 minute timeout.

@hananmalka
Copy link

@wanton7 I tried this one but it didn't work.
Looks like it ignores the timeout I set...

@wanton7
Copy link

wanton7 commented Jan 18, 2021

@hananmalka very odd because it works for beforeAll at least worked for our company and docs https://jestjs.io/docs/en/api#beforeeachfn-timeout say it supports timeout. Another bug?

@hananmalka
Copy link

@wanton7
Not sure.
This is my code:

beforeEach(async () => {
    await page.goto("https://www.google.com");
    await page.reload();
  }, 60000);

  it("test", async () => {
    await page.goto("some_other_site");
  });

And this is the error I get:

Cannot log after tests are done. Did you forget to wait for something async in your test?
  Attempted to log "[2021-01-18 20:15:12.076] [INFO] console - page.goto: Navigation failed because page was closed!

According to this error it looks like it tries to do the actions inside the "it" before the "beforeEach" ends...
I have no idea what is this about.

I'm using playwright and testRunner: "jasmine2"
When I removing this testRunner from jest.config.js - all works as expected.
Seems like it's an issue with the testRunner - but unfortunately I don't know what.

@wanton7
Copy link

wanton7 commented Jan 18, 2021

@hananmalka from looks if it, I don't think you even have this issue. I think Promise from await page.goto("https://www.google.com"); is rejected. Looks to me www.google.com closes connection before your page.goto call completes.

harbu added a commit to streamr-dev/broker that referenced this issue Feb 3, 2021
Use `jest-circus` as test runner. Seems to resolve this issue jestjs/jest#9527 and the issue where a rejecting promise returned from `beforeAll` does not prevent test cases from being run. I had to fix tests cases that have both `done()` and `async` in use in them because circus throws an error if using both in a test. I also increased default test timeout to 10 seconds, as it seems 5 seconds is not enough in many cases.
@Rossh87
Copy link

Rossh87 commented Feb 9, 2021

For anyone else having trouble with this, the problematic behavior comes from the default Jasmine2 test runner. Specifying jest-circus as your test runner will stop tests from running when a before hook fails, and yields a more intelligible error. To run your tests with jest-circus, from the root of your project run yarn add jest-circus, and pass in the appropriate CLI option whenever you invoke jest:

yarn jest --testRunner=jest-circus/runner [...other options]

Alternatively, add the following to your jest config file:

{
//...your other config options
"testRunner": "jest-circus/runner"
}

@thernstig
Copy link
Contributor

@Rossh87 Hmm I was using jest-circus when I had this trouble, I am pretty certain. Maybe they fixed it. Can you confirm it works when a beforeEach() fails too?

@Rossh87
Copy link

Rossh87 commented Feb 10, 2021

@thernstig Beforeeach and beforeAll work how I would expect, at least in my testing environment. Here's the repo I was using--maybe see if it gives you the same results?

I dug through the commit history a bit looking for this specific change to jest-circus without finding anything conclusive, but I didn't spend a ton of effort on it.

@thernstig
Copy link
Contributor

thernstig commented Feb 11, 2021

@Rossh87 is right. This can/should be closed now. Using jest-circus it works fine, and that is what you should use anyway. For reference there is still problems with reporting if a beforeAll() fails, but that is a separate issue #6695 (especially this #6695 (comment)).

This is what I did to confirm that the scenario describe in this issue does bail if beforeAll() or beforeEach() fails in case of timeout:

Code

beforeAll( // or beforeEach
  async () =>
    new Promise((resolve, reject) => {
      // Never resolves
    })
);

test('case', async () => {
  console.log('should never be executed');
});

Failure with beforeAll()

FAIL   UNIT:SERVER  server/util/__tests__/test1.unit.test.js (6.838 s)
  ✕ casecase

    thrown: "Exceeded timeout of 5000 ms for a hook.
    Use jest.setTimeout(newTimeout) to increase the timeout value, if this is a long-running test."

      15 | // });
      16 | 
    > 17 | beforeAll(
         | ^
      18 |   async () =>
      19 |     new Promise((resolve, reject) => {
      20 |       // Never resolves

      at Object.<anonymous> (util/__tests__/test1.unit.test.js:17:1)

Test Suites: 1 failed, 1 total
Tests:       1 failed, 1 total
Snapshots:   0 total
Time:        6.868 s

Failure with beforeEach()

 FAIL   UNIT:SERVER  server/util/__tests__/test1.unit.test.js (6.831 s)
  ✕ case (5002 ms)

  ● case

    thrown: "Exceeded timeout of 5000 ms for a hook.
    Use jest.setTimeout(newTimeout) to increase the timeout value, if this is a long-running test."

      15 | // });
      16 | 
    > 17 | beforeEach(
         | ^
      18 |   async () =>
      19 |     new Promise((resolve, reject) => {
      20 |       // Never resolves

      at Object.<anonymous> (util/__tests__/test1.unit.test.js:17:1)

Test Suites: 1 failed, 1 total
Tests:       1 failed, 1 total
Snapshots:   0 total
Time:        6.859 s, estimated 7 s

@thernstig
Copy link
Contributor

@aalexgabi maybe you can close this?

@DanielHGimenez
Copy link

jest-circus

Doesn't work for me

@thernstig
Copy link
Contributor

jest-circus

Doesn't work for me

I think showing your code, a minimum repro would be nice since it seems to work for some of us.

@DanielHGimenez
Copy link

DanielHGimenez commented Apr 6, 2021

jest-circus

Doesn't work for me

I think showing your code, a minimum repro would be nice since it seems to work for some of us.

@thernstig

I'm using jest-cucumber to run my tests. In definition of feature, I call setup() method that will set beforeAll, beforeEach and afterEach callbacks. The beforeAll callback will execute startInTestMode method, which will get up the server application that will be used in tests. When I run the tests, things that should be defined in startInTestMode are not defined yet. When I debug de code, the beforeAll is executed after tests begins.

const feature = loadFeature(__dirname + '/../features/create_redirect_url.feature')

defineFeature(feature, test => {

    setup()

    test('Successfully create a url for new user', ({ given, when, then }) => {

        given('user is logged in', userIsLoggedIn())

        [...]
export default function setup() {
    beforeAll(async () => {
        await startInTestMode()    })
    beforeEach(async () => {
        await Cart.deleteMany({})
        nock.cleanAll()
    })
    afterAll(async () => {
        await MongoDbMock.stopDbMock()
    })
}

export async function startInTestMode() {
    DotenvConfig.configure()
    InversifyConfig.configure()
    ExpressConfig.configure()
    ApplicationConfig.configure()

    await MongoDbMock.initDbMock()
}

@thernstig
Copy link
Contributor

thernstig commented Apr 6, 2021

Sorry I thought you used plain jest with jest-circus, I have no idea how cucumber works and maybe it is related to that then? Maybe if you try with plain jest and jest-circus, you can instead then redirect your question to the cucumber repo. In addition I assume you are configuring jest-circus like explained here https://www.npmjs.com/package/jest-circus#configure

@DanielHGimenez
Copy link

I write an issue to the jest-cucumber repository. If someone is having the same problem with jest-cucumber there is the thread: bencompton/jest-cucumber#124

ansgarm added a commit to hashicorp/terraform-cdk that referenced this issue Apr 20, 2021
apparently jest does not wait for an async function to complete in BeforeAll hooks (see: jestjs/jest#9527). With the default timeout of 5 seconds this had the effect of our test cases being run without initialization to be complete. this was no issue prior as we used to use execSync which blocked the whole js main loop and thereby also blocked jest in running our test cases.

switched exec to spawn for some test-helper shell calls. this allows to capture all logs and can also allow to print them as they appear (line per line) which helped discover the cause of the jest related issue
@cchavezmx
Copy link

i change de mongoose version to: "mongoose": "5.13.5", and works!! 🤔

@thernstig
Copy link
Contributor

@SimenB I believe this can be closed, see #9527 (comment)

@thernstig
Copy link
Contributor

@SimenB this should be able to be closed, see my comment above.

@misterrodger
Copy link

Just FYI, this issue also may have to do with running an older version of Mongo, or that it's running slowly on your local machine.

If it's passing in CI, try upgrading and running Mongo with the Docker extension in VSCode to get your tests to pass locally.

@wanton7
Copy link

wanton7 commented Apr 22, 2022

Our company doesn't use Mongo. We use PostgreSQL and we where effected by this until we increased default test timeout about 3 months ago.

@337Gslime
Copy link

337Gslime commented Apr 22, 2022 via email

@vlovich
Copy link

vlovich commented Aug 2, 2022

We're seeing a related problem even with jest-circus (but maybe that's intentional, not sure). If beforeAll times out, then afterEach / afterAll get invoked. afterAll I could maybe see making some sense but running afterEach is weird.

Jest version 27.4.1 which uses jest-circus by default:

beforeAll(async () => {
    console.log('beforeAll start')
    await new Promise()
    console.log('beforeAll should not hit')
})

beforeEach(async () => {
    console.log('beforeEach start')
    await new Promise()
    console.log('beforeEach should not hit')
})

afterEach(() => {
    console.error('afterEach')
})

afterAll(() => {
    console.error('afterAll')
})

test('test', () => {
    console.error('test body')
})

prints

  console.log
    beforeAll start

      at test.js:2:13

  console.error
    afterEach

      12 |
      13 | afterEach(() => {
    > 14 |     console.error('afterEach')
         |             ^
      15 | })
      16 |
      17 | afterAll(() => {

      at Object.<anonymous> (test.js:14:13)

  console.error
    afterAll

      16 |
      17 | afterAll(() => {
    > 18 |     console.error('afterAll')
         |             ^
      19 | })
      20 |
      21 | test('test', () => {

      at test.js:18:13

 FAIL  ./test.js (5.517 s)
  ✕ test (23 ms)

  ● test

    thrown: "Exceeded timeout of 5000 ms for a hook.
    Use jest.setTimeout(newTimeout) to increase the timeout value, if this is a long-running test."

    > 1 | beforeAll(async () => {
        | ^
      2 |     console.log('beforeAll start')
      3 |     await new Promise((resolver) => {})
      4 |     console.log('beforeAll should not hit')

      at Object.<anonymous> (test.js:1:1)
      at TestScheduler.scheduleTests (node_modules/@jest/core/build/TestScheduler.js:333:13)
      at runJest (node_modules/@jest/core/build/runJest.js:404:19)

Test Suites: 1 failed, 1 total
Tests:       1 failed, 1 total
Snapshots:   0 total
Time:        5.579 s

A similar pattern occurs if beforeAll throws an exception (i.e. afterEach is still invoked).

I would posit that after methods running in the case of a timeout / exception in a before is a non-intuitive design choice that should at least have lots of warning signs about it in the docs. Ideally it's the user's responsibility to cleanup any resources if beforeEach fails. It's as simple as something like:

beforeEach((async () => {
}).catch((e) => {
   // cleanup indeterminate state
   if (resource1 !== undefined) {
      await resource1.shutdown()
   }
   throw e
}))

That way afterEach can be more of a happy path cleanup that doesn't have to account for cleaning up state because the matching before had a problem.

@earonesty
Copy link

earonesty commented Apr 28, 2023

beforeEach is fundamentally flawed. it should have a return value that returns isolated resources that are made available to tests as arguments. setting describe-scoped variables kills parallelization. as it stands, it forces serialization, or a million describe blocks, which need to roll their own fixture architecture

Copy link

This issue is stale because it has been open for 1 year with no activity. Remove stale label or comment or this will be closed in 30 days.

@github-actions github-actions bot added the Stale label Apr 27, 2024
@earonesty
Copy link

Stale or not, its still not ok

@github-actions github-actions bot removed the Stale label Apr 27, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

No branches or pull requests