action #121042
[sporadic] typing issue in comments UI test size:M
0%
Description
Observation¶
[12:42:18] t/ui/15-comments.t ......................... 12/? get: 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(0x55cbb5d49500), "Error while executing command: get: unexpected alert open: {A"..., HASH(0x55cbb2ea54f0), HASH(0x55cbb621f7c0)) called at /usr/lib/perl5/vendor_perl/5.26.1/Selenium/Remote/Driver.pm line 356 Selenium::Remote::Driver::catch {...} ("Error while executing command: get: unexpected alert open: {A"...) called at /usr/lib/perl5/vendor_perl/5.26.1/Try/Tiny.pm line 123 Try::Tiny::try(CODE(0x55cbb6206820), Try::Tiny::Catch=REF(0x55cbb61f4f10)) called at /usr/lib/perl5/vendor_perl/5.26.1/Selenium/Remote/Driver.pm line 361 Selenium::Remote::Driver::__ANON__(CODE(0x55cbb5ac8590), Test::Selenium::Chrome=HASH(0x55cbb5d49500), HASH(0x55cbb2ea54f0), HASH(0x55cbb621f7c0)) called at (eval 1713)[/usr/lib/perl5/vendor_perl/5.26.1/Class/Method/Modifiers.pm:89] line 1 Selenium::Remote::Driver::__ANON__(Test::Selenium::Chrome=HASH(0x55cbb5d49500), HASH(0x55cbb2ea54f0), HASH(0x55cbb621f7c0)) called at (eval 1715)[/usr/lib/perl5/vendor_perl/5.26.1/Class/Method/Modifiers.pm:148] line 2 Selenium::Remote::Driver::_execute_command(Test::Selenium::Chrome=HASH(0x55cbb5d49500), HASH(0x55cbb2ea54f0), HASH(0x55cbb621f7c0)) called at /usr/lib/perl5/vendor_perl/5.26.1/Selenium/Remote/Driver.pm line 946 Selenium::Remote::Driver::get(Test::Selenium::Chrome=HASH(0x55cbb5d49500), "/group_overview/1001") called at t/ui/15-comments.t line 493 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(0x55cba96c1160), "group overview: /group_overview/1001", CODE(0x55cbb61ec710)) called at /usr/lib/perl5/5.26.1/Test/More.pm line 807 Test::More::subtest("group overview: /group_overview/1001", CODE(0x55cbb61ec710)) called at t/ui/15-comments.t line 505 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(0x55cba96c1160), "editing when logged in as regular user", CODE(0x55cbb61e0128)) called at /usr/lib/perl5/5.26.1/Test/More.pm line 807 Test::More::subtest("editing when logged in as regular user", CODE(0x55cbb61e0128)) called at t/ui/15-comments.t line 506 [12:42:18] t/ui/15-comments.t ......................... 13/? # Tests were run but no plan was declared and done_testing() was not seen. [12:42:18] t/ui/15-comments.t ......................... Dubious, test returned 254 (wstat 65024, 0xfe00) All 13 subtests passed
I've encountered it only once so far and retrying helped. Likely 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)
History
#3
Updated by robert.richardson 2 months ago
- Subject changed from [sporadic] typing issue in comments UI test to [sporadic] typing issue in comments UI test size:M
- Description updated (diff)
- Status changed from New to Workable
#6
Updated by mkittler 2 months ago
The relevant code is (and we have similar code in various other places within that test):
$driver->find_element_by_id('text')->send_keys($description_test_message); $driver->find_element_by_id('submitComment')->click(); # alert shows up as if previous call didn't send any keys to the text area $driver->get($group_url); # problem is surfacing here as we can't change the page without dismissing the alert first
$description_test_message
is definitely not empty.- The ID
text
is really unique on the page. - Nevertheless the button click (that basically invokes some JavaScript to be executed) leads to a JavaScript-alert complaining that the textarea
text
is empty.
So I have no idea why that would sometimes not work. send_keys
is expected to be a synchronous call, right? In addition:
- The textarea
text
is a plain text area (without JavaScript event handlers on key strokes or the like). So typing should really not be broken. - If
text
wouldn't exist from the beginning than$driver->find_element_by_id('text')
would return an error. - If
text
was hidden andsend_keys
would therefore refuse to send keys we'd get an error. - I see no way that
text
would be swapped out in the middle. This is the form to submit a new comment and that's not messed with dynamically in our JavaScript code.
Maybe this is a bug in Selenium/chromedriver? It is not like those were still well maintained and we experienced bugs before.
Not sure what to do? Since I've only saw it once so far (and we have this code without any significant modifications in-place for ages) I'd say that doesn't even justifying to mark this test as unstable (it currently isn't marked unstable).
#7
Updated by okurz 2 months ago
mkittler wrote:
Not sure what to do? Since I've only saw it once so far (and we have this code without any significant modifications in-place for ages) I'd say that doesn't even justifying to mark this test as unstable (it currently isn't marked unstable).
I agree. Albeit some ideas you could try if you like:
- Repeatedly (infinitely) run the "find…send_keys…click" test code section to try to reproduce it more easily
- Implement retry in the test, like a for-loop or something, just in case we run into the problem again
#8
Updated by cdywan 2 months ago
Apparently mkittler is still planning to work on this, so I'll just add my initial thoughts here. I noticed the wait_for_ajax after submitComment->click won't ensure all elements are in place. That can mean the page is not in a consistent state when it returns. Although it "should" be caught by the check that comments can be edited. In general the test seems slow to me, even when running it locally - maybe that can cause problems on low-powered machines?
#9
Updated by mkittler 2 months ago
I noticed the wait_for_ajax after submitComment->click won't ensure all elements are in place.
A wait_for_ajax
should be sufficient considering we reload the page anyways. The important part is that the AJAX request is done, not that any elements show up on the page (which we reload anyways). However, in the concrete place this ticket is about there's not even a wait_for_ajax
. I've created a PR to fix that: https://github.com/os-autoinst/openQA/pull/4944
The missing wait_for_ajax
could not be the reason for the problem we see here, though. That the AJAX request isn't happening in the first place and that we instead get an alert is the problem.
#10
Updated by mkittler 2 months ago
Repeatedly (infinitely) run the "find…send_keys…click" test code section to try to reproduce it more easily
When I reproduce the issue, then what? This doesn't really help solving the conundrum and thus doesn't help fixing the issue.
Implement retry in the test, like a for-loop or something, just in case we run into the problem again
There are many places where we have code like this. Only fixing one of them seems odd and might not help when the same issue next time occurs on a different place.
I'm unassigning. Maybe someone else has an idea what the problem is.
#12
Updated by kraih about 2 months ago
- Assignee set to kraih
I'll take a look, but will put the ticket back into the queue if i can't find a solution before my vacation.
#13
Updated by kraih about 2 months ago
mkittler wrote:
So I have no idea why that would sometimes not work.
send_keys
is expected to be a synchronous call, right?
That seems to be defined in the WebDriver spec here and how i understand it too.
#14
Updated by kraih about 2 months ago
- Assignee deleted (
kraih)
I've been unable to replicate it in a Circle CI ssh session unfortunately, and didn't see anything obvious in the code.
#15
Updated by kraih about 1 month ago
- Assignee set to kraih
Since nobody else has made progress and this is still high priority, maybe i'll try looking a bit closer at the code.
#16
Updated by kraih about 1 month ago
- Status changed from Workable to In Progress
#17
Updated by openqa_review about 1 month ago
- Due date set to 2023-01-20
Setting due date based on mean cycle time of SUSE QE Tools
#18
Updated by kraih 27 days ago
Just saw it happen for the first time, so for me it's like 1 in 100 test runs now:
t/ui/15-comments.t .. 12/? executeScript: unexpected alert open: {Alert text : The comment text mustn't be empty.} at /home/sri/work/openQA/repos/openQA/t/ui/../lib/OpenQA/SeleniumTest.pm:81 at /home/sri/work/openQA/repos/openQA/t/ui/../lib/OpenQA/SeleniumTest.pm line 84. OpenQA::SeleniumTest::__ANON__(Test::Selenium::Chrome=HASH(0xaaab02c0b658), "Error while executing command: executeScript: unexpected aler"..., HASH(0xaaab02f5d5a0), HASH(0xaaab02f81f40)) called at /usr/lib/perl5/vendor_perl/5.36.0/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.36.0/Try/Tiny.pm line 123 Try::Tiny::try(CODE(0xaaab02f6b068), Try::Tiny::Catch=REF(0xaaab02f69378)) called at /usr/lib/perl5/vendor_perl/5.36.0/Selenium/Remote/Driver.pm line 361 Selenium::Remote::Driver::__ANON__(CODE(0xaaab029a9b18), Test::Selenium::Chrome=HASH(0xaaab02c0b658), HASH(0xaaab02f5d5a0), HASH(0xaaab02f81f40)) called at (eval 1774) line 1 Selenium::Remote::Driver::__ANON__(Test::Selenium::Chrome=HASH(0xaaab02c0b658), HASH(0xaaab02f5d5a0), HASH(0xaaab02f81f40)) called at (eval 1776) line 2 Selenium::Remote::Driver::_execute_command(Test::Selenium::Chrome=HASH(0xaaab02c0b658), HASH(0xaaab02f5d5a0), HASH(0xaaab02f81f40)) called at /usr/lib/perl5/vendor_perl/5.36.0/Selenium/Remote/Driver.pm line 1058 Selenium::Remote::Driver::execute_script(Test::Selenium::Chrome=HASH(0xaaab02c0b658), "return window.jQuery && jQuery.active === 0") called at /home/sri/work/openQA/repos/openQA/t/ui/../lib/OpenQA/SeleniumTest.pm line 163 OpenQA::SeleniumTest::wait_for_ajax("msg", "comment for job 99938 added by regular user") called at t/ui/15-comments.t line 476 main::__ANON__() called at /usr/lib/perl5/5.36.0/Test/Builder.pm line 374 eval {...} called at /usr/lib/perl5/5.36.0/Test/Builder.pm line 374 Test::Builder::subtest(Test::Builder=HASH(0xaaaaf7fd4300), "test results", CODE(0xaaab02c0b000)) called at /usr/lib/perl5/5.36.0/Test/More.pm line 809 Test::More::subtest("test results", CODE(0xaaab02c0b000)) called at t/ui/15-comments.t line 479 main::__ANON__() called at /usr/lib/perl5/5.36.0/Test/Builder.pm line 374 eval {...} called at /usr/lib/perl5/5.36.0/Test/Builder.pm line 374 Test::Builder::subtest(Test::Builder=HASH(0xaaaaf7fd4300), "editing when logged in as regular user", CODE(0xaaab02f50178)) called at /usr/lib/perl5/5.36.0/Test/More.pm line 809 Test::More::subtest("editing when logged in as regular user", CODE(0xaaab02f50178)) called at t/ui/15-comments.t line 507 # Tests were run but no plan was declared and done_testing() was not seen. t/ui/15-comments.t .. Dubious, test returned 254 (wstat 65024, 0xfe00) All 13 subtests passed Test Summary Report ------------------- t/ui/15-comments.t (Wstat: 65024 (exited 254) Tests: 13 Failed: 0) Non-zero exit status: 254 Parse errors: No plan found in TAP output Files=1, Tests=13, 21 wallclock secs ( 0.02 usr 0.01 sys + 2.48 cusr 0.29 csys = 2.80 CPU) Result: FAIL
It was in a different place than the original problem though, which suggests that it can happen for all similar comment submits in the test.
#19
Updated by kraih 27 days ago
Two cases in about 300 test runs, same line as before:
t/ui/15-comments.t .. 12/? executeScript: unexpected alert open: {Alert text : The comment text mustn't be empty.} at /home/sri/work/openQA/repos/openQA/t/ui/../lib/OpenQA/SeleniumTest.pm:81 at /home/sri/work/openQA/repos/openQA/t/ui/../lib/OpenQA/SeleniumTest.pm line 84. OpenQA::SeleniumTest::__ANON__(Test::Selenium::Chrome=HASH(0xaaab106162b0), "Error while executing command: executeScript: unexpected aler"..., HASH(0xaaab10979088), HASH(0xaaab10962f40)) called at /usr/lib/perl5/vendor_perl/5.36.0/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.36.0/Try/Tiny.pm line 123 Try::Tiny::try(CODE(0xaaab10985368), Try::Tiny::Catch=REF(0xaaab10984d80)) called at /usr/lib/perl5/vendor_perl/5.36.0/Selenium/Remote/Driver.pm line 361 Selenium::Remote::Driver::__ANON__(CODE(0xaaab1015e370), Test::Selenium::Chrome=HASH(0xaaab106162b0), HASH(0xaaab10979088), HASH(0xaaab10962f40)) called at (eval 1768) line 1 Selenium::Remote::Driver::__ANON__(Test::Selenium::Chrome=HASH(0xaaab106162b0), HASH(0xaaab10979088), HASH(0xaaab10962f40)) called at (eval 1770) line 2 Selenium::Remote::Driver::_execute_command(Test::Selenium::Chrome=HASH(0xaaab106162b0), HASH(0xaaab10979088), HASH(0xaaab10962f40)) called at /usr/lib/perl5/vendor_perl/5.36.0/Selenium/Remote/Driver.pm line 1058 Selenium::Remote::Driver::execute_script(Test::Selenium::Chrome=HASH(0xaaab106162b0), "return window.jQuery && jQuery.active === 0") called at /home/sri/work/openQA/repos/openQA/t/ui/../lib/OpenQA/SeleniumTest.pm line 163 OpenQA::SeleniumTest::wait_for_ajax("msg", "comment for job 99938 added by regular user") called at t/ui/15-comments.t line 476 main::__ANON__() called at /usr/lib/perl5/5.36.0/Test/Builder.pm line 374 eval {...} called at /usr/lib/perl5/5.36.0/Test/Builder.pm line 374 Test::Builder::subtest(Test::Builder=HASH(0xaaab059e4b70), "test results", CODE(0xaaab10992618)) called at /usr/lib/perl5/5.36.0/Test/More.pm line 809 Test::More::subtest("test results", CODE(0xaaab10992618)) called at t/ui/15-comments.t line 479 main::__ANON__() called at /usr/lib/perl5/5.36.0/Test/Builder.pm line 374 eval {...} called at /usr/lib/perl5/5.36.0/Test/Builder.pm line 374 Test::Builder::subtest(Test::Builder=HASH(0xaaab059e4b70), "editing when logged in as regular user", CODE(0xaaab1095dd08)) called at /usr/lib/perl5/5.36.0/Test/More.pm line 809 Test::More::subtest("editing when logged in as regular user", CODE(0xaaab1095dd08)) called at t/ui/15-comments.t line 507 # Tests were run but no plan was declared and done_testing() was not seen. t/ui/15-comments.t .. Dubious, test returned 254 (wstat 65024, 0xfe00) All 13 subtests passed Test Summary Report ------------------- t/ui/15-comments.t (Wstat: 65024 (exited 254) Tests: 13 Failed: 0) Non-zero exit status: 254 Parse errors: No plan found in TAP output Files=1, Tests=13, 20 wallclock secs ( 0.03 usr 0.00 sys + 2.53 cusr 0.25 csys = 2.81 CPU) Result: FAIL
All attempts to manually trigger the problem still unsuccessful.
#20
Updated by kraih 26 days ago
Had the test pass 600 times with the change from this PR: https://github.com/os-autoinst/openQA/pull/4978
#23
Updated by mkittler 25 days ago
I've just seen it again in a CI run of https://github.com/os-autoinst/openQA/pull/4980: https://app.circleci.com/pipelines/github/os-autoinst/openQA/10868/workflows/0ace4fb7-95fc-473b-8130-fc20fb0c2cbe/jobs/101774
[11:35:50] 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(0x55e95e152b00), "Error while executing command: executeScript: unexpected aler"..., HASH(0x55e95e61ebd8), HASH(0x55e95e5f4368)) 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(0x55e95e5ef618), Try::Tiny::Catch=REF(0x55e95e5fae30)) called at /usr/lib/perl5/vendor_perl/5.26.1/Selenium/Remote/Driver.pm line 361 Selenium::Remote::Driver::__ANON__(CODE(0x55e95dc905b8), Test::Selenium::Chrome=HASH(0x55e95e152b00), HASH(0x55e95e61ebd8), HASH(0x55e95e5f4368)) called at (eval 1708)[/usr/lib/perl5/vendor_perl/5.26.1/Class/Method/Modifiers.pm:89] line 1 Selenium::Remote::Driver::__ANON__(Test::Selenium::Chrome=HASH(0x55e95e152b00), HASH(0x55e95e61ebd8), HASH(0x55e95e5f4368)) called at (eval 1710)[/usr/lib/perl5/vendor_perl/5.26.1/Class/Method/Modifiers.pm:148] line 2 Selenium::Remote::Driver::_execute_command(Test::Selenium::Chrome=HASH(0x55e95e152b00), HASH(0x55e95e61ebd8), HASH(0x55e95e5f4368)) 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(0x55e95e152b00), "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 494 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(0x55e951b4b9a8), "group overview: /group_overview/1001", CODE(0x55e95e5f6df8)) called at /usr/lib/perl5/5.26.1/Test/More.pm line 807 Test::More::subtest("group overview: /group_overview/1001", CODE(0x55e95e5f6df8)) called at t/ui/15-comments.t line 507 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(0x55e951b4b9a8), "editing when logged in as regular user", CODE(0x55e95e5e66c8)) called at /usr/lib/perl5/5.26.1/Test/More.pm line 807 Test::More::subtest("editing when logged in as regular user", CODE(0x55e95e5e66c8)) called at t/ui/15-comments.t line 508 [11:35:50] t/ui/15-comments.t ......................... 13/? # Tests were run but no plan was declared and done_testing() was not seen. [11:35:50] t/ui/15-comments.t ......................... Dubious, test returned 254 (wstat 65024, 0xfe00)
This PRs branch is up-to-date and thus contains 3266e22545f3a03272995171ac489db55f9efb9d from https://github.com/os-autoinst/openQA/pull/4978.
#24
Updated by kraih 17 days ago
As expected, the case Marius encountered is for a different line. It's almost the exact same test code, so the same fix should work there as well. https://github.com/os-autoinst/openQA/pull/4984
#27
Updated by cdywan 16 days ago
- Due date changed from 2023-01-20 to 2023-01-27
kraih wrote:
As expected, the case Marius encountered is for a different line. It's almost the exact same test code, so the same fix should work there as well. https://github.com/os-autoinst/openQA/pull/4984
This is due today, but given the time it took before I think we need to monitor this another week.