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

Failing tests slow down all following tests, even in headless mode #6881

Open
badeball opened this issue Mar 30, 2020 · 4 comments
Open

Failing tests slow down all following tests, even in headless mode #6881

badeball opened this issue Mar 30, 2020 · 4 comments
Labels
type: performance 🏃‍♀️ Performance related type: regression A bug that didn't appear until a specific Cy version release v3.8.0 🐛 Issue present since 3.8.0

Comments

@badeball
Copy link
Contributor

badeball commented Mar 30, 2020

Current behavior:

Failing tests consisting of a lot of steps slows down all consecutive tests considerably. For a failing test, the command log for said test will remain open. It consists of quite a lot of markup. Coupled together with the fact that Cypress forces reflow of layout everytime it determines visibility, etc., this absolutely thrashes performance. This problem is present in 3.7.0 and below, but got significantly worse in 3.8.0.

Additionally, the general feel of the interactive UI with a high amount of command logs, is just terrible in terms of responsiveness. Simply hovering over elements is slugish to an unbearable point.

A little background information

During our development, a regression making 6 of 41 tests fail was introduced, as shown below.

   Running: <redacted>                                 ...                                (43 of 53) 

   <redacted><redacted> (7016ms)
     ✓ <redacted> (5037ms)
     ✓ <redacted> (4746ms)
     ✓ <redacted> (4686ms)
     ✓ <redacted> (4629ms)
     ✓ <redacted> (5375ms)
     ✓ <redacted> (4693ms)
     ✓ <redacted> (7231ms)
     ✓ <redacted> (3719ms)
     ✓ <redacted> (5266ms)
     ✓ <redacted> (7956ms)
     ✓ <redacted> (9075ms)
     ✓ <redacted> (9252ms)
     ✓ <redacted> (3661ms)
     ✓ <redacted> (4086ms)
     1) <redacted>
     2) <redacted>
     3) <redacted>
     4) <redacted>
     5) <redacted>
     6) <redacted><redacted> (4870ms)
     ✓ <redacted> (6504ms)
     ✓ <redacted> (4824ms)
     ✓ <redacted> (6617ms)
     ✓ <redacted> (5433ms)
     ✓ <redacted> (9013ms)
     ✓ <redacted> (9274ms)
     ✓ <redacted> (4432ms)
     ✓ <redacted> (4608ms)
     ✓ <redacted> (4712ms)
     ✓ <redacted> (4511ms)
     ✓ <redacted> (8251ms)
     ✓ <redacted> (8541ms)
     ✓ <redacted> (8472ms)
     ✓ <redacted> (8693ms)
     ✓ <redacted> (8873ms)
     ✓ <redacted> (12172ms)
     ✓ <redacted> (8675ms)
     ✓ <redacted> (8626ms)
     ✓ <redacted> (8438ms)

   35 passing (7m)
   6 failing

Parallel with this, we upgraded to cypress-4.1.0 and observed something unfortunate, shown below. As one can see, the execution time of tests following the failing tests, increased considerable.

   Running:  <redacted>                                                                    (44 of 54)

   <redacted><redacted> (9567ms)
     ✓ <redacted> (6955ms)
     ✓ <redacted> (6910ms)
     ✓ <redacted> (7023ms)
     ✓ <redacted> (6756ms)
     ✓ <redacted> (7955ms)
     ✓ <redacted> (6096ms)
     ✓ <redacted> (11265ms)
     ✓ <redacted> (4629ms)
     ✓ <redacted> (7926ms)
     ✓ <redacted> (12803ms)
     ✓ <redacted> (15681ms)
     ✓ <redacted> (16625ms)
     ✓ <redacted> (4489ms)
     ✓ <redacted> (5044ms)
     1) <redacted>
     2) <redacted>
     3) <redacted>
     4) <redacted>
     5) <redacted>
     6) <redacted><redacted> (21714ms)
     ✓ <redacted> (35442ms)
     ✓ <redacted> (23371ms)
     ✓ <redacted> (33974ms)
     ✓ <redacted> (23397ms)
     ✓ <redacted> (49464ms)
     ✓ <redacted> (51058ms)
     ✓ <redacted> (22014ms)
     ✓ <redacted> (23502ms)
     ✓ <redacted> (25381ms)
     ✓ <redacted> (24161ms)
     ✓ <redacted> (52178ms)
     ✓ <redacted> (49096ms)
     ✓ <redacted> (51023ms)
     ✓ <redacted> (51839ms)
     ✓ <redacted> (50230ms)
     ✓ <redacted> (48274ms)
     ✓ <redacted> (46821ms)
     ✓ <redacted> (47702ms)
     ✓ <redacted> (45066ms)

   35 passing (20m)
   6 failing

We tried re-arranging the tests and moved the failing tests to the end and the effect diminished.

   Running:  <redacted>                                                                      (1 of 1)

   <redacted><redacted> (10593ms)
     ✓ <redacted> (6916ms)
     ✓ <redacted> (6338ms)
     ✓ <redacted> (6246ms)
     ✓ <redacted> (6137ms)
     ✓ <redacted> (7078ms)
     ✓ <redacted> (5671ms)
     ✓ <redacted> (10339ms)
     ✓ <redacted> (4087ms)
     ✓ <redacted> (6529ms)
     ✓ <redacted> (11301ms)
     ✓ <redacted> (13544ms)
     ✓ <redacted> (14227ms)
     ✓ <redacted> (4072ms)
     ✓ <redacted> (5305ms)
     ✓ <redacted> (5020ms)
     ✓ <redacted> (6854ms)
     ✓ <redacted> (4815ms)
     ✓ <redacted> (7030ms)
     ✓ <redacted> (5385ms)
     ✓ <redacted> (10327ms)
     ✓ <redacted> (10822ms)
     ✓ <redacted> (4456ms)
     ✓ <redacted> (4293ms)
     ✓ <redacted> (4730ms)
     ✓ <redacted> (4513ms)
     ✓ <redacted> (9982ms)
     ✓ <redacted> (9725ms)
     ✓ <redacted> (10105ms)
     ✓ <redacted> (10149ms)
     ✓ <redacted> (10121ms)
     ✓ <redacted> (10870ms)
     ✓ <redacted> (10586ms)
     ✓ <redacted> (10314ms)
     ✓ <redacted> (9570ms)
     1) <redacted>
     2) <redacted>
     3) <redacted>
     4) <redacted>
     5) <redacted>
     6) <redacted>

   35 passing (9m)
   6 failing

We then moved the failing tests to the beginning and the effect increased.

   Running:  <redacted>                                                                      (1 of 1)

   <redacted>

     1) <redacted>
     2) <redacted>
     3) <redacted>
     4) <redacted>
     5) <redacted>
     6) <redacted><redacted> (41532ms)
     ✓ <redacted> (36657ms)
     ✓ <redacted> (36386ms)
     ✓ <redacted> (35610ms)
     ✓ <redacted> (33402ms)
     ✓ <redacted> (38492ms)
     ✓ <redacted> (30358ms)
     ✓ <redacted> (52543ms)
     ✓ <redacted> (21940ms)
     ✓ <redacted> (35505ms)
     ✓ <redacted> (57207ms)
     ✓ <redacted> (68097ms)
     ✓ <redacted> (73801ms)
     ✓ <redacted> (20574ms)
     ✓ <redacted> (26460ms)
     ✓ <redacted> (25082ms)
     ✓ <redacted> (36254ms)
     ✓ <redacted> (24939ms)
     ✓ <redacted> (36228ms)
     ✓ <redacted> (27381ms)
     ✓ <redacted> (52244ms)
     ✓ <redacted> (52555ms)
     ✓ <redacted> (22583ms)
     ✓ <redacted> (24298ms)
     ✓ <redacted> (25579ms)
     ✓ <redacted> (24874ms)
     ✓ <redacted> (50217ms)
     ✓ <redacted> (48576ms)
     ✓ <redacted> (51119ms)
     ✓ <redacted> (50526ms)
     ✓ <redacted> (51364ms)
     ✓ <redacted> (50846ms)
     ✓ <redacted> (51190ms)
     ✓ <redacted> (50819ms)
     ✓ <redacted> (48400ms)

   35 passing (29m)
   6 failing

Desired behavior:

For execution time to not only be consistent, but also low.

Test code to reproduce

A minimal repository illustrating this behavior can be found here.

First, run the tests without any change.

$ npm test

...

  Running:  spec.js                                                                         (1 of 1)

  - should fail
  - should fail
  - should fail
  - should fail
  - should fail
  - should fail
  - should fail
  - should fail
  - should fail
  - should fail
  ✓ should not run slow (1613ms)
  ✓ should not run slow (1523ms)
  ✓ should not run slow (1494ms)
  ✓ should not run slow (1519ms)
  ✓ should not run slow (1484ms)
  ✓ should not run slow (1477ms)
  ✓ should not run slow (1457ms)
  ✓ should not run slow (1472ms)
  ✓ should not run slow (1526ms)
  ✓ should not run slow (1475ms)

  10 passing (15s)
  10 pending

...

Then enable the skipped tests and watch the execution time increase.

$ npm test

...

Running:  spec.js                                                                         (1 of 1)

  1) should fail
  2) should fail
  3) should fail
  4) should fail
  5) should fail
  6) should fail
  7) should fail
  8) should fail
  9) should fail
  10) should fail
  ✓ should not run slow (4441ms)
  ✓ should not run slow (4097ms)
  ✓ should not run slow (4080ms)
  ✓ should not run slow (4683ms)
  ✓ should not run slow (4151ms)
  ✓ should not run slow (4160ms)
  ✓ should not run slow (4076ms)
  ✓ should not run slow (4248ms)
  ✓ should not run slow (4149ms)
  ✓ should not run slow (4114ms)

  10 passing (2m)
  10 failing

...

Versions

Cypress v4.2.0, Arch Linux, Electron 80.

@jennifer-shehane
Copy link
Member

I can indeed recreate this behavior. Thank you for providing a clear reproducible example.

This happens in 4.3.0 in both Electron and Chrome headless - during cypress run, so snapshots are not involved in performance.

Seems to need to have several cy.request() in a single FAILING test while accessing its('body').

4.2.0 - Electron (no failing tests)

Screen Shot 2020-03-31 at 12 45 03 PM

4.2.0 - Electron (failing tests before)

Screen Shot 2020-03-31 at 12 48 22 PM

4.2.0 - Electron (all passing tests)

Screen Shot 2020-03-31 at 12 49 54 PM

3.8.0 does seem to have made the slowdown worse. I can't think of any changes in that version that could have effected this (after experimenting) except perhaps the Electron upgrade which brings me back to this performance issue: #5987

3.7.0

Screen Shot 2020-03-31 at 1 26 15 PM

3.8.0

Screen Shot 2020-03-31 at 1 27 25 PM

The smallest reproducible case where I could see the timing of the subsequent passing test be effected (basically doubling in time):

it('should fail', () => {
  for (let i = 0; i < 100; i++) {
    cy.request('http://localhost:8080')
      .its('body')
  }

  cy.wrap(null).then(() => {
    expect(false).to.be.true;
  });
});

it('should not run slow', () => {
  expect(true).to.be.true
})

With failing test

Screen Shot 2020-03-31 at 1 15 32 PM

Skip failing test

Screen Shot 2020-03-31 at 1 16 39 PM

@cypress-app-bot
Copy link
Collaborator

This issue has not had any activity in 180 days. Cypress evolves quickly and the reported behavior should be tested on the latest version of Cypress to verify the behavior is still occurring. It will be closed in 14 days if no updates are provided.

@cypress-app-bot cypress-app-bot added the stale no activity on this issue for a long period label Nov 3, 2023
@badeball
Copy link
Contributor Author

badeball commented Nov 3, 2023

This is still an issue with latest version. I've updated the example.

@jennifer-shehane jennifer-shehane removed stale no activity on this issue for a long period stage: icebox labels Nov 3, 2023
@elleklinton
Copy link

elleklinton commented Dec 19, 2023

Hello, I just want to chime in and say I am also facing this exact issue. I have about 84 tests in my application, and if none fail, each test takes about 10 seconds to run. However, if a single test fails, all subsequent tests that run are seemingly exponentially slower -- i.e. they take sometimes 60, even 100 seconds to run, which is 10x longer than they should take. Please do share if there is a solution to this problem, or if there is any other update, as this makes our builds excruciatingly slow to run functional tests...

I am on Cypress 13.2.0 btw

@jennifer-shehane

Thanks so much, cypress is awesome otherwise 😄

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
type: performance 🏃‍♀️ Performance related type: regression A bug that didn't appear until a specific Cy version release v3.8.0 🐛 Issue present since 3.8.0
Projects
None yet
Development

No branches or pull requests

4 participants