Project

General

Profile

Actions

action #128153

closed

[sporadic] typing issue in comments UI test t/15-comments.t size:M

Added by mkittler 11 months ago. Updated 11 months ago.

Status:
Resolved
Priority:
High
Assignee:
Category:
Regressions/Crashes
Target version:
Start date:
Due date:
% Done:

0%

Estimated time:

Description

Observation

Basically #121042 happened again:

[08:06:15] t/ui/15-comments.t ......................... 12/? executeScript: unexpected alert open: {Alert text : The comment text mustn't be empty.} at /home/squamata/project/t/ui/../lib/OpenQA/SeleniumTest.pm:81 at /home/squamata/project/t/ui/../lib/OpenQA/SeleniumTest.pm line 84.
    OpenQA::SeleniumTest::__ANON__(Test::Selenium::Chrome=HASH(0x55fd9e4ed3f0), "Error while executing command: executeScript: unexpected aler"..., HASH(0x55fd9e8b0e68), HASH(0x55fd9e8b4598)) called at /usr/lib/perl5/vendor_perl/5.26.1/Selenium/Remote/Driver.pm line 356
    Selenium::Remote::Driver::catch {...} ("Error while executing command: executeScript: unexpected aler"...) called at /usr/lib/perl5/vendor_perl/5.26.1/Try/Tiny.pm line 123
    Try::Tiny::try(CODE(0x55fd9e8b45b0), Try::Tiny::Catch=REF(0x55fd9e8cb4e8)) called at /usr/lib/perl5/vendor_perl/5.26.1/Selenium/Remote/Driver.pm line 361
    Selenium::Remote::Driver::__ANON__(CODE(0x55fd9e16d058), Test::Selenium::Chrome=HASH(0x55fd9e4ed3f0), HASH(0x55fd9e8b0e68), HASH(0x55fd9e8b4598)) called at (eval 1716)[/usr/lib/perl5/vendor_perl/5.26.1/Class/Method/Modifiers.pm:89] line 1
    Selenium::Remote::Driver::__ANON__(Test::Selenium::Chrome=HASH(0x55fd9e4ed3f0), HASH(0x55fd9e8b0e68), HASH(0x55fd9e8b4598)) called at (eval 1718)[/usr/lib/perl5/vendor_perl/5.26.1/Class/Method/Modifiers.pm:148] line 2
    Selenium::Remote::Driver::_execute_command(Test::Selenium::Chrome=HASH(0x55fd9e4ed3f0), HASH(0x55fd9e8b0e68), HASH(0x55fd9e8b4598)) called at /usr/lib/perl5/vendor_perl/5.26.1/Selenium/Remote/Driver.pm line 1053
    Selenium::Remote::Driver::execute_script(Test::Selenium::Chrome=HASH(0x55fd9e4ed3f0), "return window.jQuery \x{26}\x{26} jQuery.active === 0") called at /home/squamata/project/t/ui/../lib/OpenQA/SeleniumTest.pm line 163
    OpenQA::SeleniumTest::wait_for_ajax("msg", "comment with pinning for group added by regular user") called at t/ui/15-comments.t line 500
    main::__ANON__() called at /usr/lib/perl5/5.26.1/Test/Builder.pm line 309
    eval {...} called at /usr/lib/perl5/5.26.1/Test/Builder.pm line 309
    Test::Builder::subtest(Test::Builder=HASH(0x55fd91d79ba0), "group overview: /group_overview/1001", CODE(0x55fd9e8c7f00)) called at /usr/lib/perl5/5.26.1/Test/More.pm line 807
    Test::More::subtest("group overview: /group_overview/1001", CODE(0x55fd9e8c7f00)) called at t/ui/15-comments.t line 513
    main::__ANON__() called at /usr/lib/perl5/5.26.1/Test/Builder.pm line 309
    eval {...} called at /usr/lib/perl5/5.26.1/Test/Builder.pm line 309
    Test::Builder::subtest(Test::Builder=HASH(0x55fd91d79ba0), "editing when logged in as regular user", CODE(0x55fd9e88d808)) called at /usr/lib/perl5/5.26.1/Test/More.pm line 807
    Test::More::subtest("editing when logged in as regular user", CODE(0x55fd9e88d808)) called at t/ui/15-comments.t line 514

This is not the first time we've seen this issue. However, one can still say it happens only very rarely.

Acceptance criteria

  • AC1: Sporadic issue no longer appears

Suggestions

  • Use Circle CI ssh feature to debug (since it has not been replicated locally)
  • Ponder over the code/test again
  • Add a retry (one could consider this test as "unable" like we already do for some other tests or add the retry within the relevant section of the test itself)

Files

15-comments.pl (13.5 KB) 15-comments.pl mkittler, 2022-11-28 12:58
15-comments.pl (13.4 KB) 15-comments.pl mkittler, 2023-04-21 10:31

Related issues 2 (0 open2 closed)

Related to openQA Project - action #111542: [sporadic] openQA test t/ui/15-comments.t fails in 'heading text' size:MResolvedmkittler2022-05-24

Actions
Copied from openQA Project - action #121042: [sporadic] typing issue in comments UI test size:MResolvedkraih2022-11-282023-01-27

Actions
Actions #1

Updated by mkittler 11 months ago

Actions #2

Updated by mkittler 11 months ago

  • Priority changed from Normal to High

I've just seen it again:

[13:56:27] t/ui/15-comments.t ......................... 12/? executeScript: unexpected alert open: {Alert text : The comment text mustn't be empty.} at /home/squamata/project/t/ui/../lib/OpenQA/SeleniumTest.pm:81 at /home/squamata/project/t/ui/../lib/OpenQA/SeleniumTest.pm line 84.
    OpenQA::SeleniumTest::__ANON__(Test::Selenium::Chrome=HASH(0x55727f774520), "Error while executing command: executeScript: unexpected aler"..., HASH(0x55727f9c0f38), HASH(0x55727fb37b08)) called at /usr/lib/perl5/vendor_perl/5.26.1/Selenium/Remote/Driver.pm line 356
    Selenium::Remote::Driver::catch {...} ("Error while executing command: executeScript: unexpected aler"...) called at /usr/lib/perl5/vendor_perl/5.26.1/Try/Tiny.pm line 123
    Try::Tiny::try(CODE(0x55727c78d280), Try::Tiny::Catch=REF(0x55727fb307b8)) called at /usr/lib/perl5/vendor_perl/5.26.1/Selenium/Remote/Driver.pm line 361
    Selenium::Remote::Driver::__ANON__(CODE(0x55727ea68cf0), Test::Selenium::Chrome=HASH(0x55727f774520), HASH(0x55727f9c0f38), HASH(0x55727fb37b08)) called at (eval 1711)[/usr/lib/perl5/vendor_perl/5.26.1/Class/Method/Modifiers.pm:89] line 1
    Selenium::Remote::Driver::__ANON__(Test::Selenium::Chrome=HASH(0x55727f774520), HASH(0x55727f9c0f38), HASH(0x55727fb37b08)) called at (eval 1713)[/usr/lib/perl5/vendor_perl/5.26.1/Class/Method/Modifiers.pm:148] line 2
    Selenium::Remote::Driver::_execute_command(Test::Selenium::Chrome=HASH(0x55727f774520), HASH(0x55727f9c0f38), HASH(0x55727fb37b08)) called at /usr/lib/perl5/vendor_perl/5.26.1/Selenium/Remote/Driver.pm line 1053
    Selenium::Remote::Driver::execute_script(Test::Selenium::Chrome=HASH(0x55727f774520), "return window.jQuery \x{26}\x{26} jQuery.active === 0") called at /home/squamata/project/t/ui/../lib/OpenQA/SeleniumTest.pm line 163
    OpenQA::SeleniumTest::wait_for_ajax("msg", "comment with pinning for group added by regular user") called at t/ui/15-comments.t line 500
    main::__ANON__() called at /usr/lib/perl5/5.26.1/Test/Builder.pm line 309
    eval {...} called at /usr/lib/perl5/5.26.1/Test/Builder.pm line 309
    Test::Builder::subtest(Test::Builder=HASH(0x557273008a88), "group overview: /parent_group_overview/1", CODE(0x55727fb44b08)) called at /usr/lib/perl5/5.26.1/Test/More.pm line 807
    Test::More::subtest("group overview: /parent_group_overview/1", CODE(0x55727fb44b08)) called at t/ui/15-comments.t line 513
    main::__ANON__() called at /usr/lib/perl5/5.26.1/Test/Builder.pm line 309
    eval {...} called at /usr/lib/perl5/5.26.1/Test/Builder.pm line 309
    Test::Builder::subtest(Test::Builder=HASH(0x557273008a88), "editing when logged in as regular user", CODE(0x55727fb18b20)) called at /usr/lib/perl5/5.26.1/Test/More.pm line 807
    Test::More::subtest("editing when logged in as regular user", CODE(0x55727fb18b20)) called at t/ui/15-comments.t line 514
Actions #3

Updated by okurz 11 months ago

  • Due date deleted (2023-01-27)
  • Start date deleted (2022-11-28)
Actions #4

Updated by okurz 11 months ago

  • Status changed from New to Workable
Actions #5

Updated by mkittler 11 months ago

  • Category deleted (Regressions/Crashes)
  • Status changed from Workable to In Progress
  • Assignee set to mkittler
  • Target version deleted (Ready)
Actions #6

Updated by mkittler 11 months ago

  • Category set to Regressions/Crashes
  • Status changed from In Progress to Feedback
  • Target version set to Ready
Actions #7

Updated by okurz 11 months ago

  • Status changed from Feedback to Resolved

https://github.com/os-autoinst/openQA/pull/5095 PR merged. As this is about CI tests we can resolve right away as the tests passed in the PR. We can reopen if tests would fail again in the same or very similar way in CI tests.

Actions #9

Updated by mkittler 11 months ago

Looks like this hasn't worked, indeed:

[09:54:55] t/ui/15-comments.t ......................... 12/? executeScript: unexpected alert open: {Alert text : The comment text mustn't be empty.} at /home/squamata/project/t/ui/../lib/OpenQA/SeleniumTest.pm:81 at /home/squamata/project/t/ui/../lib/OpenQA/SeleniumTest.pm line 84.
    OpenQA::SeleniumTest::__ANON__(Test::Selenium::Chrome=HASH(0x55cd5d932780), "Error while executing command: executeScript: unexpected aler"..., HASH(0x55cd5de04360), HASH(0x55cd5de051e8)) called at /usr/lib/perl5/vendor_perl/5.26.1/Selenium/Remote/Driver.pm line 356
    Selenium::Remote::Driver::catch {...} ("Error while executing command: executeScript: unexpected aler"...) called at /usr/lib/perl5/vendor_perl/5.26.1/Try/Tiny.pm line 123
    Try::Tiny::try(CODE(0x55cd5dddda78), Try::Tiny::Catch=REF(0x55cd5de173d0)) called at /usr/lib/perl5/vendor_perl/5.26.1/Selenium/Remote/Driver.pm line 361
    Selenium::Remote::Driver::__ANON__(CODE(0x55cd5d22bf80), Test::Selenium::Chrome=HASH(0x55cd5d932780), HASH(0x55cd5de04360), HASH(0x55cd5de051e8)) called at (eval 1716)[/usr/lib/perl5/vendor_perl/5.26.1/Class/Method/Modifiers.pm:89] line 1
    Selenium::Remote::Driver::__ANON__(Test::Selenium::Chrome=HASH(0x55cd5d932780), HASH(0x55cd5de04360), HASH(0x55cd5de051e8)) called at (eval 1718)[/usr/lib/perl5/vendor_perl/5.26.1/Class/Method/Modifiers.pm:148] line 2
    Selenium::Remote::Driver::_execute_command(Test::Selenium::Chrome=HASH(0x55cd5d932780), HASH(0x55cd5de04360), HASH(0x55cd5de051e8)) called at /usr/lib/perl5/vendor_perl/5.26.1/Selenium/Remote/Driver.pm line 1053
    Selenium::Remote::Driver::execute_script(Test::Selenium::Chrome=HASH(0x55cd5d932780), "return window.jQuery \x{26}\x{26} jQuery.active === 0") called at /home/squamata/project/t/ui/../lib/OpenQA/SeleniumTest.pm line 163
    OpenQA::SeleniumTest::wait_for_ajax("msg", "comment with pinning for group added by regular user") called at t/ui/15-comments.t line 503
    main::__ANON__() called at /usr/lib/perl5/5.26.1/Test/Builder.pm line 309
    eval {...} called at /usr/lib/perl5/5.26.1/Test/Builder.pm line 309
    Test::Builder::subtest(Test::Builder=HASH(0x55cd512054a0), "group overview: /group_overview/1001", CODE(0x55cd5de07df8)) called at /usr/lib/perl5/5.26.1/Test/More.pm line 807
    Test::More::subtest("group overview: /group_overview/1001", CODE(0x55cd5de07df8)) called at t/ui/15-comments.t line 516
    main::__ANON__() called at /usr/lib/perl5/5.26.1/Test/Builder.pm line 309
    eval {...} called at /usr/lib/perl5/5.26.1/Test/Builder.pm line 309
    Test::Builder::subtest(Test::Builder=HASH(0x55cd512054a0), "editing when logged in as regular user", CODE(0x55cd5ddc6560)) called at /usr/lib/perl5/5.26.1/Test/More.pm line 807
    Test::More::subtest("editing when logged in as regular user", CODE(0x55cd5ddc6560)) called at t/ui/15-comments.t line 517
[09:54:55] t/ui/15-comments.t ......................... 13/? # Tests were run but no plan was declared and done_testing() was not seen.
[09:54:55] t/ui/15-comments.t .........................       Dubious, test returned 254 (wstat 65024, 0xfe00)
All 13 subtests passed

Considering the line number this test has already run with my most recent attempt to fix the problem. It is also one of the places that is covered. So there must still be some synchronization missing. I just don't know what it is at this point.

Actions #10

Updated by okurz 11 months ago

  • Subject changed from [sporadic] typing issue in comments UI test size:M to [sporadic] typing issue in comments UI test t/15-comments.t size:M
Actions #11

Updated by okurz 11 months ago

  • Status changed from Feedback to Workable
Actions #12

Updated by okurz 11 months ago

  • Related to action #111542: [sporadic] openQA test t/ui/15-comments.t fails in 'heading text' size:M added
Actions #13

Updated by mkittler 11 months ago

The code of the previously mentioned failure is:

500        wait_for_element(selector => '#text', description => 'comment form is displayed');
501        $driver->find_element_by_id('text')->send_keys($description_test_message);
502        $driver->find_element_by_id('submitComment')->click();
503        wait_for_ajax(msg => 'comment with pinning for group added by regular user');
504        $driver->get($group_url);

The line failing with an unexpected alert is 503 and is preceded by a typing + clicking. The element that is typed in is ensured to be there via wait_for_element. The clicking definitely works as this is provoking the alert. Apparently at the time of clicking nothing has been typed yet. So there must be a problem with the synchronization of the typing or the typing doesn't work at all.

In another place I've been using the following code when the alert is actually expected:

$driver->find_element_by_id('submitComment')->click;
eval { wait_for_ajax(msg => 'alert when trying to submit comment') };
like $@, qr/unexpected alert/, 'alert already shown shown when trying to wait for it' if $@;
like $driver->get_alert_text, qr/Invalid result 'new_result' for force_result/, 'error from server shown';
$driver->dismiss_alert;

Maybe this (very ugly) error-handling approach could be used here as well:

wait_for_element(selector => '#text', description => 'comment form is displayed');
$driver->find_element_by_id('text')->send_keys($description_test_message);  # maybe this should go into the loop? but then we'd also needed to clear the textarea in case the text would show up after all
for (;; $driver->dismiss_alert) {
    $driver->find_element_by_id('submitComment')->click();
    eval { wait_for_ajax(msg => 'comment with pinning for group added by regular user') };
    last unless my $error = $@;
    next if like $error, qr/unexpected alert.*The comment text mustn't be empty/, 'just encountered an "unexpected" alert';
    last;
}
$driver->get($group_url);

I'm a bit reluctant to add code like this; especially because I cannot verify it easily and it supposedly needed to go in various places.

Actions #14

Updated by okurz 11 months ago

I tried to do a web research about the topic a bit but no distinct answer.

  1. As you said that the text is not always typed correctly: Could it be that the text field is "visible" but not yet "interactable"? Maybe https://stackoverflow.com/a/57982102 or something equivalent help?
  2. Did you try to reproduce the problem locally, maybe with explicitly trying to trigger the condition?
  3. Do you know if there is a) no text at all, b) maybe only first character missing, c) some characters in the text missing or auto-replaced?
  4. How about waiting for the text to show up before clicking?

If all of the above yield no good solution then I would probably rewrite the code similar as in your last suggestion but:

wait_for_element(selector => '#text', description => 'comment form is displayed');
for (1..3) {
    $driver->find_element_by_id('text')->send_keys($description_test_message);
    $driver->find_element_by_id('submitComment')->click();
    eval { wait_for_ajax(msg => 'comment with pinning for group added by regular user') };
    last unless my $error = $@;
    die "Unexpected error found: $error" unless $error =~ qr/unexpected alert.*The comment text mustn't be empty/;
    $driver->dismiss_alert;
}
$driver->get($group_url);

so changes to your proposals are

  • Limit the amount of retries
  • Use test directives only in the deterministic execution path so that the number of actual test statements and according test progress messages are not impacted
  • Explicitly output the error if it is something different than the known "musn't be empty" case
Actions #15

Updated by mkittler 11 months ago

I've seen yet another occurrence. It was the exact same spot as in #128153#note-9.

Actions #16

Updated by mkittler 11 months ago

  • Status changed from Workable to Feedback
Actions #17

Updated by mkittler 11 months ago

  • Status changed from Feedback to Resolved

The PR has been merged and I've ran it 200 times locally without running into problems. If it occurs again after all we can still reopen the ticket (as we did in the past).

Actions

Also available in: Atom PDF