Project

General

Profile

Actions

action #78055

open

coordination #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

Added by okurz over 3 years ago. Updated over 2 years ago.

Status:
New
Priority:
Low
Assignee:
-
Category:
Regressions/Crashes
Target version:
Start date:
2020-11-16
Due date:
% Done:

0%

Estimated time:

Description

Observation

from https://openqa.opensuse.org/tests/1475943/file/autoinst-log.txt

[2020-11-16T20:54:50.111 CET] [debug] EVENT {"event":"RESUME","timestamp":{"microseconds":24962,"seconds":1605556490}}
[2020-11-16T20:54:51.036 CET] [debug] QEMU: QEMU emulator version 3.1.1 (openSUSE Leap 15.1)
[2020-11-16T20:54:51.041 CET] [debug] QEMU: Copyright (c) 2003-2018 Fabrice Bellard and the QEMU Project developers
[2020-11-16T20:54:56.157 CET] [debug] considering VNC stalled, no update for 5.88 seconds
GOT GO

[2020-11-16T20:55:29.985 CET] [debug] pointer type 1 0 800 600 -257
[2020-11-16T20:55:29.985 CET] [debug] led state 0 1 1 -261
[2020-11-16T20:55:29.994 CET] [debug] Snapshots are supported
[2020-11-16T20:55:30.027 CET] [debug] ||| starting setup_zdup tests/installation/setup_zdup.pm
[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)
[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
[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
[2020-11-16T20:55:31.869 CET] [debug] stopping command server 63134 because test execution ended
[2020-11-16T20:55:31.870 CET] [debug] isotovideo: informing websocket clients before stopping command server: http://127.0.0.1:20133/3JeipOHeAM4mQybM/broadcast
[2020-11-16T20:55:31.907 CET] [debug] Driver backend collected unknown process with pid 64306 and exit status: 0
[2020-11-16T20:55:35.815 CET] [debug] commands process exited: 0
[2020-11-16T20:55:35.919 CET] [debug] done with command server
[2020-11-16T20:55:35.922 CET] [debug] stopping autotest process 64169
[2020-11-16T20:55:35.927 CET] [debug] autotest received signal TERM, saving results of current test before exiting
[2020-11-16T20:55:35.968 CET] [debug] [autotest] process exited: 1
[2020-11-16T20:55:36.070 CET] [debug] done with autotest process
[2020-11-16T20:55:36.072 CET] [debug] isotovideo failed
[2020-11-16T20:55:36.094 CET] [debug] stopping backend process 64242
[2020-11-16T20:55:36.094 CET] [debug] done with backend process
62899: 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

Actions #1

Updated by okurz over 3 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
Actions #2

Updated by okurz over 3 years ago

  • Parent task set to #62420
Actions #4

Updated by okurz over 3 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".

Actions #5

Updated by okurz over 2 years ago

  • Parent task changed from #62420 to #102909
Actions

Also available in: Atom PDF