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

Asynchronous operations not stopped in tests? #7817

Closed
oleersoy opened this issue Feb 6, 2019 · 5 comments
Closed

Asynchronous operations not stopped in tests? #7817

oleersoy opened this issue Feb 6, 2019 · 5 comments

Comments

@oleersoy
Copy link

oleersoy commented Feb 6, 2019

🐛 Bug Report

When running npm t on this repository I sometimes get the message Timeout - Async callback was not invoked within the 5000ms timeout specified by jest.setTimeout.. The first time this happened I played around with only on some of the tests, and did not change any code, and all of a sudden it started working ... so life was good. Now it's happening again, and it's also random.

To Reproduce

git clone git@github.com:superflycss/cli.git
cd cli
npm t

In order to see what's going on I tried running only this test:

describe("The build command", () => {
  it.only("should build main, test css and html files", async () => {
    const sandbox = tmp();
    let result = await cli(["new",  "-t", "e", sandbox], ".");
    const red = fixtures.css();
    const redPath = path.join(sandbox, PLI.src.main.css,'index.css');

    fs.writeFileSync(redPath, red);

    result = await cli(["b"], sandbox);
    expect(result.code).toBe(0);
    expect(result.stdout).toContain("build");
    del.sync(SANDBOX);
  });

The first time I tried this I was still getting an error message and it said to try adding --detectOpenHandles. So I added that, and now the test passes. I did not change the code at all. I included the complete console log of this below:

ole@mki:~/SuperflyCSS/cli$ npm t

> @superflycss/cli@4.1.6 test /home/ole/SuperflyCSS/cli
> jest

 FAIL  ./index.spec.js (6.341s)
  The new command
    ○ skipped 4 tests
  The build command
    ✕ should build main, test css and html files (5075ms)
    ○ skipped 1 test
  The build:main:css command
    ○ skipped 1 test
  The build:test:css command
    ○ skipped 1 test
  The build:test:html command
    ○ skipped 1 test
  The build:main:html command
    ○ skipped 1 test
  The build:main:filtered:css command
    ○ skipped 1 test
  The build:test:filtered:css command
    ○ skipped 1 test
  The build:main:minified:css command
    ○ skipped 1 test
  The build:test:minified:css command
    ○ skipped 1 test

  ● The build command › should build main, test css and html files

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

      53 | 
      54 | describe("The build command", () => {
    > 55 |   it.only("should build main, test css and html files", async () => {
         |      ^
      56 |     const sandbox = tmp();
      57 |     let result = await cli(["new",  "-t", "e", sandbox], ".");
      58 |     const red = fixtures.css();

      at Spec (node_modules/jest-jasmine2/build/jasmine/Spec.js:85:20)
      at Suite.only (index.spec.js:55:6)
      at Object.describe (index.spec.js:54:1)

Test Suites: 1 failed, 1 total
Tests:       1 failed, 13 skipped, 14 total
Snapshots:   0 total
Time:        8.209s
Ran all test suites.
Jest did not exit one second after the test run has completed.

This usually means that there are asynchronous operations that weren't stopped in your tests. Consider running Jest with `--detectOpenHandles` to troubleshoot this issue.
npm ERR! Test failed.  See above for more details.
ole@mki:~/SuperflyCSS/cli$ jest --detectOpenHandles

Command 'jest' not found, did you mean:

  command 'test' from deb coreutils

Try: sudo apt install <deb name>

ole@mki:~/SuperflyCSS/cli$ npm t

> @superflycss/cli@4.1.6 test /home/ole/SuperflyCSS/cli
> jest --detectOpenHandles

 PASS  ./index.spec.js
  The new command
    ○ skipped 4 tests
  The build command
    ✓ should build main, test css and html files (3001ms)
    ○ skipped 1 test
  The build:main:css command
    ○ skipped 1 test
  The build:test:css command
    ○ skipped 1 test
  The build:test:html command
    ○ skipped 1 test
  The build:main:html command
    ○ skipped 1 test
  The build:main:filtered:css command
    ○ skipped 1 test
  The build:test:filtered:css command
    ○ skipped 1 test
  The build:main:minified:css command
    ○ skipped 1 test
  The build:test:minified:css command
    ○ skipped 1 test

Test Suites: 1 passed, 1 total
Tests:       13 skipped, 1 passed, 14 total
Snapshots:   0 total
Time:        4.337s, estimated 7s
Ran all test suites.
ole@mki:~/SuperflyCSS/cli$ 

Expected behavior

All the tests should pass.

@oleersoy
Copy link
Author

oleersoy commented Feb 6, 2019

This is another example. I changed to a simpler test and flagged it with only. Then I ran npm t and the test passed and no errors on the console. I repeated it without making any other changes, and Jest logged an error:

> @superflycss/cli@4.1.6 test /home/ole/SuperflyCSS/cli
> jest --detectOpenHandles

 PASS  ./index.spec.js
  The new command
    ✓ should create a prototype project by default (1175ms)
    ○ skipped 3 tests
  The build command
    ○ skipped 2 tests
  The build:main:md command
    ○ skipped 1 test
  The build:test:md command
    ○ skipped 1 test
  The build:main:css command
    ○ skipped 1 test
  The build:test:css command
    ○ skipped 1 test
  The build:test:html command
    ○ skipped 1 test
  The build:main:html command
    ○ skipped 1 test
  The build:main:filtered:css command
    ○ skipped 1 test
  The build:test:filtered:css command
    ○ skipped 1 test
  The build:main:minified:css command
    ○ skipped 1 test
  The build:test:minified:css command
    ○ skipped 1 test

Test Suites: 1 passed, 1 total
Tests:       15 skipped, 1 passed, 16 total
Snapshots:   0 total
Time:        1.913s, estimated 2s
Ran all test suites.
ole@mki:~/SuperflyCSS/cli$ npm t

> @superflycss/cli@4.1.6 test /home/ole/SuperflyCSS/cli
> jest --detectOpenHandles

 PASS  ./index.spec.js
  The new command
    ✓ should create a prototype project by default (1227ms)
    ○ skipped 3 tests
  The build command
    ○ skipped 2 tests
  The build:main:md command
    ○ skipped 1 test
  The build:test:md command
    ○ skipped 1 test
  The build:main:css command
    ○ skipped 1 test
  The build:test:css command
    ○ skipped 1 test
  The build:test:html command
    ○ skipped 1 test
  The build:main:html command
    ○ skipped 1 test
  The build:main:filtered:css command
    ○ skipped 1 test
  The build:test:filtered:css command
    ○ skipped 1 test
  The build:main:minified:css command
    ○ skipped 1 test
  The build:test:minified:css command
    ○ skipped 1 test

Test Suites: 1 passed, 1 total
Tests:       15 skipped, 1 passed, 16 total
Snapshots:   0 total
Time:        1.955s, estimated 2s
Ran all test suites.

Jest has detected the following 1 open handle potentially keeping Jest from exiting:

  ●  PROCESSWRAP

      256 | function cli(args, cwd) {
      257 |   return new Promise(resolve => {
    > 258 |     exec(
          |     ^
      259 |       `node ${path.resolve("./index")} ${args.join(" ")}`,
      260 |       { cwd },
      261 |       (error, stdout, stderr) => {

      at exec (index.spec.js:258:5)
      at cli (index.spec.js:257:10)
      at Object.cli (index.spec.js:14:24)

@oleersoy
Copy link
Author

oleersoy commented Feb 8, 2019

It seems like it's probably related to how Jest times reporting the open handle stuff. For example I just ran npm t several time in a row and as can be seen sometimes Jest reports an error and sometimes the test just runs fine:

ole@mki:~/SuperflyCSS/cli$ npm t

> @superflycss/cli@4.1.6 test /home/ole/SuperflyCSS/cli
> jest --detectOpenHandles

 PASS  ./index.spec.js
  The new command
    ✓ should create a prototype project by default (1544ms)
    ○ skipped 3 tests
  The build command
    ○ skipped 2 tests
  The build:main:md command
    ○ skipped 1 test
  The build:test:md command
    ○ skipped 1 test
  The build:main:css command
    ○ skipped 1 test
  The build:test:css command
    ○ skipped 1 test
  The build:test:html command
    ○ skipped 1 test
  The build:main:html command
    ○ skipped 1 test
  The build:main:filtered:css command
    ○ skipped 1 test
  The build:test:filtered:css command
    ○ skipped 1 test
  The build:main:minified:css command
    ○ skipped 1 test
  The build:test:minified:css command
    ○ skipped 1 test

Test Suites: 1 passed, 1 total
Tests:       15 skipped, 1 passed, 16 total
Snapshots:   0 total
Time:        2.398s
Ran all test suites.

Jest has detected the following 1 open handle potentially keeping Jest from exiting:

  ●  PROCESSWRAP

      256 | function cli(args, cwd) {
      257 |   return new Promise(resolve => {
    > 258 |     exec(
          |     ^
      259 |       `node ${path.resolve("./index")} ${args.join(" ")}`,
      260 |       { cwd },
      261 |       (error, stdout, stderr) => {

      at exec (index.spec.js:258:5)
      at cli (index.spec.js:257:10)
      at Object.cli (index.spec.js:14:24)

ole@mki:~/SuperflyCSS/cli$ npm t

> @superflycss/cli@4.1.6 test /home/ole/SuperflyCSS/cli
> jest --detectOpenHandles

 PASS  ./index.spec.js
  The new command
    ✓ should create a prototype project by default (1254ms)
    ○ skipped 3 tests
  The build command
    ○ skipped 2 tests
  The build:main:md command
    ○ skipped 1 test
  The build:test:md command
    ○ skipped 1 test
  The build:main:css command
    ○ skipped 1 test
  The build:test:css command
    ○ skipped 1 test
  The build:test:html command
    ○ skipped 1 test
  The build:main:html command
    ○ skipped 1 test
  The build:main:filtered:css command
    ○ skipped 1 test
  The build:test:filtered:css command
    ○ skipped 1 test
  The build:main:minified:css command
    ○ skipped 1 test
  The build:test:minified:css command
    ○ skipped 1 test

Test Suites: 1 passed, 1 total
Tests:       15 skipped, 1 passed, 16 total
Snapshots:   0 total
Time:        2.029s
Ran all test suites.
ole@mki:~/SuperflyCSS/cli$ npm t

> @superflycss/cli@4.1.6 test /home/ole/SuperflyCSS/cli
> jest --detectOpenHandles

jest-haste-map: @providesModule naming collision:
  Duplicate module name: prototype project
  Paths: /home/ole/SuperflyCSS/cli/test/sandbox/700b4405-8311-4573-b915-8aacd868ca59/package.json collides with /home/ole/SuperflyCSS/cli/test/sandbox/2becebee-c2b8-44d5-b0e9-dc707504d5bd/package.json

This warning is caused by a @providesModule declaration with the same name across two different files.
 PASS  ./index.spec.js
  The new command
    ✓ should create a prototype project by default (1241ms)
    ○ skipped 3 tests
  The build command
    ○ skipped 2 tests
  The build:main:md command
    ○ skipped 1 test
  The build:test:md command
    ○ skipped 1 test
  The build:main:css command
    ○ skipped 1 test
  The build:test:css command
    ○ skipped 1 test
  The build:test:html command
    ○ skipped 1 test
  The build:main:html command
    ○ skipped 1 test
  The build:main:filtered:css command
    ○ skipped 1 test
  The build:test:filtered:css command
    ○ skipped 1 test
  The build:main:minified:css command
    ○ skipped 1 test
  The build:test:minified:css command
    ○ skipped 1 test

Test Suites: 1 passed, 1 total
Tests:       15 skipped, 1 passed, 16 total
Snapshots:   0 total
Time:        2.015s
Ran all test suites.
ole@mki:~/SuperflyCSS/cli$ npm t

> @superflycss/cli@4.1.6 test /home/ole/SuperflyCSS/cli
> jest --detectOpenHandles

 PASS  ./index.spec.js
  The new command
    ✓ should create a prototype project by default (1258ms)
    ○ skipped 3 tests
  The build command
    ○ skipped 2 tests
  The build:main:md command
    ○ skipped 1 test
  The build:test:md command
    ○ skipped 1 test
  The build:main:css command
    ○ skipped 1 test
  The build:test:css command
    ○ skipped 1 test
  The build:test:html command
    ○ skipped 1 test
  The build:main:html command
    ○ skipped 1 test
  The build:main:filtered:css command
    ○ skipped 1 test
  The build:test:filtered:css command
    ○ skipped 1 test
  The build:main:minified:css command
    ○ skipped 1 test
  The build:test:minified:css command
    ○ skipped 1 test

Test Suites: 1 passed, 1 total
Tests:       15 skipped, 1 passed, 16 total
Snapshots:   0 total
Time:        2.038s
Ran all test suites.

Jest has detected the following 1 open handle potentially keeping Jest from exiting:

  ●  PROCESSWRAP

      256 | function cli(args, cwd) {
      257 |   return new Promise(resolve => {
    > 258 |     exec(
          |     ^
      259 |       `node ${path.resolve("./index")} ${args.join(" ")}`,
      260 |       { cwd },
      261 |       (error, stdout, stderr) => {

      at exec (index.spec.js:258:5)
      at cli (index.spec.js:257:10)
      at Object.cli (index.spec.js:14:24)

ole@mki:~/SuperflyCSS/cli$ npm t

> @superflycss/cli@4.1.6 test /home/ole/SuperflyCSS/cli
> jest --detectOpenHandles

 PASS  ./index.spec.js
  The new command
    ✓ should create a prototype project by default (1256ms)
    ○ skipped 3 tests
  The build command
    ○ skipped 2 tests
  The build:main:md command
    ○ skipped 1 test
  The build:test:md command
    ○ skipped 1 test
  The build:main:css command
    ○ skipped 1 test
  The build:test:css command
    ○ skipped 1 test
  The build:test:html command
    ○ skipped 1 test
  The build:main:html command
    ○ skipped 1 test
  The build:main:filtered:css command
    ○ skipped 1 test
  The build:test:filtered:css command
    ○ skipped 1 test
  The build:main:minified:css command
    ○ skipped 1 test
  The build:test:minified:css command
    ○ skipped 1 test

Test Suites: 1 passed, 1 total
Tests:       15 skipped, 1 passed, 16 total
Snapshots:   0 total
Time:        2.033s
Ran all test suites.

Jest has detected the following 1 open handle potentially keeping Jest from exiting:

  ●  PROCESSWRAP

      256 | function cli(args, cwd) {
      257 |   return new Promise(resolve => {
    > 258 |     exec(
          |     ^
      259 |       `node ${path.resolve("./index")} ${args.join(" ")}`,
      260 |       { cwd },
      261 |       (error, stdout, stderr) => {

      at exec (index.spec.js:258:5)
      at cli (index.spec.js:257:10)
      at Object.cli (index.spec.js:14:24)

ole@mki:~/SuperflyCSS/cli$ npm t

> @superflycss/cli@4.1.6 test /home/ole/SuperflyCSS/cli
> jest --detectOpenHandles

 PASS  ./index.spec.js
  The new command
    ✓ should create a prototype project by default (1266ms)
    ○ skipped 3 tests
  The build command
    ○ skipped 2 tests
  The build:main:md command
    ○ skipped 1 test
  The build:test:md command
    ○ skipped 1 test
  The build:main:css command
    ○ skipped 1 test
  The build:test:css command
    ○ skipped 1 test
  The build:test:html command
    ○ skipped 1 test
  The build:main:html command
    ○ skipped 1 test
  The build:main:filtered:css command
    ○ skipped 1 test
  The build:test:filtered:css command
    ○ skipped 1 test
  The build:main:minified:css command
    ○ skipped 1 test
  The build:test:minified:css command
    ○ skipped 1 test

Test Suites: 1 passed, 1 total
Tests:       15 skipped, 1 passed, 16 total
Snapshots:   0 total
Time:        2.049s
Ran all test suites.
ole@mki:~/SuperflyCSS/cli$ npm t

> @superflycss/cli@4.1.6 test /home/ole/SuperflyCSS/cli
> jest --detectOpenHandles

 PASS  ./index.spec.js
  The new command
    ✓ should create a prototype project by default (1236ms)
    ○ skipped 3 tests
  The build command
    ○ skipped 2 tests
  The build:main:md command
    ○ skipped 1 test
  The build:test:md command
    ○ skipped 1 test
  The build:main:css command
    ○ skipped 1 test
  The build:test:css command
    ○ skipped 1 test
  The build:test:html command
    ○ skipped 1 test
  The build:main:html command
    ○ skipped 1 test
  The build:main:filtered:css command
    ○ skipped 1 test
  The build:test:filtered:css command
    ○ skipped 1 test
  The build:main:minified:css command
    ○ skipped 1 test
  The build:test:minified:css command
    ○ skipped 1 test

Test Suites: 1 passed, 1 total
Tests:       15 skipped, 1 passed, 16 total
Snapshots:   0 total
Time:        2.004s
Ran all test suites.

Jest has detected the following 1 open handle potentially keeping Jest from exiting:

  ●  PROCESSWRAP

      256 | function cli(args, cwd) {
      257 |   return new Promise(resolve => {
    > 258 |     exec(
          |     ^
      259 |       `node ${path.resolve("./index")} ${args.join(" ")}`,
      260 |       { cwd },
      261 |       (error, stdout, stderr) => {

      at exec (index.spec.js:258:5)
      at cli (index.spec.js:257:10)
      at Object.cli (index.spec.js:14:24)

ole@mki:~/SuperflyCSS/cli$ npm t

> @superflycss/cli@4.1.6 test /home/ole/SuperflyCSS/cli
> jest --detectOpenHandles

 PASS  ./index.spec.js
  The new command
    ✓ should create a prototype project by default (1256ms)
    ○ skipped 3 tests
  The build command
    ○ skipped 2 tests
  The build:main:md command
    ○ skipped 1 test
  The build:test:md command
    ○ skipped 1 test
  The build:main:css command
    ○ skipped 1 test
  The build:test:css command
    ○ skipped 1 test
  The build:test:html command
    ○ skipped 1 test
  The build:main:html command
    ○ skipped 1 test
  The build:main:filtered:css command
    ○ skipped 1 test
  The build:test:filtered:css command
    ○ skipped 1 test
  The build:main:minified:css command
    ○ skipped 1 test
  The build:test:minified:css command
    ○ skipped 1 test

Test Suites: 1 passed, 1 total
Tests:       15 skipped, 1 passed, 16 total
Snapshots:   0 total
Time:        2.034s
Ran all test suites.

Jest has detected the following 1 open handle potentially keeping Jest from exiting:

  ●  PROCESSWRAP

      256 | function cli(args, cwd) {
      257 |   return new Promise(resolve => {
    > 258 |     exec(
          |     ^
      259 |       `node ${path.resolve("./index")} ${args.join(" ")}`,
      260 |       { cwd },
      261 |       (error, stdout, stderr) => {

      at exec (index.spec.js:258:5)
      at cli (index.spec.js:257:10)
      at Object.cli (index.spec.js:14:24)

ole@mki:~/SuperflyCSS/cli$ npm t

> @superflycss/cli@4.1.6 test /home/ole/SuperflyCSS/cli
> jest --detectOpenHandles

 PASS  ./index.spec.js
  The new command
    ✓ should create a prototype project by default (1240ms)
    ○ skipped 3 tests
  The build command
    ○ skipped 2 tests
  The build:main:md command
    ○ skipped 1 test
  The build:test:md command
    ○ skipped 1 test
  The build:main:css command
    ○ skipped 1 test
  The build:test:css command
    ○ skipped 1 test
  The build:test:html command
    ○ skipped 1 test
  The build:main:html command
    ○ skipped 1 test
  The build:main:filtered:css command
    ○ skipped 1 test
  The build:test:filtered:css command
    ○ skipped 1 test
  The build:main:minified:css command
    ○ skipped 1 test
  The build:test:minified:css command
    ○ skipped 1 test

Test Suites: 1 passed, 1 total
Tests:       15 skipped, 1 passed, 16 total
Snapshots:   0 total
Time:        2.012s
Ran all test suites.
ole@mki:~/SuperflyCSS/cli$ 


@github-actions
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 14 days.

@github-actions github-actions bot added the Stale label Feb 25, 2022
@github-actions
Copy link

This issue was closed because it has been stalled for 7 days with no activity. Please open a new issue if the issue is still relevant, linking to this one.

@github-actions
Copy link

github-actions bot commented May 2, 2022

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.

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

No branches or pull requests

1 participant