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

[BUG] Performance degradation when setTimeout / setImmediate is not used in parent test #1017

Open
3 tasks done
inga-lovinde opened this issue Apr 16, 2024 · 0 comments
Open
3 tasks done
Labels
bug something not go good

Comments

@inga-lovinde
Copy link

inga-lovinde commented Apr 16, 2024

Is there an existing issue for this?

  • I have searched the existing issues

Have you read the CONTRIBUTING guide on posting bugs, and CODE_OF_CONDUCT?

  • yes I read the things

This issue exists in the latest tap version

  • I am using the latest tap

Description

When a lot of small CPU-bound async tests are run, tap is really slow (20+ seconds for 3k simple assertions).

Adding a single await for next tick in the beginning of the parent test improves performance by an order of magnitude.

I would expect tests to take similar (small) amount of time regardless of whether there is an await in the beginning or not.

Reproduction

With latest tap and default tap settings, and the following perf.spec.ts file:

import t from "tap";

const waitForTick = () => new Promise(resolve => setImmediate(resolve));

t.test("Checking performance", async (t) => {
  await waitForTick();
  for (let j = 0; j < 3_000; j++) {
    const a = j;
    t.test(`Checking for ${j}`, async (t) => {
      t.equal(a * 2, a + a);
    });
  }
});

tap finishes in reasonable time:

> yarn spec
yarn run v1.22.19
$ tap run --disable-coverage "src/**/*.spec.ts"
 PASS  src/perf.spec.ts 3000 OK 3.802s


  🌈 TEST COMPLETE 🌈


Asserts:  3000 pass  0 fail  3000 of 3000 complete
Suites:      1 pass  0 fail        1 of 1 complete

# No coverage generated
# { total: 3000, pass: 3000 }
# time=3854.952ms

Done in 4.39s.

> yarn spec --reporter=silent
yarn run v1.22.19
$ tap run --disable-coverage "src/**/*.spec.ts"
Done in 3.19s.

However, if I comment out await waitForTick();, tap takes much much longer:

> yarn spec
yarn run v1.22.19
$ tap run --disable-coverage "src/**/*.spec.ts"
 PASS  src/perf.spec.ts 3000 OK 22s


  🌈 TEST COMPLETE 🌈


Asserts:  3000 pass  0 fail  3000 of 3000 complete
Suites:      1 pass  0 fail        1 of 1 complete

# No coverage generated
# { total: 3000, pass: 3000 }
# time=22063.745ms

Done in 22.60s.

> yarn spec --reporter=silent
yarn run v1.22.19
$ tap run --disable-coverage "src/**/*.spec.ts"
Done in 22.34s.

While it's running, most of the time CPU load is high, and the screen looks like this:

 RUNS  src/perf.spec.ts 0 OK 18s

Asserts:  0 pass  0 fail  0 of 0 complete
Suites:   0 pass  0 fail  0 of 0 complete

Environment

> which tap
> yarn list tap
yarn list v1.22.19                                                                                                   
warning Filtering by arguments is deprecated. Please use the pattern option instead.                                 
└─ tap@18.7.2
Done in 0.72s.                                                                                                       
> yarn run tap versions
yarn run v1.22.19                                                                                                    
$ [PROJECT_DIRECTORY]/node_modules/.bin/tap versions                                       
tap: 18.7.2
"@tapjs/config": 2.4.17
"@tapjs/core": 1.5.2
"@tapjs/run": 1.5.2
"@tapjs/stack": 1.2.8
"@tapjs/test": 1.4.2
tap-parser: 15.3.2
tap-yaml: 2.2.2
tcompare: 6.4.6
plugins:
  "@tapjs/after": 1.1.20
  "@tapjs/after-each": 1.1.20
  "@tapjs/asserts": 1.1.20
  "@tapjs/before": 1.1.20
  "@tapjs/before-each": 1.1.20
  "@tapjs/filter": 1.2.20
  "@tapjs/fixture": 1.2.20
  "@tapjs/intercept": 1.2.20
  "@tapjs/mock": 1.3.2
  "@tapjs/node-serialize": 1.3.2
  "@tapjs/snapshot": 1.2.20
  "@tapjs/spawn": 1.1.20
  "@tapjs/stdin": 1.1.20
  "@tapjs/typescript": 1.4.2
  "@tapjs/worker": 1.1.20
Done in 0.31s.                                                                                                       
> yarn tap config list
yarn run v1.22.19                                                                                                    
$ [PROJECT_DIRECTORY]/node_modules/.bin/tap config list                                    
# vim: set filetype=yaml :
color: false
coverage-report:
  - text
exclude:
  - "**/@(fixture*(s)|dist)/**"
include:
  - "**/@(test?(s)|__test?(s)__)/**/*.@(js|cjs|mjs|tap|cts|jsx|mts|ts|tsx)"
  - "**/*.@(test?(s)|spec).@(js|cjs|mjs|tap|cts|jsx|mts|ts|tsx)"
  - "**/test?(s).@(js|cjs|mjs|tap|cts|jsx|mts|ts|tsx)"
jobs: 12
reporter: tap
snapshot-clean-cwd: true
timeout: 30
Done in 0.32s.                                                                                                       
> yarn tap plugin list
yarn run v1.22.19                                                                                                    
$ [PROJECT_DIRECTORY]/node_modules/.bin/tap plugin list                                    
node:internal/process/esm_loader:97
    internalBinding('errors').triggerUncaughtException(
                              ^

[Error: Cannot find package '@tapjs/core' imported from [PROJECT_DIRECTORY]/x] {
  code: 'ERR_MODULE_NOT_FOUND'
}
error Command failed with exit code 1.                                                                               
info Visit https://yarnpkg.com/en/docs/cli/run for documentation about this command.                                 
> yarn list @isaacs/ts-node-temp-fork-for-pr-2009
yarn list v1.22.19                                                                                                   
warning Filtering by arguments is deprecated. Please use the pattern option instead.                                 
└─ tap@18.7.2
   └─ @isaacs/ts-node-temp-fork-for-pr-2009@10.9.5
Done in 0.70s.                                                                                                       
> yarn list typescript
yarn list v1.22.19                                                                                                   
warning Filtering by arguments is deprecated. Please use the pattern option instead.                                 
├─ tap@18.7.2
│  ├─ tshy@1.14.0
│  │  └─ typescript@5.4.5
│  └─ typescript@5.2.2
└─ typescript@5.4.2
Done in 0.76s.                                                                                                       
> uname -a
Linux [MACHINE_NAME] 6.6.24-0-lts #1-Alpine SMP PREEMPT_DYNAMIC Thu, 04 Apr 2024 12:08:14 +0000 x86_64 Linux
@inga-lovinde inga-lovinde added the bug something not go good label Apr 16, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug something not go good
Projects
None yet
Development

No branches or pull requests

1 participant