action #78055
opencoordination #102906: [saga][epic] Increased stability of tests with less "known failures", known incompletes handled automatically within openQA
coordination #102909: [epic] Prevent more incompletes already within os-autoinst or openQA
job incomplete exiting prematurely before reaching needle check timeout auto_review:"(?s)called testapi::assert_screen.*no match: [^-0]+\.[0-9]s,[^\n]*\n[^\n]*backend process exited: 0.*\[autotest\] process exited: 1":retry
0%
Description
Observation¶
from https://openqa.opensuse.org/tests/1475943/file/autoinst-log.txt
[0m[37m[2020-11-16T20:54:50.111 CET] [debug] EVENT {"event":"RESUME","timestamp":{"microseconds":24962,"seconds":1605556490}}
[0m[37m[2020-11-16T20:54:51.036 CET] [debug] QEMU: QEMU emulator version 3.1.1 (openSUSE Leap 15.1)
[0m[37m[2020-11-16T20:54:51.041 CET] [debug] QEMU: Copyright (c) 2003-2018 Fabrice Bellard and the QEMU Project developers
[0m[37m[2020-11-16T20:54:56.157 CET] [debug] considering VNC stalled, no update for 5.88 seconds
[0mGOT GO
[37m[2020-11-16T20:55:29.985 CET] [debug] pointer type 1 0 800 600 -257
[0m[37m[2020-11-16T20:55:29.985 CET] [debug] led state 0 1 1 -261
[0m[37m[2020-11-16T20:55:29.994 CET] [debug] Snapshots are supported
[0m[1;34m[2020-11-16T20:55:30.027 CET] [debug] ||| starting setup_zdup tests/installation/setup_zdup.pm
[0m[2020-11-16T20:55:30.037 CET] [debug] tests/installation/setup_zdup.pm:25 called opensusebasetest::wait_boot -> lib/opensusebasetest.pm:1093 called opensusebasetest::handle_grub -> lib/opensusebasetest.pm:884 called opensusebasetest::wait_grub -> lib/opensusebasetest.pm:655 called testapi::assert_screen
[2020-11-16T20:55:30.039 CET] [debug] <<< testapi::assert_screen(mustmatch=[
"bootloader-shim-import-prompt",
"grub2",
"inst-bootmenu"
], timeout=300)
[37m[2020-11-16T20:55:31.745 CET] [debug] WARNING: check_asserted_screen took 1.69 seconds for 68 candidate needles - make your needles more specific
[0m[37m[2020-11-16T20:55:31.745 CET] [debug] no match: 599.9s, best candidate: bootloader-tw-salt_installer-20190111 (0.29)
[0m[37m[2020-11-16T20:55:31.862 CET] [debug] backend process exited: 0
[0m[37m[2020-11-16T20:55:31.869 CET] [debug] stopping command server 63134 because test execution ended
[0m[37m[2020-11-16T20:55:31.870 CET] [debug] isotovideo: informing websocket clients before stopping command server: http://127.0.0.1:20133/3JeipOHeAM4mQybM/broadcast
[0m[37m[2020-11-16T20:55:31.907 CET] [debug] Driver backend collected unknown process with pid 64306 and exit status: 0
[0m[37m[2020-11-16T20:55:35.815 CET] [debug] commands process exited: 0
[0m[37m[2020-11-16T20:55:35.919 CET] [debug] done with command server
[0m[37m[2020-11-16T20:55:35.922 CET] [debug] stopping autotest process 64169
[0m[37m[2020-11-16T20:55:35.927 CET] [debug] autotest received signal TERM, saving results of current test before exiting
[0m[37m[2020-11-16T20:55:35.968 CET] [debug] [autotest] process exited: 1
[0m[37m[2020-11-16T20:55:36.070 CET] [debug] done with autotest process
[0m[37m[2020-11-16T20:55:36.072 CET] [debug] isotovideo failed
[0m[37m[2020-11-16T20:55:36.094 CET] [debug] stopping backend process 64242
[0m[37m[2020-11-16T20:55:36.094 CET] [debug] done with backend process
[0m62899: EXIT 1
so the needle check that should run down to (around) 0.0s ends prematurely at "599.9s" listing a best candidate but did not check further. Like if the internal loop just exited after one cycle.
Workaround¶
Retrigger
Updated by okurz almost 4 years ago
- Subject changed from job incomplete exiting prematurely before reaching needle check timeout auto_review:"(?s)called testapi::assert_screen.*no match: [^-0]\.[0-9]s,.*\[autotest\] process exited: 1":retry to job incomplete exiting prematurely before reaching needle check timeout auto_review:"(?s)called testapi::assert_screen.*no match: [^-0]+\.[0-9]s,.*\[autotest\] process exited: 1":retry
Updated by okurz almost 4 years ago
- Copied to action #80776: [jeos] job incomplete auto_review:"(?s)(podman|docker).*Virtio terminal and svirt serial terminal do not support send_key":retry added
Updated by okurz almost 4 years ago
- Subject changed from job incomplete exiting prematurely before reaching needle check timeout auto_review:"(?s)called testapi::assert_screen.*no match: [^-0]+\.[0-9]s,.*\[autotest\] process exited: 1":retry to job incomplete exiting prematurely before reaching needle check timeout auto_review:"(?s)called testapi::assert_screen.*no match: [^-0]+\.[0-9]s,[^\n]*\n[^\n]*backend process exited: 0.*\[autotest\] process exited: 1":retry
matched on a bit too many jobs but found a better regex with looking for explicit line breaks with \n
so that we can match exactly on the following:
[2020-11-16T20:55:31.745 CET] [debug] no match: 599.9s, best candidate: bootloader-tw-salt_installer-20190111 (0.29)
[2020-11-16T20:55:31.862 CET] [debug] backend process exited: 0
where a line with "no match" and bigger timeout is followed directly by "backend process exited".