jestjs / jest

Delightful JavaScript Testing.
https://jestjs.io
MIT License
44.21k stars 6.46k forks source link

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

Open aalexgabi opened 4 years ago

aalexgabi commented 4 years ago

πŸ› 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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

@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 commented 4 years ago

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 commented 4 years ago

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 commented 4 years ago

Same with using beforeEach().

albert-schilling commented 4 years ago

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 commented 4 years ago

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 commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

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

hananmalka commented 3 years ago

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

wanton7 commented 3 years ago

@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 commented 3 years ago

@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 commented 3 years ago

@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.

Rossh87 commented 3 years ago

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 commented 3 years ago

@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 commented 3 years ago

@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 commented 3 years ago

@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 https://github.com/facebook/jest/issues/6695 (especially this https://github.com/facebook/jest/issues/6695#issuecomment-489536977).

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)
  βœ• case

  ● 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 | 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 commented 3 years ago

@aalexgabi maybe you can close this?

DanielHGimenez commented 3 years ago

jest-circus

Doesn't work for me

thernstig commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

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 commented 3 years ago

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

cchavezmx commented 2 years ago

i change de mongoose version to: "mongoose": "5.13.5", and works!! πŸ€”

thernstig commented 2 years ago

@SimenB I believe this can be closed, see https://github.com/facebook/jest/issues/9527#issuecomment-777489217

thernstig commented 2 years ago

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

misterrodger commented 2 years ago

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 commented 2 years ago

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 commented 2 years ago

I'm getting tired of all this shit I'ma just start doin shit anyway kind of way

On Fri, 22 Apr 2022, 2:27 am wanton7, @.***> wrote:

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

β€” Reply to this email directly, view it on GitHub https://github.com/facebook/jest/issues/9527#issuecomment-1106237725, or unsubscribe https://github.com/notifications/unsubscribe-auth/AXSL3Z5P7VW6SAUHCAOPGYLVGJWGJANCNFSM4KQ5YSXQ . You are receiving this because you are subscribed to this thread.Message ID: @.***>

vlovich commented 2 years ago

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 commented 1 year ago

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

github-actions[bot] commented 5 months ago

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.

earonesty commented 5 months ago

Stale or not, its still not ok