action #18924
closed[tools][sles][functional] test fails in grub_test - grub screen was not matched in time
Added by SLindoMansilla about 7 years ago. Updated almost 7 years ago.
0%
Description
Observation¶
openQA test in scenario sle-12-SP3-Server-DVD-ppc64le-textmode@ppc64le fails in
grub_test
The SUT rebooted too fast for autoinst to catch the GRUB screen and assert_screen timed out.
Reproducible¶
Sporadic
Failed in
- Build0365: osd#912073 (current job)
- Build0344: osd#890928
- Build0260: osd#795673
Cloning job into osd: osd#913259
Expected result¶
Last good: 0363 (or more recent)
Problem¶
The reasons are one or multiple of the following:
- H1: overloaded worker
- H2: too many needles to check in one go
- H3: test is suboptimal in general to rely on the one needle being found which could be missed
suggestions for improvements:
- S2-1: review used needles regarding "last match", remove or blacklist
- S3-1: As a fallback to grub2 not found look for generic-desktop or login prompt as last resort and reboot to try again
Further details¶
Always latest result in this scenario: latest
Workaround¶
Retrigger, sporadic
Updated by RBrownSUSE about 7 years ago
- Status changed from New to Feedback
Isn't this a product issue? The installer triggering a 'soft reboot' not a reinitialisation back to BIOS?
Updated by SLindoMansilla almost 7 years ago
- Category changed from Bugs in existing tests to Enhancement to existing tests
- Status changed from Feedback to New
I don't know how to determine if it is a product bug. For this reason I haven't created a bug ticket.
But since we had to have a black badge, I created this ticket for investigation purposes.
If I cannot provide information of the apparent bug to the developers, I should not create a product bug ticket, right?
I don't understand what you mean with 'a soft reboot'. Perhaps it is the construction of that English sentence.
What I understand reading it is: "The installer is triggering a soft reboot and that is wrong, because it should reinitialize back to BIOS."
If I know well, a soft reboot is simply rebooting a computer by software without removing the power source. So, a soft reboot should also reinitialize back to BIOS.
I have changed the category to express better the idea of this ticket, at least, we could improve the test to have more screenshots at this point and being able to determine the bug.
Updated by okurz almost 7 years ago
- Subject changed from [tools][sles][functional] test fails in grub_test - The SUT rebooted too fast for autoinst to catch the GRUB screen. to [tools][sles][functional] test fails in grub_test - grub screen was not matched in time
- Description updated (diff)
- Status changed from New to In Progress
Investigated further with slindomansilla. In https://openqa.suse.de/tests/912073#step/grub_test/2 we can see that the SUT ends up in the login prompt. So it seems the SUT behaves fine, we just missed the grub screen and get a "stall detected" warning by the backend.
Checking the logfile in the last good going back from the latest link we see that grub2-SLES-12SP3-OFW-20170303 was the needle that last matched so this is the one we are looking for. Suspecting that we missed the grub screen because of too long time between subsequent checks of the correct needle we looked into
$ curl -s https://openqa.suse.de/tests/933896/file/autoinst-log.txt | grep '\(alt-o\|MATCH(grub2-SLES-12SP3-OFW-20170303\)'
00:07:35.5255 52299 <<< testapi::send_key(key='alt-o')
00:07:36.6859 52305 MATCH(grub2-SLES-12SP3-OFW-20170303:0.00)
00:07:37.8772 52305 MATCH(grub2-SLES-12SP3-OFW-20170303:0.00)
00:07:39.9117 52305 MATCH(grub2-SLES-12SP3-OFW-20170303:0.00)
00:07:45.0357 52305 MATCH(grub2-SLES-12SP3-OFW-20170303:0.00)
00:08:04.3463 52305 MATCH(grub2-SLES-12SP3-OFW-20170303:0.00)
00:08:05.3389 52305 MATCH(grub2-SLES-12SP3-OFW-20170303:0.00)
…
See the time difference between subsequent checks. The duration can be as long as 9 seconds. During that time the grub screen could show up and vanish again before being matched.
Description updated with problem reasons and suggestions.
Updated by okurz almost 7 years ago
What we found is a lot of needles which should have been unregistered and some which don't make any sense at all, e.g. login_console-on-different-host-20160725.json which is looked for in tests with tag on_host_lower_than_sles_12_sp2 but it also has the tag grub2. comparing that to the name of the needle I guess everyone should get the point that this is very misleading.
Updated by okurz almost 7 years ago
- Assignee set to okurz
Updated by SLindoMansilla almost 7 years ago
Found same problem on another module: osd#938009#step/boot_to_desktop/3
Updated by okurz almost 7 years ago
- Related to action #19210: check_or_assert_screen should sort out duplicate needles on multiple tags added
Updated by okurz almost 7 years ago
https://github.com/os-autoinst/os-autoinst/pull/792 is another step to mitigate that problem.
Updated by okurz almost 7 years ago
Updated by okurz almost 7 years ago
- Has duplicate action #19252: [tools] SUT is to fast for wait_boot at initial startup (SLOF on QA-Power8 related?) added
Updated by nicksinger almost 7 years ago
- Follows action #19194: [tools] figure out why QA-Power8-5-kvm fails more than malbec added
Updated by nicksinger almost 7 years ago
- Has duplicate deleted (action #19252: [tools] SUT is to fast for wait_boot at initial startup (SLOF on QA-Power8 related?))
Updated by okurz almost 7 years ago
I checked http://openqa.suse.de/tests/958483. It was running on malbec, logs seem to be fine, no "stall" mentioned but still the grub screen seems to have been missed. And I looked closely for the times it took and then I found:
03:59:13.1423 38135 MATCH(bootloader-ofw-grub2-zdup-20151013:0.00)
03:59:13.2573 38135 MATCH(grub2-ofw-SP3-20161108:0.00)
03:59:13.9001 38135 MATCH(bootloader-ofw-12sp2-grub2-20170511:0.00)
03:59:14.5610 38135 MATCH(bootloader-ofw-12sp0-grub2-20170310:0.00)
03:59:15.2083 38135 MATCH(grub2-SLES-12SP3-OFW-20170303:0.00)
03:59:15.8555 38135 MATCH(bootloader-ofw-12sp2-grub2-20170317:0.00)
03:59:15.9696 38135 MATCH(bootloader-ofw-zdup-grub2-20151013:0.00)
03:59:16.6154 38135 MATCH(bootloader-ofw-12sp3-grub2-20170412:0.00)
03:59:17.2622 38135 MATCH(bootloader-ofw-12sp1-grub2-20151023:0.00)
03:59:17.3763 38135 MATCH(bootloader-ofw-grub2-zdup-20151013:0.00)
03:59:17.4908 38135 MATCH(bootloader-ofw-inst-bootmenu_on_local-20170511:0.00)
03:59:18.1335 38135 MATCH(bootloader-ofw-12sp2-grub2-20170511:0.00)
03:59:18.7943 38135 MATCH(bootloader-ofw-12sp0-grub2-20170310:0.00)
03:59:19.4417 38135 MATCH(grub2-SLES-12SP3-OFW-20170303:0.00)
03:59:20.0890 38135 MATCH(bootloader-ofw-12sp2-grub2-20170317:0.00)
03:59:20.2030 38135 MATCH(bootloader-ofw-20150724:0.00)
03:59:20.3170 38135 MATCH(bootloader-ofw-zdup-grub2-20151013:0.00)
03:59:20.9620 38135 MATCH(bootloader-ofw-12sp3-grub2-20170412:0.00)
03:59:21.6089 38135 MATCH(bootloader-ofw-12sp1-grub2-20151023:0.00)
03:59:21.7229 38135 MATCH(bootloader-ofw-inst-bootmenu_on_local-20170511:0.00)
03:59:21.8369 38135 MATCH(bootloader-ofw-20150724:0.00)
03:59:22.0151 38135 MATCH(inst-bootmenu-20160309:0.00)
03:59:22.0163 38135 WARNING: check_asserted_screen took 9.00 seconds - make your needles more specific
03:59:22.0169 38135 DEBUG_IO:
NAME TIME CUMULATIVE PERCENTAGE
Searching for needles 0.000 0.000 0.000%
**++ search__: get image 0.000 0.000 0.000%
**++ search__: areas exclusion 0.000 0.000 0.000%
**++ tinycv::search_needle 13x17x632 0.124 0.124 1.379%
**++ mean_square_error 0.000 0.124 0.002%
** search_: bootloader-ofw-grub2-zdup-20151013 0.000 0.124 0.000%
**++ search__: get image 0.000 0.124 0.000%
**++ search__: areas exclusion 0.000 0.124 0.000%
**++ tinycv::search_needle 13x17x632 0.115 0.239 1.276%
**++ mean_square_error 0.000 0.239 0.001%
** search_: grub2-ofw-SP3-20161108 0.000 0.239 0.000%
**++ search__: get image 0.000 0.239 0.000%
**++ search__: areas exclusion 0.000 0.239 0.000%
**++ tinycv::search_needle 209x28x84 0.315 0.555 3.506%
**++ tinycv::search_needle 26x75x98 0.327 0.882 3.637%
**++ mean_square_error 0.000 0.882 0.001%
** search_: bootloader-ofw-12sp2-grub2-20170511 0.000 0.882 0.000%
**++ search__: get image 0.000 0.882 0.000%
**++ search__: areas exclusion 0.000 0.882 0.000%
**++ tinycv::search_needle 215x30x80 0.320 1.202 3.558%
**++ tinycv::search_needle 24x80x57 0.341 1.543 3.785%
**++ mean_square_error 0.000 1.543 0.001%
** search_: bootloader-ofw-12sp0-grub2-20170310 0.000 1.543 0.000%
**++ search__: get image 0.000 1.543 0.000%
**++ search__: areas exclusion 0.000 1.543 0.000%
**++ tinycv::search_needle 217x28x84 0.320 1.863 3.560%
**++ tinycv::search_needle 26x75x98 0.327 2.190 3.632%
**++ mean_square_error 0.000 2.190 0.001%
** search_: grub2-SLES-12SP3-OFW-20170303 0.000 2.190 0.000%
**++ search__: get image 0.000 2.190 0.000%
**++ search__: areas exclusion 0.000 2.190 0.000%
**++ tinycv::search_needle 217x28x84 0.320 2.511 3.561%
**++ tinycv::search_needle 26x75x98 0.327 2.837 3.632%
**++ mean_square_error 0.000 2.838 0.001%
** search_: bootloader-ofw-12sp2-grub2-20170317 0.000 2.838 0.000%
**++ search__: get image 0.000 2.838 0.000%
**++ search__: areas exclusion 0.000 2.838 0.000%
**++ tinycv::search_needle 13x17x632 0.114 2.951 1.267%
**++ mean_square_error 0.000 2.952 0.001%
** search_: bootloader-ofw-zdup-grub2-20151013 0.000 2.952 0.000%
**++ search__: get image 0.000 2.952 0.000%
**++ search__: areas exclusion 0.000 2.952 0.000%
**++ tinycv::search_needle 214x30x81 0.319 3.270 3.541%
**++ tinycv::search_needle 25x95x96 0.327 3.597 3.635%
**++ mean_square_error 0.000 3.597 0.001%
** search_: bootloader-ofw-12sp3-grub2-20170412 0.000 3.597 0.000%
**++ search__: get image 0.000 3.597 0.000%
**++ search__: areas exclusion 0.000 3.597 0.000%
**++ tinycv::search_needle 214x30x81 0.318 3.915 3.531%
**++ tinycv::search_needle 25x79x96 0.329 4.244 3.657%
**++ mean_square_error 0.000 4.244 0.001%
** search_: bootloader-ofw-12sp1-grub2-20151023 0.000 4.244 0.000%
**++ search__: get image 0.000 4.244 0.000%
**++ search__: areas exclusion 0.000 4.244 0.000%
**++ tinycv::search_needle 13x17x632 0.114 4.358 1.267%
**++ mean_square_error 0.000 4.358 0.001%
** search_: bootloader-ofw-grub2-zdup-20151013 0.000 4.358 0.000%
**++ search__: get image 0.000 4.358 0.000%
**++ search__: areas exclusion 0.000 4.358 0.000%
**++ tinycv::search_needle 13x69x632 0.114 4.473 1.271%
**++ mean_square_error 0.000 4.473 0.001%
** search_: bootloader-ofw-inst-bootmenu_on_local-20170511 0.000 4.473 0.000%
**++ search__: get image 0.000 4.473 0.000%
**++ search__: areas exclusion 0.000 4.473 0.000%
**++ tinycv::search_needle 209x28x84 0.316 4.789 3.510%
**++ tinycv::search_needle 26x75x98 0.327 5.115 3.632%
**++ mean_square_error 0.000 5.115 0.001%
** search_: bootloader-ofw-12sp2-grub2-20170511 0.000 5.115 0.000%
**++ search__: get image 0.000 5.115 0.000%
**++ search__: areas exclusion 0.000 5.115 0.000%
**++ tinycv::search_needle 215x30x80 0.320 5.436 3.559%
**++ tinycv::search_needle 24x80x57 0.340 5.776 3.783%
**++ mean_square_error 0.000 5.776 0.001%
** search_: bootloader-ofw-12sp0-grub2-20170310 0.000 5.776 0.000%
**++ search__: get image 0.000 5.776 0.000%
**++ search__: areas exclusion 0.000 5.776 0.000%
**++ tinycv::search_needle 217x28x84 0.320 6.097 3.561%
**++ tinycv::search_needle 26x75x98 0.327 6.424 3.633%
**++ mean_square_error 0.000 6.424 0.001%
** search_: grub2-SLES-12SP3-OFW-20170303 0.000 6.424 0.000%
**++ search__: get image 0.000 6.424 0.000%
**++ search__: areas exclusion 0.000 6.424 0.000%
**++ tinycv::search_needle 217x28x84 0.320 6.744 3.561%
**++ tinycv::search_needle 26x75x98 0.327 7.071 3.632%
**++ mean_square_error 0.000 7.071 0.001%
** search_: bootloader-ofw-12sp2-grub2-20170317 0.000 7.071 0.000%
**++ search__: get image 0.000 7.071 0.000%
**++ search__: areas exclusion 0.000 7.071 0.000%
**++ tinycv::search_needle 13x69x632 0.114 7.185 1.266%
**++ mean_square_error 0.000 7.185 0.001%
** search_: bootloader-ofw-20150724 0.000 7.185 0.000%
**++ search__: get image 0.000 7.185 0.000%
**++ search__: areas exclusion 0.000 7.185 0.000%
**++ tinycv::search_needle 13x17x632 0.114 7.299 1.266%
**++ mean_square_error 0.000 7.299 0.001%
** search_: bootloader-ofw-zdup-grub2-20151013 0.000 7.299 0.000%
**++ search__: get image 0.000 7.299 0.000%
**++ search__: areas exclusion 0.000 7.299 0.000%
**++ tinycv::search_needle 214x30x81 0.318 7.617 3.531%
**++ tinycv::search_needle 25x95x96 0.327 7.944 3.636%
**++ mean_square_error 0.000 7.944 0.001%
** search_: bootloader-ofw-12sp3-grub2-20170412 0.000 7.944 0.000%
**++ search__: get image 0.000 7.944 0.000%
**++ search__: areas exclusion 0.000 7.944 0.000%
**++ tinycv::search_needle 214x30x81 0.318 8.262 3.532%
**++ tinycv::search_needle 25x79x96 0.329 8.591 3.657%
**++ mean_square_error 0.000 8.591 0.001%
** search_: bootloader-ofw-12sp1-grub2-20151023 0.000 8.591 0.000%
**++ search__: get image 0.000 8.591 0.000%
**++ search__: areas exclusion 0.000 8.591 0.000%
**++ tinycv::search_needle 13x69x632 0.114 8.705 1.266%
**++ mean_square_error 0.000 8.705 0.001%
** search_: bootloader-ofw-inst-bootmenu_on_local-20170511 0.000 8.705 0.000%
**++ search__: get image 0.000 8.705 0.000%
**++ search__: areas exclusion 0.000 8.705 0.000%
**++ tinycv::search_needle 13x69x632 0.114 8.819 1.265%
**++ mean_square_error 0.000 8.819 0.001%
** search_: bootloader-ofw-20150724 0.000 8.819 0.000%
**++ search__: get image 0.000 8.819 0.000%
**++ search__: areas exclusion 0.000 8.819 0.000%
**++ tinycv::search_needle 149x71x351 0.178 8.997 1.980%
**++ mean_square_error 0.000 8.997 0.001%
** search_: inst-bootmenu-20160309 0.000 8.997 0.000%
_stop_ 0.000 8.997 0.003%
03:59:22.0170 38135 no match: 75.0s
so very well explainable why the grub screen has been missed. I see the biggest problem in the infrastructure but I don't know how to read the above logs. Who can help?
Anyway for workarounds I have two ideas what could be changed. Because basically we want to see the grub screen "just to be sure" and then press ret not to waste time. So we could either repeatedly press a key from the start until we see the grub screen or use a check_screen instead and if we did not find a grub screen but the display manager we would just accept this as ok as well.
Updated by RBrownSUSE almost 7 years ago
- Status changed from In Progress to Resolved