Bug 35598 - selenium/authentication_2fa.t is still failing randomly
Summary: selenium/authentication_2fa.t is still failing randomly
Status: Pushed to oldstable
Alias: None
Product: Koha
Classification: Unclassified
Component: Test Suite (show other bugs)
Version: unspecified
Hardware: All All
: P5 - low normal (vote)
Assignee: Jonathan Druart
QA Contact: Tomás Cohen Arazi
URL:
Keywords:
Depends on:
Blocks: 25551
  Show dependency treegraph
 
Reported: 2023-12-19 09:01 UTC by Jonathan Druart
Modified: 2024-01-19 20:55 UTC (History)
4 users (show)

See Also:
Change sponsored?: ---
Patch complexity: ---
Documentation contact:
Documentation submission:
Text to go in the release notes:
Version(s) released in:
24.05.00,23.11.02,23.05.08


Attachments
Bug 35598: Fix selenium/authentication_2fa.t random failure (3.99 KB, patch)
2023-12-19 09:53 UTC, Jonathan Druart
Details | Diff | Splinter Review
Bug 35598: Fix selenium/authentication_2fa.t random failure (4.11 KB, patch)
2023-12-20 07:54 UTC, Jonathan Druart
Details | Diff | Splinter Review
Bug 35598: Fix selenium/authentication_2fa.t random failure (4.16 KB, patch)
2023-12-20 09:58 UTC, David Nind
Details | Diff | Splinter Review
Bug 35598: Fix selenium/authentication_2fa.t random failure (4.26 KB, patch)
2023-12-20 15:15 UTC, Tomás Cohen Arazi
Details | Diff | Splinter Review

Note You need to log in before you can comment on or make changes to this bug.
Description Jonathan Druart 2023-12-19 09:01:25 UTC
Koha_Master/2767 Docker_15

koha_1       | STRACE:	/usr/share/perl5/Try/Tiny.pm:123 in Selenium::Remote::Driver::catch {...} 
koha_1       | 	/usr/share/perl5/Selenium/Remote/Driver.pm:361 in Try::Tiny::try
koha_1       | 	(eval 582):1 in Selenium::Remote::Driver::__ANON__
koha_1       | 	(eval 584):2 in Selenium::Remote::Driver::__ANON__
koha_1       | 	(eval 556):17 in Selenium::Remote::Driver::_execute_command
koha_1       | 	/usr/share/perl5/Selenium/Remote/WebElement.pm:125 in Selenium::Remote::WebElement::_execute_command
koha_1       | 	t/db_dependent/selenium/authentication_2fa.t:276 in Selenium::Remote::WebElement::send_keys
koha_1       | 	/usr/share/perl/5.32/Test/Builder.pm:334 in main::__ANON__
koha_1       | 	/usr/share/perl/5.32/Test/Builder.pm:334 in (eval)
koha_1       | 	/usr/share/perl/5.32/Test/More.pm:809 in Test::Builder::subtest
koha_1       | 	t/db_dependent/selenium/authentication_2fa.t:294 in Test::More::subtest
koha_1       | 
selenium_1   | 1702911648831	Marionette	INFO	Stopped listening on port 41385
selenium_1   | JavaScript error: resource:///modules/Interactions.jsm, line 230: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIUserIdleService.removeIdleObserver]
selenium_1   | 15:00:49.452 INFO [ActiveSessions$1.onStop] - Removing session c3461b22-7a80-4b56-b177-653a53cc2651 (org.openqa.selenium.firefox.GeckoDriverService)
koha_1       |     # Looks like you planned 7 tests but ran 3.
koha_1       | 
koha_1       | #   Failed test 'Enforce 2FA setup on first login'
koha_1       | #   at t/db_dependent/selenium/authentication_2fa.t line 294.
koha_1       | Error while executing command: element not interactable: Element <input id="pin_code" name="pin_code" type="text"> is not reachable by keyboard at /usr/share/perl5/Selenium/Remote/Driver.pm line 411.
koha_1       |  at /usr/share/perl5/Selenium/Remote/Driver.pm line 356.
koha_1       | # Looks like your test exited with 255 just after 4.
koha_1       | [15:00:49] t/db_dependent/selenium/authentication_2fa.t
Comment 1 Jonathan Druart 2023-12-19 09:53:09 UTC Comment hidden (obsolete)
Comment 2 David Nind 2023-12-19 18:55:42 UTC
The tests are failing for me after applying the patch (and keeping the wait), started KTD with: ktd --selenium up.

Here is the result after
~~~~~~~~~~~~~~~~~~~~~~~~

prove t/db_dependent/selenium/authentication_2fa.t
t/db_dependent/selenium/authentication_2fa.t .. 2/5 
    #   Failed test 'Email not sent will display an error'
    #   at t/db_dependent/selenium/authentication_2fa.t line 215.
    #                   ''
    #     doesn't match '(?^u:Email not sent)'
    # Looks like you failed 1 test of 3.

#   Failed test 'Send OTP code'
#   at t/db_dependent/selenium/authentication_2fa.t line 234.
    # Looks like you planned 7 tests but ran 2.
t/db_dependent/selenium/authentication_2fa.t .. 4/5 
#   Failed test 'Enforce 2FA setup on first login'
#   at t/db_dependent/selenium/authentication_2fa.t line 296.
Cannot wait more for element '//*[@id="registration-form"]' to be visible at /kohadevbox/koha/t/lib/Selenium.pm line 189.
# Looks like your test exited with 255 just after 4.
t/db_dependent/selenium/authentication_2fa.t .. Dubious, test returned 255 (wstat 65280, 0xff00)
Failed 3/5 subtests 

Test Summary Report
-------------------
t/db_dependent/selenium/authentication_2fa.t (Wstat: 65280 Tests: 4 Failed: 2)
  Failed tests:  3-4
  Non-zero exit status: 255
  Parse errors: Bad plan.  You planned 5 tests but ran 4.
Files=1, Tests=4, 73 wallclock secs ( 0.01 usr  0.02 sys +  1.46 cusr  0.28 csys =  1.77 CPU)
Result: FAIL


Here is the result after - with -v
~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~

prove -v t/db_dependent/selenium/authentication_2fa.t
t/db_dependent/selenium/authentication_2fa.t .. 
1..5
# Subtest: Setup
    1..13
    ok 1 - Hitting the main page should redirect to the login form
    ok 2 - Patron with flags superlibrarian should be able to login
    ok 3 - Must be redirected to 404 is the pref is off
    ok 4 - Must be on the page with the pref on
    ok 5 - 2FA is disabled
    ok 6 - 2FA is disabled
    ok 7 - There is a QR code
    ok 8
    ok 9
    ok 10 - secret is not set in DB yet
    ok 11 - 2FA is enabled
    ok 12 - 2FA is enabled
    ok 13 - encrypted secret is set in DB
ok 1 - Setup
# Subtest: Login
    1..18
    ok 1 - Must be on the first auth screen
    ok 2 - Must be on the second auth screen
    ok 3
    ok 4 - Must be redirected to the original page
    ok 5 - Must be on the first auth screen
    ok 6 - Must be on the second auth screen
    ok 7
    ok 8
    ok 9 - Must still be on the second auth screen
    ok 10
    ok 11 - Must be on the first auth screen
    ok 12
    ok 13 - Must be on the first auth screen
    ok 14
    ok 15 - Must be on the second auth screen
    ok 16
    ok 17
    ok 18 - Must be redirected to the original page
ok 2 - Login
# Subtest: Send OTP code
    1..3
    ok 1 - Must be on the first auth screen
    ok 2 - Must be on the second auth screen
    not ok 3 - Email not sent will display an error

    #   Failed test 'Email not sent will display an error'
    #   at t/db_dependent/selenium/authentication_2fa.t line 215.
    #                   ''
    #     doesn't match '(?^u:Email not sent)'
    # Looks like you failed 1 test of 3.
not ok 3 - Send OTP code

#   Failed test 'Send OTP code'
#   at t/db_dependent/selenium/authentication_2fa.t line 234.
# Subtest: Enforce 2FA setup on first login
    1..7
    ok 1 - Must be on the first auth screen
    ok 2 - Must be on the 2FA auth setup screen
    # Looks like you planned 7 tests but ran 2.
not ok 4 - Enforce 2FA setup on first login

#   Failed test 'Enforce 2FA setup on first login'
#   at t/db_dependent/selenium/authentication_2fa.t line 296.
Cannot wait more for element '//*[@id="registration-form"]' to be visible at /kohadevbox/koha/t/lib/Selenium.pm line 189.
# Looks like your test exited with 255 just after 4.
Dubious, test returned 255 (wstat 65280, 0xff00)
Failed 3/5 subtests 

Test Summary Report
-------------------
t/db_dependent/selenium/authentication_2fa.t (Wstat: 65280 Tests: 4 Failed: 2)
  Failed tests:  3-4
  Non-zero exit status: 255
  Parse errors: Bad plan.  You planned 5 tests but ran 4.
Files=1, Tests=4, 72 wallclock secs ( 0.01 usr  0.01 sys +  1.47 cusr  0.33 csys =  1.82 CPU)
Result: FAIL
Comment 3 David Nind 2023-12-19 19:03:16 UTC
If I remove the wait with the patch applied, then the tests pass.
Comment 4 Jonathan Druart 2023-12-20 07:54:06 UTC Comment hidden (obsolete)
Comment 5 Jonathan Druart 2023-12-20 07:55:07 UTC
(In reply to David Nind from comment #3)
> If I remove the wait with the patch applied, then the tests pass.

I forgot one change to make the sleep works correctly, you also need to add "async" line 284.
I've adjusted the test plan!
Comment 6 David Nind 2023-12-20 09:58:16 UTC
Created attachment 160099 [details] [review]
Bug 35598: Fix selenium/authentication_2fa.t random failure

Jenkins is failing with
koha_1       | STRACE:	/usr/share/perl5/Try/Tiny.pm:123 in Selenium::Remote::Driver::catch {...}
koha_1       | 	/usr/share/perl5/Selenium/Remote/Driver.pm:361 in Try::Tiny::try
koha_1       | 	(eval 582):1 in Selenium::Remote::Driver::__ANON__
koha_1       | 	(eval 584):2 in Selenium::Remote::Driver::__ANON__
koha_1       | 	(eval 556):17 in Selenium::Remote::Driver::_execute_command
koha_1       | 	/usr/share/perl5/Selenium/Remote/WebElement.pm:125 in Selenium::Remote::WebElement::_execute_command
koha_1       | 	t/db_dependent/selenium/authentication_2fa.t:276 in Selenium::Remote::WebElement::send_keys
koha_1       | 	/usr/share/perl/5.32/Test/Builder.pm:334 in main::__ANON__
koha_1       | 	/usr/share/perl/5.32/Test/Builder.pm:334 in (eval)
koha_1       | 	/usr/share/perl/5.32/Test/More.pm:809 in Test::Builder::subtest
koha_1       | 	t/db_dependent/selenium/authentication_2fa.t:294 in Test::More::subtest
koha_1       |
selenium_1   | 1702911648831	Marionette	INFO	Stopped listening on port 41385
selenium_1   | JavaScript error: resource:///modules/Interactions.jsm, line 230: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIUserIdleService.removeIdleObserver]
selenium_1   | 15:00:49.452 INFO [ActiveSessions$1.onStop] - Removing session c3461b22-7a80-4b56-b177-653a53cc2651 (org.openqa.selenium.firefox.GeckoDriverService)
koha_1       |     # Looks like you planned 7 tests but ran 3.
koha_1       |
koha_1       | #   Failed test 'Enforce 2FA setup on first login'
koha_1       | #   at t/db_dependent/selenium/authentication_2fa.t line 294.
koha_1       | Error while executing command: element not interactable: Element <input id="pin_code" name="pin_code" type="text"> is not reachable by keyboard at /usr/share/perl5/Selenium/Remote/Driver.pm line 411.

The error is: "Element <input id="pin_code" name="pin_code" type="text"> is not reachable by keyboard"

A guess is that the input is either 1. outside of the viewport, or 2. not
displayed yet.

1. We are hidding #registration-form then show it when we retrieved the
   info (after POST /api/v1/auth/two-factor/registration)
2. Couldn't there be a race condition?
In auth.tt
284                     success: function (data) {
292                         $("#registration-form").show();
And in the selenium test:
$s->wait_for_ajax; # There is an ajax request to populate the qr_code and the secret
Not sure this wait_for_ajax is waiting for the end of success, I don't
think so.

This patch is supposed to fix both theories.

Test plan:
0. Do not apply the patch
1. Edit auth.tt and sleep 1 second before showing the form:
290                         const sleep = ms => new Promise(r => setTimeout(r, ms));
291                         await sleep(1000);
292                         $("#registration-form").show();

You will also need to replace the following line (284):
  success: function (data) {
with
  success: async function (data) {

2. prove t/db_dependent/selenium/authentication_2fa.t
=> "is not reachable by keyboard" error!

3. Apply the patch, keep the sleep

4. prove t/db_dependent/selenium/authentication_2fa.t
=> Tests are passing

Signed-off-by: David Nind <david@davidnind.com>
Comment 7 David Nind 2023-12-20 10:02:07 UTC
Testing notes:

1. If I add the async to line 284 of koha-tmpl/intranet-tmpl/prog/en/modules/auth.tt BEFORE applying the patch, the tests pass.

2. If I add async to line 284 of koha-tmpl/intranet-tmpl/prog/en/modules/auth.tt AFTER applying the patch, the tests pass.

I'm assuming 2 is what is required.
Comment 8 Jonathan Druart 2023-12-20 10:35:33 UTC
(In reply to David Nind from comment #7)
> Testing notes:
> 
> 1. If I add the async to line 284 of
> koha-tmpl/intranet-tmpl/prog/en/modules/auth.tt BEFORE applying the patch,
> the tests pass.
> 
> 2. If I add async to line 284 of
> koha-tmpl/intranet-tmpl/prog/en/modules/auth.tt AFTER applying the patch,
> the tests pass.
> 
> I'm assuming 2 is what is required.

On master:

diff --git a/koha-tmpl/intranet-tmpl/prog/en/modules/auth.tt b/koha-tmpl/intranet-tmpl/prog/en/modules/auth.tt
index 14e30e5e6e5..81ab5eac13d 100644
--- a/koha-tmpl/intranet-tmpl/prog/en/modules/auth.tt
+++ b/koha-tmpl/intranet-tmpl/prog/en/modules/auth.tt
@@ -281,12 +281,14 @@
                     data: {},
                     type: 'POST',
                     url: '/api/v1/auth/two-factor/registration',
-                    success: function (data) {
+                    success: async function (data) {
                         $("#qr_code").attr('src', data.qr_code);
                         $("#secret32").val(data.secret32);
                         $("#issuer").html(data.issuer);
                         $("#key_id").html(data.key_id);
                         $("#key_secret").html(data.secret32);
+                        const sleep = ms => new Promise(r => setTimeout(r, ms));
+                        await sleep(1000);
                         $("#registration-form").show();
                     },
                     error: function (data) {




$ prove t/db_dependent/selenium/authentication_2fa.t 
t/db_dependent/selenium/authentication_2fa.t .. 3/5 
STRACE: /usr/share/perl5/Try/Tiny.pm:123 in Selenium::Remote::Driver::catch {...} 
        /usr/share/perl5/Selenium/Remote/Driver.pm:361 in Try::Tiny::try
        (eval 582):1 in Selenium::Remote::Driver::__ANON__
        (eval 584):2 in Selenium::Remote::Driver::__ANON__
        (eval 556):17 in Selenium::Remote::Driver::_execute_command
        /usr/share/perl5/Selenium/Remote/WebElement.pm:125 in Selenium::Remote::WebElement::_execute_command
        t/db_dependent/selenium/authentication_2fa.t:276 in Selenium::Remote::WebElement::send_keys
        /usr/share/perl/5.32/Test/Builder.pm:334 in main::__ANON__
        /usr/share/perl/5.32/Test/Builder.pm:334 in (eval)
        /usr/share/perl/5.32/Test/More.pm:809 in Test::Builder::subtest
        t/db_dependent/selenium/authentication_2fa.t:294 in Test::More::subtest

    # Looks like you planned 7 tests but ran 3.
t/db_dependent/selenium/authentication_2fa.t .. 4/5 
#   Failed test 'Enforce 2FA setup on first login'
#   at t/db_dependent/selenium/authentication_2fa.t line 294.
Error while executing command: element not interactable: Element <input id="pin_code" name="pin_code" type="text"> is not reachable by keyboard at /usr/share/perl5/Selenium/Remote/Driver.pm line 411.
 at /usr/share/perl5/Selenium/Remote/Driver.pm line 356.
# Looks like your test exited with 255 just after 4.
Comment 9 Tomás Cohen Arazi 2023-12-20 15:15:17 UTC
Created attachment 160124 [details] [review]
Bug 35598: Fix selenium/authentication_2fa.t random failure

Jenkins is failing with
koha_1       | STRACE:	/usr/share/perl5/Try/Tiny.pm:123 in Selenium::Remote::Driver::catch {...}
koha_1       | 	/usr/share/perl5/Selenium/Remote/Driver.pm:361 in Try::Tiny::try
koha_1       | 	(eval 582):1 in Selenium::Remote::Driver::__ANON__
koha_1       | 	(eval 584):2 in Selenium::Remote::Driver::__ANON__
koha_1       | 	(eval 556):17 in Selenium::Remote::Driver::_execute_command
koha_1       | 	/usr/share/perl5/Selenium/Remote/WebElement.pm:125 in Selenium::Remote::WebElement::_execute_command
koha_1       | 	t/db_dependent/selenium/authentication_2fa.t:276 in Selenium::Remote::WebElement::send_keys
koha_1       | 	/usr/share/perl/5.32/Test/Builder.pm:334 in main::__ANON__
koha_1       | 	/usr/share/perl/5.32/Test/Builder.pm:334 in (eval)
koha_1       | 	/usr/share/perl/5.32/Test/More.pm:809 in Test::Builder::subtest
koha_1       | 	t/db_dependent/selenium/authentication_2fa.t:294 in Test::More::subtest
koha_1       |
selenium_1   | 1702911648831	Marionette	INFO	Stopped listening on port 41385
selenium_1   | JavaScript error: resource:///modules/Interactions.jsm, line 230: NS_ERROR_FAILURE: Component returned failure code: 0x80004005 (NS_ERROR_FAILURE) [nsIUserIdleService.removeIdleObserver]
selenium_1   | 15:00:49.452 INFO [ActiveSessions$1.onStop] - Removing session c3461b22-7a80-4b56-b177-653a53cc2651 (org.openqa.selenium.firefox.GeckoDriverService)
koha_1       |     # Looks like you planned 7 tests but ran 3.
koha_1       |
koha_1       | #   Failed test 'Enforce 2FA setup on first login'
koha_1       | #   at t/db_dependent/selenium/authentication_2fa.t line 294.
koha_1       | Error while executing command: element not interactable: Element <input id="pin_code" name="pin_code" type="text"> is not reachable by keyboard at /usr/share/perl5/Selenium/Remote/Driver.pm line 411.

The error is: "Element <input id="pin_code" name="pin_code" type="text"> is not reachable by keyboard"

A guess is that the input is either 1. outside of the viewport, or 2. not
displayed yet.

1. We are hidding #registration-form then show it when we retrieved the
   info (after POST /api/v1/auth/two-factor/registration)
2. Couldn't there be a race condition?
In auth.tt
284                     success: function (data) {
292                         $("#registration-form").show();
And in the selenium test:
$s->wait_for_ajax; # There is an ajax request to populate the qr_code and the secret
Not sure this wait_for_ajax is waiting for the end of success, I don't
think so.

This patch is supposed to fix both theories.

Test plan:
0. Do not apply the patch
1. Edit auth.tt and sleep 1 second before showing the form:
290                         const sleep = ms => new Promise(r => setTimeout(r, ms));
291                         await sleep(1000);
292                         $("#registration-form").show();

You will also need to replace the following line (284):
  success: function (data) {
with
  success: async function (data) {

2. prove t/db_dependent/selenium/authentication_2fa.t
=> "is not reachable by keyboard" error!

3. Apply the patch, keep the sleep

4. prove t/db_dependent/selenium/authentication_2fa.t
=> Tests are passing

Signed-off-by: David Nind <david@davidnind.com>
Signed-off-by: Tomas Cohen Arazi <tomascohen@theke.io>
Edit (tcohen): Tidied a bit to clear complaints
Comment 10 Katrin Fischer 2024-01-11 11:12:06 UTC
Pushed for 24.05!

Well done everyone, thank you!
Comment 11 Fridolin Somers 2024-01-15 13:29:18 UTC
Pushed to 23.11.x for 23.11.02
Comment 12 Lucas Gass 2024-01-19 20:55:01 UTC
Backported to 23.05.x for upcoming 23.05.08