action #67120
Updated by riafarov almost 4 years ago
## Observation
Related to this change: https://github.com/os-autoinst/os-autoinst-distri-opensuse/pull/10288
openQA test in scenario sle-15-SP2-Online-ppc64le-lvm@ppc64le fails in
[zypper_ref](https://openqa.suse.de/tests/4264225/modules/zypper_ref/steps/2)
[Last good](https://openqa.suse.de/tests/4247142) was using root-console, but after https://github.com/os-autoinst/os-autoinst-distri-opensuse/commit/4e9cca349646152944d403c221b8322ac6842a72#diff-aff3537aeb29a78d33dc1fc514ab716dR26
the module is attempting to use virtio console due to https://github.com/os-autoinst/os-autoinst-distri-opensuse/blob/master/lib/opensusebasetest.pm#L1098 , but fails. Even though the commit looks like it's 22 days old and last good already had VIRTIO_CONSOLE=1, it didn't use the root-virtio-console.
Last good autoinst.log:
~~~
[2020-05-16T11:57:49.052 CEST] [debug] ||| starting zypper_ref tests/console/zypper_ref.pm
[2020-05-16T11:57:49.053 CEST] [debug] tests/console/zypper_ref.pm:25 called testapi::select_console
[2020-05-16T11:57:49.053 CEST] [debug] <<< testapi::select_console(testapi_console="root-console")
[2020-05-16T11:57:49.859 CEST] [debug] tests/console/zypper_ref.pm:25 called testapi::select_console -> lib/susedistribution.pm:883 called testapi::assert_screen
[2020-05-16T11:57:49.859 CEST] [debug] <<< testapi::assert_screen(mustmatch="root-console", timeout=30, no_wait=1)
[2020-05-16T11:57:50.025 CEST] [debug] >>> testapi::_handle_found_needle: found root-console-top-20200304, similarity 1.00 @ 96/2
[2020-05-16T11:57:50.025 CEST] [debug] tests/console/zypper_ref.pm:26 called utils::zypper_enable_install_dvd -> lib/utils.pm:554 called utils::zypper_call -> lib/utils.pm:509 called testapi::script_run
~~~
Failed tests:
~~~
[0m[1;34m[2020-05-21T05:14:21.047 CEST] [debug] ||| starting zypper_ref tests/console/zypper_ref.pm
[0m[2020-05-21T05:14:21.047 CEST] [debug] tests/console/zypper_ref.pm:26 called opensusebasetest::select_serial_terminal -> lib/opensusebasetest.pm:1115 called testapi::select_console
[2020-05-21T05:14:21.047 CEST] [debug] <<< testapi::select_console(testapi_console="root-virtio-terminal")
[2020-05-21T05:14:21.048 CEST] [debug] <<< consoles::virtio_terminal::open_pipe(pipe_prefix="/var/lib/openqa/pool/8/virtio_console")
[33m[2020-05-21T05:14:21.049 CEST] [info] ::: consoles::virtio_terminal::open_pipe: Set PIPE_SZ from 1048576 to 1048576
[0m[33m[2020-05-21T05:14:21.049 CEST] [info] ::: consoles::virtio_terminal::open_pipe: Set PIPE_SZ from 1048576 to 1048576
[0m[37m[2020-05-21T05:14:21.049 CEST] [debug] activate_console, console: root-virtio-terminal, type: virtio-terminal
[0m[2020-05-21T05:14:21.050 CEST] [debug] tests/console/zypper_ref.pm:26 called opensusebasetest::select_serial_terminal -> lib/opensusebasetest.pm:1115 called testapi::select_console -> lib/susedistribution.pm:746 called serial_terminal::login -> lib/serial_terminal.pm:82 called bmwqemu::log_call
[2020-05-21T05:14:21.050 CEST] [debug] <<< serial_terminal::login()
[2020-05-21T05:14:21.050 CEST] [debug] tests/console/zypper_ref.pm:26 called opensusebasetest::select_serial_terminal -> lib/opensusebasetest.pm:1115 called testapi::select_console -> lib/susedistribution.pm:746 called serial_terminal::login -> lib/serial_terminal.pm:87 called testapi::wait_serial
[2020-05-21T05:14:21.050 CEST] [debug] <<< testapi::wait_serial(timeout=5, record_output=undef, expect_not_found=0, quiet=1, buffer_size=undef, regexp=qr/login:\s*$/ui, no_regex=0)
[2020-05-21T05:14:21.050 CEST] [debug] <<< consoles::serial_screen::read_until(quiet=1, expect_not_found=0, buffer_size=undef, pattern="(?^ui:login:\\s*\$)", timeout=5, json_cmd_token="sEJFMwpt", cmd="backend_wait_serial", no_regex=0, regexp="(?^ui:login:\\s*\$)", record_output=undef)
[32m[2020-05-21T05:14:26.056 CEST] [debug] >>> testapi::wait_serial: (?^ui:login:\s*$): fail
[0m[2020-05-21T05:14:26.056 CEST] [debug] tests/console/zypper_ref.pm:26 called opensusebasetest::select_serial_terminal -> lib/opensusebasetest.pm:1115 called testapi::select_console -> lib/susedistribution.pm:746 called serial_terminal::login -> lib/serial_terminal.pm:90 called testapi::type_string
[2020-05-21T05:14:26.056 CEST] [debug] <<< testapi::type_string(text="\n")
[2020-05-21T05:14:26.057 CEST] [debug] <<< consoles::serial_screen::type_string(cmd="backend_type_string", text="\n", json_cmd_token="CJjINXgN")
[2020-05-21T05:14:26.057 CEST] [debug] tests/console/zypper_ref.pm:26 called opensusebasetest::select_serial_terminal -> lib/opensusebasetest.pm:1115 called testapi::select_console -> lib/susedistribution.pm:746 called serial_terminal::login -> lib/serial_terminal.pm:91 called testapi::wait_serial
[2020-05-21T05:14:26.057 CEST] [debug] <<< testapi::wait_serial(regexp=qr/login:\s*$/ui, buffer_size=undef, no_regex=0, quiet=undef, expect_not_found=0, record_output=undef, timeout=90)
[2020-05-21T05:14:26.058 CEST] [debug] <<< consoles::serial_screen::read_until(pattern="(?^ui:login:\\s*\$)", timeout=90, json_cmd_token="zVPhpmAp", quiet=undef, expect_not_found=0, buffer_size=undef, record_output=undef, regexp="(?^ui:login:\\s*\$)", cmd="backend_wait_serial", no_regex=0)
[32m[2020-05-21T05:15:56.106 CEST] [debug] >>> testapi::wait_serial: (?^ui:login:\s*$): fail
[0m[33m[2020-05-21T05:15:56.106 CEST] [info] ::: basetest::runtest: # Test died: Failed to wait for login prompt at /var/lib/openqa/cache/openqa.suse.de/tests/sle/lib/serial_terminal.pm line 91.
~~~
Further investigation is needed and possibly follow up ticket with tools' team.
Fails since (at least) Build [197.1](https://openqa.suse.de/tests/4261497)
Last good: [195.1](https://openqa.suse.de/tests/4247142) (or more recent)