QA (public) » openQA Project (public) » openQA Tests (public)

imho this is related to the worker issues we have on openqaworker2 and grenache (not speaking about the network related ones)
but tbh: I'm too tired of implementing shi**y workarounds to address those worker issues...

sure, we should focus on making the errors more obvious and clean, less workarounds :)

We have understood why the output looks like in the "wrong order". There are actually two methods "run_cmd", the second one added in https://github.com/os-autoinst/os-autoinst/pull/599 within backend/svirt. I guess we should reduce some of the duplication from there first and prevent that confusion. It looks like mnowak creates an explicit new ssh connection within backend/svirt to allow in general the use of snapshots and reverting to them.

Using the same approach as the run_cmd from backend/svirt running in a script from grenache-1.qa connecting to s390p8 does not show any problems to establish 100 connections in a row.

I managed to reproduce the problem locally with

openqa-clone-job --skip-chained-deps --host http://lord.arch --from https://openqa.suse.de 2488101 _SKIP_POST_FAIL_HOOKS=1 ROOTONLY=1 INCLUDE_MODULES=bootloader_zkvm,welcome,accept_license,skip_registration,addon_products_sle,partitioning,partitioning_finish,installer_timezone,user_settings,user_settings_root,installation_overview,start_install,await_install,reboot_after_installation,reconnect_mgmt_console

-> http://lord.arch/tests/2031

Trying with more debugging plus internal timeout on ssh commands in os-autoinst:

diff --git a/backend/baseclass.pm b/backend/baseclass.pm
index ddddcae2..aa41a6c6 100644
--- a/backend/baseclass.pm
+++ b/backend/baseclass.pm
@@ -1168,7 +1168,7 @@ sub new_ssh_connection {
     my ($self, %args) = @_;
     $args{username} ||= 'root';

-    my $ssh = Net::SSH2->new;
+    my $ssh = Net::SSH2->new(timeout => 2 * 60 * 1000, trace => -1, debug => 1);

     # Retry 5 times, in case of the guest is not running yet
     my $counter = 5;
diff --git a/backend/svirt.pm b/backend/svirt.pm
index f4211ec6..7482276b 100644
--- a/backend/svirt.pm
+++ b/backend/svirt.pm
@@ -115,12 +115,14 @@ sub run_cmd {
     my ($ssh, $cmd) = @_;

     my $chan = $ssh->channel();
+    bmwqemu::diag "run_cmd exec: $cmd …";
     $chan->exec($cmd);
     get_ssh_output($chan);
     $chan->send_eof;
     my $ret = $chan->exit_status();
     bmwqemu::diag "Command executed: $cmd, ret=$ret";
     $chan->close();
+    bmwqemu::diag "channel closed";
     return $ret;
 }   

@@ -151,6 +153,7 @@ sub can_handle {

 sub is_shutdown {
     my ($self) = @_;
+    bmwqemu::diag "is_shutdown: begin";
     my $vmname = $self->console('svirt')->name;
     my $rsp;
     if (check_var('VIRSH_VMM_FAMILY', 'hyperv')) {
@@ -160,6 +163,7 @@ sub is_shutdown {
         my $libvirt_connector = get_var('VMWARE_REMOTE_VMM', '');
         $rsp = $self->run_ssh_cmd("! virsh $libvirt_connector dominfo $vmname | grep -w 'shut off'");
     }
+    bmwqemu::diag "is_shutdown: end";
     return $rsp;
 }

Tried locally with just isotovideo and that seemed to pass until after the reboot but I could not find any of the diag messages I put in. Let's see in openQA:

-> http://lord.arch/tests/2034

So far I could not find out what the problem is.

[25/02/2019 13:24:43] <okurz> mgriessmeier: could you take a look into http://lord.arch/tests/2036/file/autoinst-log.txt ? Search for "Backend process died". I understand from the additional debug output I put in that the "installation" console is considered stalled and kills the backend although the installation scenario previously was called with "disable_vnc_stalls". Do you have a good idea if we need to do something else with the installation console before calling check_shutdown?
[25/02/2019 13:37:21] <mgriessmeier> okurz: hmm I don't see how you come to the conclusion why the installation console is stalled
[25/02/2019 13:37:33] <mgriessmeier> I only find _vnc_stalled' => 0,
[25/02/2019 13:38:27] <okurz> huh, that's a good point. Why has the backend died on "installation" console then?
[25/02/2019 13:40:47] <okurz> it's not about stall detection, more like the opposite: the connection is down nevertheless
[25/02/2019 13:41:09] <mgriessmeier> mhh yeah
[25/02/2019 13:42:30] <mgriessmeier> okurz: did you actually conduct the expiriment with the ssh script?
[25/02/2019 13:43:17] <mgriessmeier> because our first assumption was that it's related to the LPAR and not to a console
[25/02/2019 13:44:31] <okurz> mgriessmeier: yeah, the script is fine. I can connect 100 times in a row without problems from grenache-1.qa
[25/02/2019 13:45:06] <mgriessmeier> with more complex commands than 'ls' ?
[25/02/2019 13:45:15] <okurz> the dominfo one
[25/02/2019 13:45:21] <mgriessmeier> kay
[25/02/2019 13:46:51] <mgriessmeier> mnowak: did you have any issues recently with run_cmd and checking if the SUT is shut down?
[25/02/2019 13:47:36] <mnowak> mgriessmeier, not for some time. any failed job?
[25/02/2019 13:47:53] <mgriessmeier> all the incompletes on s390x :/
[25/02/2019 13:47:58] <mgriessmeier> the half-open socket thingy
[25/02/2019 13:48:10] <mgriessmeier> http://lord.arch/tests/2036/file/autoinst-log.txt  with debug output for example
[25/02/2019 13:51:55] <mnowak> mgriessmeier, this used to happen before disable_vnc_stalls was introduced, but that was triggered..
[25/02/2019 13:53:23] <okurz> mnowak: could it be your commit 1ca240982 introduced the problem?

Trying with and without the revert

env openqa-clone-set https://openqa.suse.de/tests/2488101 okurz_investigation_poo48260_current_master _SKIP_POST_FAIL_HOOKS=1 ROOTONLY=1 INCLUDE_MODULES=bootloader_zkvm,welcome,accept_license,skip_registration,addon_products_sle,partitioning,partitioning_finish,installer_timezone,user_settings,user_settings_root,installation_overview,start_install,await_install,reboot_after_installation,reconnect_mgmt_console

-> https://openqa.suse.de/tests/overview?distri=sle&version=15-SP1&build=okurz_investigation_poo48260_current_master on current master

openqa-clone-custom-git-refspec https://github.com/os-autoinst/os-autoinst-distri-opensuse/pull/6890 https://openqa.suse.de/tests/2488101

Created job #2495939: sle-15-SP1-Installer-DVD-s390x-Build175.4-skip_registration@s390x-kvm-sle12 -> https://openqa.suse.de/t2495939

env build=okurz_investigation_poo48260_current_master openqa-clone-set https://openqa.suse.de/tests/2495939 okurz_investigation_poo48260_reverted1ca24098 _SKIP_POST_FAIL_HOOKS=1 ROOTONLY=1 INCLUDE_MODULES=bootloader_zkvm,welcome,accept_license,skip_registration,addon_products_sle,partitioning,partitioning_finish,installer_timezone,user_settings,user_settings_root,installation_overview,start_install,await_install,reboot_after_installation,reconnect_mgmt_console

same build.

Retriggered all incompletes in https://openqa.suse.de/tests/overview?distri=sle&version=15-SP1&build=177.1&arch=s390x&result=incomplete

Monitoring https://openqa.suse.de/tests/overview?result=none&result=failed&result=incomplete&arch=s390x&modules=&distri=sle&version=15-SP1&build=177.1#

Looks better so far. We should still improve the logging output, e.g. what I have running on lord.arch

https://github.com/os-autoinst/os-autoinst/pull/1120