Bug 36012

Summary: ERM/Agreements_spec.ts might be failing if run too slow
Product: Koha Reporter: Jonathan Druart <jonathan.druart>
Component: Test SuiteAssignee: Jonathan Druart <jonathan.druart>
Status: Pushed to main --- QA Contact: Testopia <testopia>
Severity: normal    
Priority: P5 - low CC: fridolin.somers, matt.blenkinsop, pedro.amorim, tomascohen
Version: unspecified   
Hardware: All   
OS: All   
See Also: https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=32898
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=33861
https://bugs.koha-community.org/bugzilla3/show_bug.cgi?id=34301
Change sponsored?: --- Patch complexity: ---
Documentation contact: Documentation submission:
Text to go in the release notes:
Version(s) released in:
24.05.00
Bug Depends on: 32474    
Bug Blocks:    
Attachments: Bug 36012: Add 'waits' to cypress test
Bug 36012: Extend cypress's requestTimeout value
Bug 36012: Extend cypress's requestTimeout value

Description Jonathan Druart 2024-02-07 08:40:26 UTC
koha_1       |   Running:  ERM/Agreements_spec.ts                                                         (3 of 13)
es_1         | {"type": "server", "timestamp": "2024-02-06T16:59:14,821Z", "level": "WARN", "component": "o.e.c.r.a.DiskThresholdMonitor", "cluster.name": "docker-cluster", "node.name": "9c98971d8b48", "message": "high disk watermark [90%] exceeded on [ZlMDdHYSRcqipOaGsczI_w][9c98971d8b48][/usr/share/elasticsearch/data/nodes/0] free: 2.3gb[5.9%], shards will be relocated away from this node; currently relocating away shards totalling [0] bytes; the node is expected to continue to exceed the high disk watermark when these relocations are complete", "cluster.uuid": "wwW7XQ57T-SNI8QrMEYbPA", "node.id": "ZlMDdHYSRcqipOaGsczI_w"  }
koha_1       | <?xml version="1.0" encoding="UTF-8"?>
koha_1       | <testsuites name="Mocha Tests" time="67.080" tests="5" failures="1">
koha_1       |   <testsuite name="Root Suite" timestamp="2024-02-06T16:59:06" tests="0" file="t/cypress/integration/ERM/Agreements_spec.ts" time="0.000" failures="0">
koha_1       |   </testsuite>
koha_1       |   <testsuite name="Agreement CRUD operations" timestamp="2024-02-06T16:59:06" tests="5" time="67.047" failures="1">
koha_1       |     <testcase name="Agreement CRUD operations List agreements" time="0.000" classname="List agreements">
koha_1       |       <failure message="Timed out retrying after 5000ms: `cy.wait()` timed out waiting `5000ms` for the 4th request to the route: `getActiveAgreements`. No request ever occurred.
koha_1       | 
koha_1       | https://on.cypress.io/wait" type="CypressError"><![CDATA[CypressError: Timed out retrying after 5000ms: `cy.wait()` timed out waiting `5000ms` for the 4th request to the route: `getActiveAgreements`. No request ever occurred.
koha_1       | 
koha_1       | https://on.cypress.io/wait
koha_1       |     at cypressErr (http://localhost:8081/__cypress/runner/cypress_runner.js:75187:18)
koha_1       |     at Object.errByPath (http://localhost:8081/__cypress/runner/cypress_runner.js:75242:10)
koha_1       |     at checkForXhr (http://localhost:8081/__cypress/runner/cypress_runner.js:134821:84)
koha_1       |     at <unknown> (http://localhost:8081/__cypress/runner/cypress_runner.js:134844:28)
koha_1       |     at tryCatcher (http://localhost:8081/__cypress/runner/cypress_runner.js:1807:23)
koha_1       |     at Promise.attempt.Promise.try (http://localhost:8081/__cypress/runner/cypress_runner.js:4315:29)
koha_1       |     at whenStable (http://localhost:8081/__cypress/runner/cypress_runner.js:143192:68)
koha_1       |     at <unknown> (http://localhost:8081/__cypress/runner/cypress_runner.js:143133:14)
koha_1       |     at tryCatcher (http://localhost:8081/__cypress/runner/cypress_runner.js:1807:23)
koha_1       |     at Promise._settlePromiseFromHandler (http://localhost:8081/__cypress/runner/cypress_runner.js:1519:31)
koha_1       |     at Promise._settlePromise (http://localhost:8081/__cypress/runner/cypress_runner.js:1576:18)
koha_1       |     at Promise._settlePromise0 (http://localhost:8081/__cypress/runner/cypress_runner.js:1621:10)
koha_1       |     at Promise._settlePromises (http://localhost:8081/__cypress/runner/cypress_runner.js:1701:18)
koha_1       |     at Promise._fulfill (http://localhost:8081/__cypress/runner/cypress_runner.js:1645:18)
koha_1       |     at <unknown> (http://localhost:8081/__cypress/runner/cypress_runner.js:5450:46)
koha_1       | From Your Spec Code:
koha_1       |     at Context.eval (webpack://koha/./t/cypress/integration/ERM/Agreements_spec.ts:119:11)]]></failure>
koha_1       |     </testcase>
koha_1       |     <testcase name="Agreement CRUD operations Add agreement" time="30.510" classname="Add agreement">
koha_1       |     </testcase>
koha_1       |     <testcase name="Agreement CRUD operations Edit agreement" time="6.377" classname="Edit agreement">
koha_1       |     </testcase>
koha_1       |     <testcase name="Agreement CRUD operations Show agreement" time="4.285" classname="Show agreement">
koha_1       |     </testcase>
koha_1       |     <testcase name="Agreement CRUD operations Delete agreement" time="8.038" classname="Delete agreement">
koha_1       |     </testcase>
koha_1       |   </testsuite>
koha_1       | </testsuites>


I do not recreate locally, is it because we need to extend the timeout?
Comment 1 Jonathan Druart 2024-02-07 09:46:10 UTC
This was Koha_Master/2795

I scheduled another run (2796) and now it's InfiniteScrollSelect_spec that is getting a timeout

koha_1       |   Running:  InfiniteScrollSelect_spec.ts                                                   (1 of 13)
koha_1       | <?xml version="1.0" encoding="UTF-8"?>
koha_1       | <testsuites name="Mocha Tests" time="32.874" tests="4" failures="1">
koha_1       |   <testsuite name="Root Suite" timestamp="2024-02-07T09:33:33" tests="0" file="t/cypress/integration/InfiniteScrollSelect_spec.ts" time="0.000" failures="0">
koha_1       |   </testsuite>
koha_1       |   <testsuite name="Infinite scroll" timestamp="2024-02-07T09:33:33" tests="4" time="32.851" failures="1">
koha_1       |     <testcase name="Infinite scroll Should load the next page on scroll" time="6.352" classname="Should load the next page on scroll">
koha_1       |     </testcase>
koha_1       |     <testcase name="Infinite scroll Should correctly submit the form" time="0.000" classname="Should correctly submit the form">
koha_1       |       <failure message="Timed out retrying after 10000ms: Expected to find element: `main div[class=&apos;dialog message&apos;]`, but never found it." type="AssertionError"><![CDATA[AssertionError: Timed out retrying after 10000ms: Expected to find element: `main div[class='dialog message']`, but never found it.
koha_1       |     at Context.eval (webpack://koha/./t/cypress/integration/InfiniteScrollSelect_spec.ts:163:11)]]></failure>
koha_1       |     </testcase>
koha_1       |     <testcase name="Infinite scroll Should correctly display labels" time="5.314" classname="Should correctly display labels">
koha_1       |     </testcase>
koha_1       |     <testcase name="Infinite scroll Should correctly display the label when editing" time="4.267" classname="Should correctly display the label when editing">
koha_1       |     </testcase>
koha_1       |   </testsuite>
koha_1       | </testsuites>
Comment 2 Matt Blenkinsop 2024-02-07 10:00:09 UTC
Maybe we do need to try upping the timeout - all tests are passing locally

Can we set the Jenkins run to produce and save the cypress videos? That way we may be able to see if there's anything we're missing
Comment 3 Jonathan Druart 2024-02-09 07:28:01 UTC
For the record, #2797 is passing.

(In reply to Matt Blenkinsop from comment #2)
> Maybe we do need to try upping the timeout - all tests are passing locally

Yes, but 10s is already a lot! :)

> Can we set the Jenkins run to produce and save the cypress videos? That way
> we may be able to see if there's anything we're missing

The easiest would be IMO to connect to a node when it's running and run the cypress command manually. Otherwise you will need to adjust misc4dev, etc.

Agreements failed on Docker_4
InfiniteScroll failed on Docker_15
and the last success build was on Docker_8
Comment 4 Jonathan Druart 2024-02-14 13:22:19 UTC
Koha_Master/2798

12:40:57 koha_1       | https://on.cypress.io/wait" type="CypressError"><![CDATA[CypressError: Timed out retrying after 5000ms: `cy.wait()` timed out waiting `5000ms` for the 1st request to the route: `getPageTwo`. No request ever occurred.
Comment 5 Jonathan Druart 2024-02-14 15:29:55 UTC
Again, Koha_Master/2799

koha_1       |   Running:  InfiniteScrollSelect_spec.ts                                                   (1 of 13)
koha_1       | <?xml version="1.0" encoding="UTF-8"?>
koha_1       | <testsuites name="Mocha Tests" time="37.336" tests="4" failures="2">
koha_1       |   <testsuite name="Root Suite" timestamp="2024-02-14T14:36:05" tests="0" file="t/cypress/integration/InfiniteScrollSelect_spec.ts" time="0.000" failures="0">
koha_1       |   </testsuite>
koha_1       |   <testsuite name="Infinite scroll" timestamp="2024-02-14T14:36:05" tests="4" time="37.316" failures="2">
koha_1       |     <testcase name="Infinite scroll Should load the next page on scroll" time="5.922" classname="Should load the next page on scroll">
koha_1       |     </testcase>
koha_1       |     <testcase name="Infinite scroll Should correctly submit the form" time="0.000" classname="Should correctly submit the form">
koha_1       |       <failure message="Timed out retrying after 10000ms: Expected to find element: `main div[class=&apos;dialog message&apos;]`, but never found it." type="AssertionError"><![CDATA[AssertionError: Timed out retrying after 10000ms: Expected to find element: `main div[class='dialog message']`, but never found it.
koha_1       |     at Context.eval (webpack://koha/./t/cypress/integration/InfiniteScrollSelect_spec.ts:163:11)]]></failure>
koha_1       |     </testcase>
koha_1       |     <testcase name="Infinite scroll Should correctly display labels" time="0.000" classname="Should correctly display labels">
koha_1       |       <failure message="Timed out retrying after 10000ms: Expected to find content: &apos;License 50&apos; within the element: &lt;fieldset#agreement_license_0.rows&gt; but never did." type="AssertionError"><![CDATA[AssertionError: Timed out retrying after 10000ms: Expected to find content: 'License 50' within the element: <fieldset#agreement_license_0.rows> but never did.
koha_1       |     at Context.eval (webpack://koha/./t/cypress/integration/InfiniteScrollSelect_spec.ts:248:39)]]></failure>
koha_1       |     </testcase>
koha_1       |     <testcase name="Infinite scroll Should correctly display the label when editing" time="3.529" classname="Should correctly display the label when editing">
koha_1       |     </testcase>
koha_1       |   </testsuite>
koha_1       | </testsuites>
Comment 6 Matt Blenkinsop 2024-02-15 14:42:44 UTC
Both failures are in places where we aren't asking Cypress to wait for the result of a network response - I'm adding a patch that adds these in. We could use this as an experiment to see if it stops failures in the Infinite Scroll test. If it does then we could look to expand this to the other specs
Comment 7 Matt Blenkinsop 2024-02-15 14:43:04 UTC
Created attachment 162207 [details] [review]
Bug 36012: Add 'waits' to cypress test

This patch adds cy.wait() in two places where builds have been failing due to timeouts

Test plan:
1) cypress run --spec t/cypress/integration/InfiniteScrollSelect_spec.ts
Comment 8 Jonathan Druart 2024-03-04 15:15:09 UTC
Koha_Master/2804

koha_1       |       <failure message="Timed out retrying after 10000ms: Expected to find content: &apos;License 50&apos; within the element: &lt;fieldset#agreement_license_0.rows&gt; but never did." type="AssertionError"><![CDATA[AssertionError: Timed out retrying after 10000ms: Expected to find content: 'License 50' within the element: <fieldset#agreement_license_0.rows> but never did.
Comment 9 Katrin Fischer 2024-03-07 13:12:58 UTC
It looks like this just happened in our last run on Jenkins, it would be great to have a fix:

https://jenkins.koha-community.org/job/Koha_Master/lastCompletedBuild/testReport/(root)/Should%20correctly%20display%20labels/Infinite_scroll_Should_correctly_display_labels/
Comment 10 Katrin Fischer 2024-03-08 15:32:44 UTC
(In reply to Katrin Fischer from comment #9)
> It looks like this just happened in our last run on Jenkins, it would be
> great to have a fix:
> 
> https://jenkins.koha-community.org/job/Koha_Master/lastCompletedBuild/
> testReport/(root)/Should%20correctly%20display%20labels/
> Infinite_scroll_Should_correctly_display_labels/

Wrong link, but was the same problem as posted here previously.
Comment 11 Katrin Fischer 2024-03-08 16:25:36 UTC
I totally missed the patch here, because the status was still NEW. I've tested it locally and will push it to see if it fixes Jenkins.
Comment 12 Katrin Fischer 2024-03-08 17:59:47 UTC
Pushed for 24.05!

Well done everyone, thank you!
Comment 13 Fridolin Somers 2024-03-11 10:28:38 UTC
Depends on Bug 32474 not in 23.11.x
Comment 14 Jonathan Druart 2024-03-12 09:52:33 UTC
Still failing (Koha_Master/2809)

17:04:34 koha_1       |       <failure message="Timed out retrying after 5000ms: `cy.wait()` timed out waiting `5000ms` for the 1st request to the route: `resetDropdown`. No request ever occurred.
17:04:34 koha_1       | 
17:04:34 koha_1       | https://on.cypress.io/wait" type="CypressError"><![CDATA[CypressError: Timed out retrying after 5000ms: `cy.wait()` timed out waiting `5000ms` for the 1st request to the route: `resetDropdown`. No request ever occurred.
Comment 15 Jonathan Druart 2024-03-12 10:05:04 UTC
Created attachment 163088 [details] [review]
Bug 36012: Extend cypress's requestTimeout value

default to 5000 but tests are failing because of slow Jenkins's nodes.
We could try and extend to 10000 (10s) and see if it gets better.
Comment 16 Jonathan Druart 2024-03-12 10:05:36 UTC
(In reply to Jonathan Druart from comment #15)
> Created attachment 163088 [details] [review] [review]
> Bug 36012: Extend cypress's requestTimeout value
> 
> default to 5000 but tests are failing because of slow Jenkins's nodes.
> We could try and extend to 10000 (10s) and see if it gets better.

Matt, do you agree with that?
Comment 17 Matt Blenkinsop 2024-03-12 10:34:01 UTC
Yes I think thats the best course of action now that adding the cy.wait hasn't fixed it
Comment 18 Katrin Fischer 2024-03-15 07:04:43 UTC
This is still in NEW, can you please clarify the status? Thanks!
Comment 19 Jonathan Druart 2024-03-22 11:07:56 UTC
Koha_Master/2819 (Docker_15)

koha_1       | https://on.cypress.io/wait" type="CypressError"><![CDATA[CypressError: Timed out retrying after 5000ms: `cy.wait()` timed out waiting `5000ms` for the 1st request to the route: `get-single-agreement-search-result`. No request ever occurred.
Comment 20 Tomás Cohen Arazi 2024-03-22 13:19:57 UTC
Created attachment 163704 [details] [review]
Bug 36012: Extend cypress's requestTimeout value

default to 5000 but tests are failing because of slow Jenkins's nodes.
We could try and extend to 10000 (10s) and see if it gets better.

Signed-off-by: Tomas Cohen Arazi <tomascohen@theke.io>
Tests pass with and without the patch on my computer. Tested with:

yarn cypress run --env KOHA_USER=koha,KOHA_PASS=koha \
        --spec t/cypress/integration/ERM/Agreements_spec.ts
Comment 21 Tomás Cohen Arazi 2024-03-22 13:20:49 UTC
Matt agreed with this solution as well. PQA so we can check on Jenkins.
Comment 22 Katrin Fischer 2024-03-22 14:09:28 UTC
Pushed for 24.05!

Well done everyone, thank you!
Comment 23 Jonathan Druart 2024-05-15 12:08:25 UTC
This is still failing!

Koha_Main/2906

koha_1       | <?xml version="1.0" encoding="UTF-8"?>
koha_1       | <testsuites name="Mocha Tests" time="27.382" tests="4" failures="1">
koha_1       |   <testsuite name="Root Suite" timestamp="2024-05-15T10:03:33" tests="0" file="t/cypress/integration/InfiniteScrollSelect_spec.ts" time="0.000" failures="0">
koha_1       |   </testsuite>
koha_1       |   <testsuite name="Infinite scroll" timestamp="2024-05-15T10:03:33" tests="4" time="27.360" failures="1">
koha_1       |     <testcase name="Infinite scroll Should load the next page on scroll" time="6.075" classname="Should load the next page on scroll">
koha_1       |     </testcase>
koha_1       |     <testcase name="Infinite scroll Should correctly submit the form" time="4.025" classname="Should correctly submit the form">
koha_1       |     </testcase>
koha_1       |     <testcase name="Infinite scroll Should correctly display labels" time="0.000" classname="Should correctly display labels">
koha_1       |       <failure message="Timed out retrying after 10000ms: `cy.wait()` timed out waiting `10000ms` for the 1st request to the route: `resetDropdown`. No request ever occurred.
koha_1       | 
koha_1       | https://on.cypress.io/wait" type="CypressError"><![CDATA[CypressError: Timed out retrying after 10000ms: `cy.wait()` timed out waiting `10000ms` for the 1st request to the route: `resetDropdown`. No request ever occurred.
koha_1       | 
koha_1       | https://on.cypress.io/wait
koha_1       |     at cypressErr (http://localhost:8081/__cypress/runner/cypress_runner.js:75187:18)
koha_1       |     at Object.errByPath (http://localhost:8081/__cypress/runner/cypress_runner.js:75242:10)
koha_1       |     at checkForXhr (http://localhost:8081/__cypress/runner/cypress_runner.js:134821:84)
koha_1       |     at <unknown> (http://localhost:8081/__cypress/runner/cypress_runner.js:134844:28)
koha_1       |     at tryCatcher (http://localhost:8081/__cypress/runner/cypress_runner.js:1807:23)
koha_1       |     at Promise.attempt.Promise.try (http://localhost:8081/__cypress/runner/cypress_runner.js:4315:29)
koha_1       |     at whenStable (http://localhost:8081/__cypress/runner/cypress_runner.js:143192:68)
koha_1       |     at <unknown> (http://localhost:8081/__cypress/runner/cypress_runner.js:143133:14)
koha_1       |     at tryCatcher (http://localhost:8081/__cypress/runner/cypress_runner.js:1807:23)
koha_1       |     at Promise._settlePromiseFromHandler (http://localhost:8081/__cypress/runner/cypress_runner.js:1519:31)
koha_1       |     at Promise._settlePromise (http://localhost:8081/__cypress/runner/cypress_runner.js:1576:18)
koha_1       |     at Promise._settlePromise0 (http://localhost:8081/__cypress/runner/cypress_runner.js:1621:10)
koha_1       |     at Promise._settlePromises (http://localhost:8081/__cypress/runner/cypress_runner.js:1701:18)
koha_1       |     at Promise._fulfill (http://localhost:8081/__cypress/runner/cypress_runner.js:1645:18)
koha_1       |     at <unknown> (http://localhost:8081/__cypress/runner/cypress_runner.js:5450:46)
koha_1       | From Your Spec Code:
koha_1       |     at Context.eval (webpack://koha/./t/cypress/integration/InfiniteScrollSelect_spec.ts:248:11)]]></failure>
koha_1       |     </testcase>
koha_1       |     <testcase name="Infinite scroll Should correctly display the label when editing" time="3.187" classname="Should correctly display the label when editing">
koha_1       |     </testcase>
koha_1       |   </testsuite>
koha_1       | </testsuites>
Comment 24 Jonathan Druart 2024-05-15 12:32:03 UTC
Run in a loop locally.

After 3 runs I got
CypressError: Timed out retrying after 10000ms: `cy.wait()` timed out waiting `10000ms` for the 1st request to the route: `getPageTwo`. No request ever occurred.

Same failure after 18 runs.

This is really unreliable. It's either the code or the tests but we must fix this failure.

To debug we could try to remove the intercept/wait and rely on 500 licenses existing in the DB, and see how it behaves.
Comment 25 Matt Blenkinsop 2024-05-16 15:36:24 UTC
I've been looking at the cypress failures today using CPULimit with the limit set to 25%. When doing that in KTD I can get random failures quite easily.

I've tried various changes in the test files to try and prevent these failures but nothing seems to be working. It seems to be CPU related and the tests lagging beyond the timeout. We don't want to keep increasing the timeouts but we could try adding retries to give the tests more chances at passing?

When I run ```yarn cypress run --spec t/cypress/integration/InfiniteScrollSelect_spec.ts --config video=false retries={runMode:3,openMode:0}``` I get a big reduction in the random failures even on 25% CPU

Not a complete fix but it might improve things slightly
Comment 26 Katrin Fischer 2024-05-16 19:21:51 UTC
Thanks Matt for looking into this! I'd really love to see the random failures reduced.
Comment 27 Jonathan Druart 2024-05-17 07:03:30 UTC
(In reply to Matt Blenkinsop from comment #25)
> When I run ```yarn cypress run --spec
> t/cypress/integration/InfiniteScrollSelect_spec.ts --config video=false
> retries={runMode:3,openMode:0}``` I get a big reduction in the random
> failures even on 25% CPU

Not ideal, especially because it will impact all tests, but we could give it a try.
However I think we should have runMode==openMode, there is no good reason to have different behaviours for the two modes IMO.
Comment 28 Matt Blenkinsop 2024-05-17 09:11:22 UTC
Agreed. Can we set the builds to allocate more CPU to the Cypress tests? That might help reduce the issues as well but I'm not sure what other processes would be running in parallel
Comment 29 Jonathan Druart 2024-05-21 06:53:54 UTC
You could have a look at one of the run (when running on a PTFS-E nodes), but I don't think something else will be running at the same time.
Comment 30 Katrin Fischer 2024-05-27 11:59:29 UTC
It looks like this just popped up on D12 again.