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

Prevent false test failures caused by promise rejections handled asynchronously #14315

Merged
merged 6 commits into from
Sep 20, 2023

Conversation

stekycz
Copy link
Contributor

@stekycz stekycz commented Jul 10, 2023

This reverts commit 208f2f1.

Original PR #14110

Intended to be part of v30 release as discussed #14110 (comment)

@netlify
Copy link

netlify bot commented Jul 10, 2023

Deploy Preview for jestjs ready!

Built without sensitive environment variables

Name Link
🔨 Latest commit 2f7d8a2
🔍 Latest deploy log https://app.netlify.com/sites/jestjs/deploys/650afb29e88c9c00083c6f5e
😎 Deploy Preview https://deploy-preview-14315--jestjs.netlify.app
📱 Preview on mobile
Toggle QR Code...

QR Code

Use your smartphone camera to open QR code link.

To edit notification comments on pull requests, go to your Netlify site configuration.

Copy link
Member

@SimenB SimenB left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

hi again, @stekycz! could you resolve the conflict and add a changelog entry? 🙂

@stekycz stekycz force-pushed the stekycz-v30-false-positive-failures branch from 100d8ed to bf1bae4 Compare September 20, 2023 11:59
@stekycz
Copy link
Contributor Author

stekycz commented Sep 20, 2023

@SimenB Thanks for pinging me. I have just rebased the revert of the revert commit and added the changelog entry. Pls, let me know if there is anything else I can do.

Copy link
Member

@SimenB SimenB left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

thanks!

@SimenB SimenB enabled auto-merge (squash) September 20, 2023 13:25
@SimenB SimenB disabled auto-merge September 20, 2023 13:51
@SimenB
Copy link
Member

SimenB commented Sep 20, 2023

CI is unhappy here. Probably that the invariant helper has been moved to jest-util?

@stekycz
Copy link
Contributor Author

stekycz commented Sep 20, 2023

@SimenB I am looking into it

@stekycz stekycz requested a review from SimenB September 20, 2023 14:01
Copy link
Member

@SimenB SimenB left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

thanks!

@SimenB SimenB merged commit db42fe5 into jestjs:main Sep 20, 2023
60 checks passed
@stekycz stekycz deleted the stekycz-v30-false-positive-failures branch September 20, 2023 15:11
@SimenB
Copy link
Member

SimenB commented Sep 29, 2023

Hey @stekycz! I was looking into another issue, and found that this PR has a quite bad performance hit.

If you clone https://github.com/luiz290788/jest-node-16, you can see. db42fe5 is the merge commit of this PR.

git checkout db42fe50710280e8c1cb1d506349ddbecbb62cfa && yarn && node scripts/build.mjs

The tests in that reproduction run horribly slow. Easiest way to test with a local version of jest is just (from within that repo) node ../jest/packages/jest/bin/jest.js -i.

git checkout db42fe50710280e8c1cb1d506349ddbecbb62cfa~ && yarn && node scripts/build.mjs

And the tests are fine.

@SimenB
Copy link
Member

SimenB commented Oct 10, 2023

Ping @stekycz - I might have to revert this again unless we can get to the bottom of it 😬

@stekycz
Copy link
Contributor Author

stekycz commented Oct 11, 2023

@SimenB I am sorry, I have been off a few days and I finally got to this. I am not sure what exactly is causing the performance issue but I will try to find the root cause this week. Once I know what is causing it, the best solution would probably be hide this feature under a flag, similar to detectOpenHandles.

@SimenB
Copy link
Member

SimenB commented Oct 11, 2023

Sounds like a good plan, thanks @stekycz!

@stekycz
Copy link
Contributor Author

stekycz commented Oct 15, 2023

@SimenB I have spent some time investigating what and why is the slow part. Let me elaborate a bit below.

A) The element causing slow down is waiting for the next tick on the event loop. When I commented that code, it was back on times as on the commit before the merge of this PR. However, we cannot simply remove that as we would possibly fall into 2 issues - false positive and false negative.
- A test would pass if the unhandled promise is the last execution in the test (or hook). See the test for this scenario.
- A test would fail if the promise rejection handling is the last execution in the test (or hook). See the test for this scenario.

B) The repo you sent me is very artificial having 100k simple and fast tests. All of them are so fast that waiting for the next event loop after each test adds ~1-2ms (on my machine) to each test and it adds up given the amount of individual tests. Based on my experience, projects usually do not have so many tests and when they do, they are not all so fast. Therefore, for the most common usages the slow down would not be significant addition to the existing test execution duration IMO.

C) Another ~1-2ms (on my machine) is added to each test because of event loop awaiting after a hook execution. The example repo does not have any hook though. It brought me to a default beforeEach hook defined by Jest. I believe this hook can be registered when one of internal conditions would be satisfiable (or register a hook for each condition independently). However, that may be a good optimisation nevertheless.

Based on those findings I believe the case with 100k simple and fast tests can be considered an edge case. For majority of test code bases the slow down should be insignificant. If not, it can be addressed either now or even in a later version (giving us chance to test the feature sooner). I will leave that decision on you. However, fixing it now would not be a simple task IMO so reverting again would be the fastest option.

The slow down can be addressed by adding a (CLI) flag for the event loop awaiting. The documentation should mention then about caveats for edge cases I mentioned above in A). The flag can be implemented in 2 ways:

  1. Turned on by default, turn off when the slow down is NOT bearable for you.
  2. Turned off by default, turn on when you want to detect unhandled rejections in tests but the slow down is bearable for you.

I would prefer option 1) as it is safer for newbies. The option 2) is similar to --detectOpenHandles but open handles have an advantage they block the process to exit on its own (that makes an issue visible). Possibly unhandled rejection or handled properly is harder to debug when not detected by default.

Pls, let me know what you think about it. I can eventually add the flag for the feature based on your feedback. Thanks!

@SimenB
Copy link
Member

SimenB commented Oct 30, 2023

Just published https://github.com/jestjs/jest/releases/tag/v30.0.0-alpha.1 which includes this.


Thanks for the thorough analysis!

I think I prefer option 2 - people already have a perceived notion Jest is slow - adding micro-slowdowns all over won't help that narrative I'm afraid.

And when we have the flag, we can always flip the default later 🙂

@stekycz
Copy link
Contributor Author

stekycz commented Oct 31, 2023

Alright! Thanks for getting back to back to me. What is your runway to release the version 3.0.0 as stable? I will do my best to hide it under a flag in the following 2 weeks.

@stekycz
Copy link
Contributor Author

stekycz commented Nov 6, 2023

@SimenB I have just created PR adding a flag #14681 Pls, let's continue with the conversation there.

Copy link

github-actions bot commented Dec 7, 2023

This pull request 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.

@github-actions github-actions bot locked as resolved and limited conversation to collaborators Dec 7, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

2 participants