Tests that iterate over many DOM elements with .each() run slower in Electron during cypress run in 3.8.0
#5987
Comments
|
Definitely roll back to 3.7.0 for now. Can you run the tests with This example is a bit complicated since it requires loading Storybook. Can you provide a simpler example or a storybook url to visit that we can run the tests against? |
jennifer-shehane
added
stage: needs information
|
Thanks for your fast response! 😄 Sure, we've setup a one-off domain for this specific purpose: We've used the same button over and over to have roughly the same number of stories we ourselves are testing. I think this is relevant because the test seems to slow down as it advances. These are the different results using that endpoint:
The test code is above. Let me know if you have any trouble reproducing and thanks again for your help! |
|
This is a serious issue for me as well. |
|
@juan-fernandez Can you update this test so that it runs to completion as you've described? I'm not familiar with storybook or what this test is even supposed to do exactly. Test code I'm running. Cypress.Commands.add('componentHasLoaded', () => {
cy.get('#storybook-preview-iframe').then($iframe => {
const doc = $iframe.contents()
cy.wrap(doc.find('#root')).should('not.be.empty')
})
})
it('can load all components', () => {
cy.visit('https://unruffled-lalande-8277bd.netlify.com/?path=/story/button-0--default-1')
cy.get('[id^=explorer]').each($component => {
cy.wrap($component)
.click()
.get(`[id^=${$component[0].id}--]`)
.each($story => {
cy.wrap($story)
.click()
.wait(50)
.componentHasLoaded()
})
})
})Result:
|
@jennifer-shehane Thanks for your reply and attempt to reproduce! I think I know what is happening. Try do add this: cy.visit('?path=/settings/shortcuts').wait(3000)and run with You can directly This can be seen in https://www.loom.com/share/06105d01e4c445b183e466be6042d8d6 |
|
Hello, I've been researching this issue on Ubuntu and want to share what I've found out. TL;DR; It might be because of the too much memory usage. Start with the given situationThe first test I did was this: Cypress.Commands.add('componentHasLoaded', () => {
cy.get('#storybook-preview-iframe').then(($iframe) => {
const doc = $iframe.contents()
cy.wrap(doc.find('#root')).should('not.be.empty')
})
})
describe('issue #5987', () => {
it('test', () => {
cy.visit('https://unruffled-lalande-8277bd.netlify.com/?path=/story/button-0--default-1')
cy.get('#explorerbutton-0').click()
cy.get('[id^=explorer]').each(($component) => {
cy.wrap($component)
.click()
.get(`[id^=${$component[0].id}--]`)
.each(($story) => {
cy.wrap($story)
.click()
.wait(50)
.componentHasLoaded()
})
})
})
})Compared to @jennifer-shehane's code, I've added Anyway, the test starts to slow down after
They both cannot finish 100 buttons. (I've even watched a 30+ min gaming YouTube video while running test with my smartphone but the test didn't end.) The times to end 50 items were 1128 in Break down the test into small tests and run them separately.To understand why this happened, I tested with the code below: describe('issue #5987', () => {
let list = []
for (let i = 0; i < 100; i++) {
list.push(i)
}
before(() => {
cy.visit('https://unruffled-lalande-8277bd.netlify.com/?path=/story/button-0--default-1')
cy.get('#explorerbutton-0').click()
})
let list2 = [0, 1, 2, 3, 4]
list2.forEach((j) => {
list.forEach((i) => {
it(`test ${100 * j + i}`, () => {
cy.get(`#explorerbutton-${i}`).then(($component) => {
cy.wrap($component)
.click()
.get(`[id^=explorerbutton-${i}--]`)
.each(($story) => {
cy.wrap($story)
.click()
.wait(50)
.componentHasLoaded()
})
})
})
})
it('close all', () => {
list.forEach((i) => {
cy.get(`#explorerbutton-${i}`).click()
})
})
})
})It tests 100 buttons for 5 times. As you can see, the test is the same. But it uses the different test method. It calls In this case, this 500 tests ended under 600 seconds. (I remember it was 567 or something.) There was little slowdowns sometimes, but in most cases, it was fast enough. (If you're not stress testing Cypress, it might be the best workaround for now.) After these 2 tests, I wanted to check if it happens because there are too many commands in a test. (Around Create a simple test to reproduce the slowdown.So, I created the test 3. describe('issue #5987', () => {
it('test', () => {
cy.visit('https://unruffled-lalande-8277bd.netlify.com/?path=/story/button-0--default-1')
for (let i = 0; i < 2000; i++) {
cy.get('#explorerbutton-0').click()
}
})
})It's really simple. It just clicks To understand why it happens, I examined What's next?To check the hypothesis that it is caused by "too much memory usage", can you check how much memory is used in 3.7.0 and 3.8.0? If this hypothesis is right, what I need to check next is:
|
|
@sainthkh Yes, we've experience this ourselves in our docs tests - performing a large amount of commands in a single test slows Cypress down. (It is why we skip these tests when run in interactiveMode https://github.com/cypress-io/cypress-documentation/blob/develop/cypress/integration/table_of_contents.js#L29:L29) Have you tried reducing the I am most interesting in a possible regression, although the performance is an overall issue to be addressed. If we introduced something recently, it will be much easier to fix. |
|
@jennifer-shehane And it seems that 1.6GB of memory isn't enough for them. I might need to check:
After experiments are done, I'll share the result with you. |
|
@sainthkh Yeah, I believe that is the case. I thought we had an issue open for this somewhere but I can't find it. |
|
Experiment Result:
For example, describe('issue #5987', () => {
it('test', () => {
cy.visit('https://unruffled-lalande-8277bd.netlify.com/?path=/story/button-0--default-1')
for (let i = 0; i < 1000; i++) {
cy.get('#explorerbutton-0').click()
}
})
})The test above slows down after about 1000 entries. It uses 5%(1.6GB) of memory. <!--issue-5987.html-->
<!doctype html>
<html lang="en">
<body>
<button id="btn">Button</button>
</body>
</html>describe('issue #5987', () => {
it('test', () => {
cy.visit('/fixtures/issue-5987.html')
for (let i = 0; i < 1000; i++) {
cy.get('#btn').click()
}
})
})But when we change the tested html site simple, it works. It passed over 2000 commands, but used only 2%(0.64GB) of memory. We need to find out why simple site structure makes this difference. |
|
I realized that I was investigating a wrong problem. In When I created a new project and started fresh, I could reproduce it. There was a real difference between runtime.
I was tracking which commit caused the problem and found out that it is slowed down after #5849 (upgrading Electron to 7.1.4). In Electron 5.x, the memory use increased fast (about 0.3GB/min, i.e. 0.6GB in 2 minutes). But after Electron 6.x, it doesn't increase fast. It just went to 0.6GB after 10 minutes. Newer electron causes some kind of thrashing because it doesn't increase memory use fast. To fix this problem, I used From Electron 5.x to 6.x, these are changed:
It seems that something related to memory allocation has been changed. |
|
@sainthkh We just merged in an Electron 7.1.7 upgrade. May be worth seeing if it's been resolved in there. I've messaged the team about your theory. |
|
@jennifer-shehane Unfortunately, it didn't change, it took 11 min 25 seconds. |
|
@sainthkh Which spec are you running exactly when you are running the experiments to show the performance difference? |
|
could this have anything to do with https://support.google.com/chrome/thread/23003371 ? The test does keep scrolling to get the next story |
Cypress.Commands.add('componentHasLoaded', () => {
cy.get('#storybook-preview-iframe').then(($iframe) => {
const doc = $iframe.contents()
cy.wrap(doc.find('#root')).should('not.be.empty')
})
})
describe('issue #5987', () => {
it('test', () => {
cy.visit('https://unruffled-lalande-8277bd.netlify.com/?path=/story/button-0--default-1')
cy.get('#explorerbutton-0', { timeout: 30000 }).click()
cy.get('[id^=explorer]').each(($component) => {
cy.wrap($component)
.click()
.get(`[id^=${$component[0].id}--]`)
.each(($story) => {
cy.wrap($story)
.click()
.wait(50)
.componentHasLoaded()
})
})
})
})I added |
|
There is a performance issue introduced in Chrome 79 described here: #6023 (comment) Just wanted to link that issue here in case anyone does find their issue isolated completely to Chrome 79, it may be that issue. |
|
I used the Chrome dev tools Performance tab to profile one of my tests running under 3.7.0 vs 3.8.3. There is a definite difference in the code path. 3.7.0:
3.8.3
It seems that 3.8.0 might've introduced some change in the
Based on what I'm seeing in this trace, I am guessing that the culprit is #6000 or #5916, but I haven't done a bisect. |
|
Hi, The following test takes about 25 seconds on 3.7.0 and about 1:30 on 3.8.3. I wonder if the issue is something to do with describe('CAN LOOP', () => {
it('SHOULD LOOP', () => {
cy.visit('https://en.wikipedia.org/wiki/Star_Trek');
cy.get('.toc li').each(($el) => {
cy.wrap($el).find('a').each(($a) => {
cy.wrap($a).click();
});
});
cy.get('.toc li').each(($el) => {
cy.wrap($el).find('a').each(($a) => {
cy.wrap($a).click();
});
});
cy.get('.toc li').each(($el) => {
cy.wrap($el).find('a').each(($a) => {
cy.wrap($a).click();
});
});
});
});If I simplify the loops in the test to describe('CAN LOOP', () => {
it('SHOULD LOOP', () => {
cy.visit('https://en.wikipedia.org/wiki/Star_Trek');
cy.get('.toc li a').each(($a) => {
cy.wrap($a).click();
});
cy.get('.toc li a').each(($a) => {
cy.wrap($a).click();
});
cy.get('.toc li a').each(($a) => {
cy.wrap($a).click();
});
});
});Then is takes ~15seconds on 3.7.0 and ~23seconds on 3.8.3 |
|
In version 3.8.3 Test 1 takes SIGNIFICANTLY longer than Test 2 (note the only difference is the placement of the cy.visit()). In 3.7.0. both take almost exactly the same amount of time. Test 1 describe('CAN LOOP', () => {
it('SHOULD LOOP', () => {
cy.visit('https://en.wikipedia.org/wiki/Star_Trek');
cy.get('.toc li').each(($el) => {
cy.wrap($el).find('a').each(($a) => {
cy.wrap($a).click();
});
});
cy.get('.toc li').each(($el) => {
cy.wrap($el).find('a').each(($a) => {
cy.wrap($a).click();
});
});
});
});Test 2 describe('CAN LOOP', () => {
it('SHOULD VIST', () => {
cy.visit('https://en.wikipedia.org/wiki/Star_Trek');
});
it('SHOULD LOOP', () => {
cy.get('.toc li').each(($el) => {
cy.wrap($el).find('a').each(($a) => {
cy.wrap($a).click();
});
});
cy.get('.toc li').each(($el) => {
cy.wrap($el).find('a').each(($a) => {
cy.wrap($a).click();
});
});
});
}); |
|
This has the needs more info tag. Is there anything I can do to help besides the above tests that show the issue? |
cypress-bot
bot
added
stage: needs investigating
|
Not sure if linked, but I have this (#6597) in both 3.8 and v4. |
|
I have the same problem. In my case it's limited to Electron. Version 4 is the same |
|
I ran Git bisect with the simplified test case in #5987 (comment), measuring how long it takes to run. I got the same culprit as in #5987 (comment): the test run slows down from 18 seconds to 30 seconds starting from commit 3403713 Electron upgrade (#5849). Indeed, I didn't notice any significant difference between the Cypress versions when running in Chrome. Here's how I bisected in case it's useful:
#!/bin/bash
# Source: https://stackoverflow.com/a/49412454/305436
function float_gt() {
perl -e "{if($1>$2){print 1} else {print 0}}"
}
COMMAND="yarn dev --run-project my-tests --spec '**/tests/loop.js'"
DURATION_LIMIT=30
yarn
# Source: https://stackoverflow.com/a/26785328/305436
exec 3>&1 4>&2
DURATION=$(TIMEFORMAT='%R'; { time $COMMAND 1>&3 2>&4; } 2>&1)
if [ $? -ne 0 ]; then
echo "Test run failed, skipping commit"
exit 125
fi
exec 3>&- 4>&-
if [ $(float_gt $DURATION $DURATION_LIMIT) == 1 ]; then
echo "Took too long: $DURATION"
exit 1
fi
echo "Fast enough: $DURATION" |
juan-fernandez
changed the title
jennifer-shehane
added
the
type: regression
This comment has been minimized.
This comment has been minimized.
I have just tested and can confirm that Test 1 is still significantly slower than Test 2 on Cypress 5.2.0 |
jennifer-shehane
changed the title
.each() run slower in Electron in 3.8.0
jennifer-shehane
changed the title
.each() run slower in Electron in 3.8.0.each() run slower in Electron during cypress run in 3.8.0
|
Concerning the first example in #5987 (comment) I can recreate the behavior of the specs running slowing in headless Electron in 3.8.0. Reprodescribe('CAN LOOP', () => {
it('SHOULD LOOP', () => {
cy.visit('https://en.wikipedia.org/wiki/Star_Trek');
cy.get('.toc li').each(($el) => {
cy.wrap($el).find('a').each(($a) => {
cy.wrap($a).click();
});
});
cy.get('.toc li').each(($el) => {
cy.wrap($el).find('a').each(($a) => {
cy.wrap($a).click();
});
});
});
});Timings
|
cypress-bot
bot
added
stage: backlog
and removed
stage: needs investigating
|
Just doing some cleanup as we begin looking into this internally; closing in favor of #4164, which contains links to a bunch of different examples (including this one). Definitely a real issue, and closing doesn't mean we're not paying attention; just consolidating a bit as we start looking into this more seriously. |
Current behavior:
We have a storybook cypress smoke test that opens all the stories and checks that they render. The test itself is very simple:
With
Our test duration went from roughly 2 minutes to roughly 8 minutes as seen in the graph:
(after some commits we decided to roll back to
cypress@3.7.0)There were absolutely no changes in the app code.
The only change was moving from
cypress@3.7.0tocypress@3.8.0. From what we've seen, there are no noticeable changes in the test (no new logs or errors) other than the interaction just being slower. The command to run cypress is exactly the same but we've noticed that theElectronversion has changed from73to78as seen in the screenshots:Desired behavior:
We'd like to know if there is something to do on our end to go back to the old speed or if there is a bug in cypress that created this performance regression.
Steps to reproduce: (app code and test code)
Run a storybook test with:
With
Versions
cypress@3.8.0Performance regression found in
Also locally in MacOS
10.15.2The text was updated successfully, but these errors were encountered: