Actions
action #113396
closed[qe-core]test fails in logs_from_installation_system due to 'wait_countdown_stop' function doesn't work fine, performance issue?
Status:
Resolved
Priority:
Normal
Assignee:
Category:
Bugs in existing tests
Target version:
Start date:
2022-07-08
Due date:
% Done:
100%
Estimated time:
8.00 h
Difficulty:
Sprint:
QE-Core: July Sprint (Jul 06 - Aug 03)
Tags:
Description
Observation¶
openQA test in scenario sle-15-Server-DVD-Updates-aarch64-qam-minimal+base@aarch64-virtio fails in
logs_from_installation_system
Test suite description¶
Testsuite maintained at https://gitlab.suse.de/qa-maintenance/qam-openqa-yml.
Reproducible¶
Fails since (at least) Build 20220707-1
Expected result¶
Last good: 20220706-1 (or more recent)
Further details¶
Always latest result in this scenario: latest
ACTION¶
From the autoinst-log, I can see in test 'await_install',
'wait_countdown_stop' function has sent key "alt-s" to stop the reboot process there, however, it seems not work:
[2022-07-08T01:02:43.025678+02:00] [debug] tests/installation/await_install.pm:197 called await_install::wait_countdown_stop -> tests/installation/await_install.pm:45 called testapi::send_key
[2022-07-08T01:02:43.026211+02:00] [debug] <<< testapi::send_key(key="alt-s", do_wait=0, wait_screen_change=0)
[2022-07-08T01:02:43.369296+02:00] [debug] tests/installation/await_install.pm:197 called await_install::wait_countdown_stop -> tests/installation/await_install.pm:46 called testapi::wait_screen_change
[2022-07-08T01:02:43.370001+02:00] [debug] <<< testapi::wait_screen_change(timeout=3, similarity_level=50, similarity=55)
[2022-07-08T01:02:43.386041+02:00] [debug] waiting for screen change: 0 1000000
[2022-07-08T01:02:43.898563+02:00] [debug] waiting for screen change: 0 1000000
[2022-07-08T01:02:44.410907+02:00] [debug] waiting for screen change: 1 1000000
[2022-07-08T01:02:44.928192+02:00] [debug] waiting for screen change: 1 25.5385308432191
[2022-07-08T01:02:44.928592+02:00] [debug] >>> testapi::wait_screen_change: screen change seen at 1
[2022-07-08T01:02:44.929165+02:00] [debug] tests/installation/await_install.pm:198 called testapi::record_info
[2022-07-08T01:02:44.929691+02:00] [debug] <<< testapi::record_info(title="workaround", output="While trying to stop countdown we saw a screen change, retrying up to 9 times more", result="ok")
[2022-07-08T01:02:44.930634+02:00] [debug] tests/installation/await_install.pm:198 called await_install::wait_countdown_stop -> tests/installation/await_install.pm:45 called testapi::send_key
[2022-07-08T01:02:44.931027+02:00] [debug] <<< testapi::send_key(key="alt-s", do_wait=0, wait_screen_change=0)
[2022-07-08T01:02:45.270135+02:00] [debug] tests/installation/await_install.pm:198 called await_install::wait_countdown_stop -> tests/installation/await_install.pm:46 called testapi::wait_screen_change
[2022-07-08T01:02:45.270842+02:00] [debug] <<< testapi::wait_screen_change(timeout=3, similarity_level=50, similarity=55)
[2022-07-08T01:02:45.286134+02:00] [debug] waiting for screen change: 0 1000000
[2022-07-08T01:02:45.803449+02:00] [debug] waiting for screen change: 0 43.5021660349225
[2022-07-08T01:02:45.803865+02:00] [debug] >>> testapi::wait_screen_change: screen change seen at 0
[2022-07-08T01:02:45.804458+02:00] [debug] tests/installation/await_install.pm:198 called testapi::record_info
[2022-07-08T01:02:45.804969+02:00] [debug] <<< testapi::record_info(title="workaround", output="While trying to stop countdown we saw a screen change, retrying up to 8 times more", result="ok")
[2022-07-08T01:02:45.805881+02:00] [debug] tests/installation/await_install.pm:198 called await_install::wait_countdown_stop -> tests/installation/await_install.pm:45 called testapi::send_key
[2022-07-08T01:02:45.806285+02:00] [debug] <<< testapi::send_key(key="alt-s", do_wait=0, wait_screen_change=0)
[2022-07-08T01:02:46.144722+02:00] [debug] tests/installation/await_install.pm:198 called await_install::wait_countdown_stop -> tests/installation/await_install.pm:46 called testapi::wait_screen_change
[2022-07-08T01:02:46.145353+02:00] [debug] <<< testapi::wait_screen_change(timeout=3, similarity_level=50, similarity=55)
[2022-07-08T01:02:46.158213+02:00] [debug] waiting for screen change: 0 1000000
[2022-07-08T01:02:46.675674+02:00] [debug] waiting for screen change: 0 25.0089828516758
[2022-07-08T01:02:46.676107+02:00] [debug] >>> testapi::wait_screen_change: screen change seen at 0
[2022-07-08T01:02:46.676703+02:00] [debug] tests/installation/await_install.pm:198 called testapi::record_info
[2022-07-08T01:02:46.677217+02:00] [debug] <<< testapi::record_info(title="workaround", output="While trying to stop countdown we saw a screen change, retrying up to 7 times more", result="ok")
[2022-07-08T01:02:46.678186+02:00] [debug] tests/installation/await_install.pm:198 called await_install::wait_countdown_stop -> tests/installation/await_install.pm:45 called testapi::send_key
[2022-07-08T01:02:46.678636+02:00] [debug] <<< testapi::send_key(key="alt-s", wait_screen_change=0, do_wait=0)
[2022-07-08T01:02:47.016808+02:00] [debug] tests/installation/await_install.pm:198 called await_install::wait_countdown_stop -> tests/installation/await_install.pm:46 called testapi::wait_screen_change
[2022-07-08T01:02:47.017395+02:00] [debug] <<< testapi::wait_screen_change(timeout=3, similarity_level=50, similarity=55)
[2022-07-08T01:02:47.032559+02:00] [debug] waiting for screen change: 0 1000000
[2022-07-08T01:02:47.546980+02:00] [debug] waiting for screen change: 0 1000000
[2022-07-08T01:02:48.061593+02:00] [debug] waiting for screen change: 1 1000000
[2022-07-08T01:02:48.576185+02:00] [debug] waiting for screen change: 1 1000000
[2022-07-08T01:02:49.090664+02:00] [debug] waiting for screen change: 2 1000000
[2022-07-08T01:02:49.605189+02:00] [debug] waiting for screen change: 2 1000000
[2022-07-08T01:02:50.356651+02:00] [debug] >>> testapi::wait_screen_change: timed out
[2022-07-08T01:02:50.663053+02:00] [debug] ||| finished await_install installation (runtime: 804 s)
The issue can be seen in past 3 drops and rerun 1-2 times can be the workaround. however, I am wondering that the issue should have something to do with worker performance on aarch64 platform.
AC1: Increase the QEMURAM
AC2: Enhance the logic for function 'wait_countdown_stop' to make sure we can stop auto rebooting within 10s.
Actions