Project

General

Profile

Actions

action #63059

closed

[SLE][Migration][SLE15SP2][Regression] test fails in zypper_lifecycle - Test died: script failed with : KAoS1

Added by tinawang123 about 4 years ago. Updated almost 4 years ago.

Status:
Rejected
Priority:
High
Assignee:
Category:
Bugs in existing tests
Target version:
-
Start date:
2020-02-04
Due date:
% Done:

100%

Estimated time:
12.00 h
Difficulty:

Description

Observation

openQA test in scenario sle-15-SP2-Regression-on-Migration-from-SLE15-SPX-to-SLE15-SP2-s390x-offline_sles15_pscc_basesys-srv-desk-dev-contm-lgm-wsm_all_full@s390x-kvm-sle15 fails in
zypper_lifecycle

Test suite description

Reproducible

Fails since (at least) Build 104.1

Expected result

Last good: (unknown) (or more recent)

Further details

Always latest result in this scenario: latest

Actions #1

Updated by leli about 4 years ago

  • Subject changed from [SLE][Migration][SLE15SP2] test fails in zypper_lifecycle - Test died: script failed with : KAoS1 to [SLE][Migration][SLE15SP2][Regression] test fails in zypper_lifecycle - Test died: script failed with : KAoS1
  • Estimated time set to 12.00 h
Actions #2

Updated by okurz about 4 years ago

This is an autogenerated message for openQA integration by the openqa_review script:

This bug is still referenced in a failing openQA test: offline_sles15sp1_pscc_basesys-srv-desk-dev-contm-lgm-py2-tsm-wsm_all_full
https://openqa.suse.de/tests/3916227

To prevent further reminder comments one of the following options should be followed:

  1. The test scenario is fixed by applying the bug fix to the tested product or the test is adjusted
  2. The openQA job group is moved to "Released"
  3. The label in the openQA scenario is removed
Actions #3

Updated by leli about 4 years ago

  • Priority changed from Normal to Urgent
Actions #4

Updated by hjluo about 4 years ago

  • Status changed from New to In Progress
  • Assignee set to hjluo
Actions #5

Updated by coolgw about 4 years ago

error part seems change, but we still using this ticket tracking this.
https://openqa.suse.de/tests/3928548#step/zypper_lifecycle/1

This was caused by "zypper lifecycle" command timedout. we can fist fix this.

[2020-02-26T23:40:19.256 UTC] [debug] tests/console/zypper_lifecycle.pm:43 called testapi::script_output
[2020-02-26T23:40:19.257 UTC] [debug] <<< testapi::type_string(string="zypper lifecycle\n", max_interval=250, wait_screen_changes=0, wait_still_screen=0, timeout=30, similarity_level=47)
[2020-02-26T23:40:19.876 UTC] [debug] tests/console/zypper_lifecycle.pm:43 called testapi::script_output
[2020-02-26T23:40:19.877 UTC] [debug] <<< testapi::send_key(key="ctrl-d", do_wait=0, wait_screen_change=0)
[2020-02-26T23:40:20.214 UTC] [debug] tests/console/zypper_lifecycle.pm:43 called testapi::script_output
[2020-02-26T23:40:20.215 UTC] [debug] <<< testapi::type_string(string="(echo AwZR8; bash -eox pipefail /tmp/scriptAwZR8.sh ; echo SCRIPT_FINISHEDAwZR8-\$?-) | tee /dev/ttyAMA0\n", max_interval=250, wait_screen_changes=0, wait_still_screen=0, timeout=30, similarity_level=47)
[2020-02-26T23:40:24.637 UTC] [debug] tests/console/zypper_lifecycle.pm:43 called testapi::script_output
[2020-02-26T23:40:24.638 UTC] [debug] <<< testapi::wait_serial(timeout=300, record_output=1, buffer_size=undef, no_regex=0, regexp="SCRIPT_FINISHEDAwZR8-\d+-", expect_not_found=0, quiet=undef)
[2020-02-26T23:45:26.636 UTC] [debug] >>> testapi::wait_serial: SCRIPT_FINISHEDAwZR8-\d+-: fail
[2020-02-26T23:45:26.637 UTC] [debug] script timeout: zypper lifecycle at /usr/lib/os-autoinst/testapi.pm line 1104.

Actions #6

Updated by hjluo about 4 years ago

Test died: script timeout: zypper lifecycle at /usr/lib/os-autoinst/testapi.pm line 1104

[2020-03-11T09:08:55.778 UTC] [debug] tests/console/zypper_lifecycle.pm:43 called testapi::script_output
[2020-03-11T09:08:55.778 UTC] [debug] <<< testapi::type_string(string="cat - > /tmp/scriptAwZR8.sh;\n", max_interval=250, wait_screen_changes=0, wait_still_screen=0, timeout=30, similarity_level=47)
[2020-03-11T09:08:56.885 UTC] [debug] tests/console/zypper_lifecycle.pm:43 called testapi::script_output
[2020-03-11T09:08:56.886 UTC] [debug] <<< testapi::type_string(string="zypper lifecycle\n", max_interval=250, wait_screen_changes=0, wait_still_screen=0, timeout=30, similarity_level=47)
[2020-03-11T09:08:57.478 UTC] [debug] tests/console/zypper_lifecycle.pm:43 called testapi::script_output
[2020-03-11T09:08:57.478 UTC] [debug] <<< testapi::send_key(key="ctrl-d", wait_screen_change=0, do_wait=0)
[2020-03-11T09:08:57.816 UTC] [debug] tests/console/zypper_lifecycle.pm:43 called testapi::script_output
[2020-03-11T09:08:57.816 UTC] [debug] <<< testapi::type_string(string="(echo AwZR8; bash -eox pipefail /tmp/scriptAwZR8.sh ; echo SCRIPT_FINISHEDAwZR8-\$?-) | tee /dev/ttyAMA0\n", max_interval=250, wait_screen_changes=0, wait_still_screen=0, timeout=30, similarity_level=47)
[2020-03-11T09:09:02.056 UTC] [debug] tests/console/zypper_lifecycle.pm:43 called testapi::script_output
[2020-03-11T09:09:02.057 UTC] [debug] <<< testapi::wait_serial(quiet=undef, buffer_size=undef, timeout=300, record_output=1, expect_not_found=0, regexp="SCRIPT_FINISHEDAwZR8-\d+-", no_regex=0)
[2020-03-11T09:14:03.824 UTC] [debug] >>> testapi::wait_serial: SCRIPT_FINISHEDAwZR8-\d+-: fail
[2020-03-11T09:14:03.825 UTC] [debug] script timeout: zypper lifecycle at /usr/lib/os-autoinst/testapi.pm line 1104.

you can see it take 09:14:03 - 09:08:55 which cost 6 minutes without return. so we think/verified 9 minutes will be OK.

Actions #7

Updated by hjluo about 4 years ago

the syntax error is that we did't handle this kind of scenario.

for repo in (System Packages) ; do zypper -n -x se -t package -i -s -r $repo ; done | grep name= | head -n 1
bash: syntax error near unexpected token `('

which should be:

for repo in "(System Packages)"; do zypper -n -x se -t package -i -s -r $repo ; done | grep name= | head -n 1

Actions #8

Updated by hjluo about 4 years ago

[2020-03-11T05:42:48.888 CET] [debug] <<< testapi::wait_serial(timeout=300, record_output=1, buffer_size=undef, no_regex=0, regexp="SCRIPT_FINISHEDAwZR8-\d+-", quiet=undef, expect_not_found=0)

solvable-list>
solvable status="installed" name="389-ds" kind="package" edition="1.4.2.8~git0.3aaa3e820-1.9" arch="s390x" repository="(System Packages)"/>
solvable status="installed" name="GeoIP" kind="package" edition="1.6.12-4.17" arch="s390x" repository="(System Packages)"/>
solvable status="installed" name="GeoIP-data" kind="package" edition="1.6.12-4.17" arch="noarch" repository="(System Packages)"/>
solvable status="installed" name="Mesa" kind="package" edition="19.3.4-44.6" arch="s390x" repository="(System Packages)"/>
solvable status="installed" name="Mesa-dri" kind="package" edition="19.3.4-44.9" arch="s390x" repository="(System Packages)"/>
solvable status="installed" name="Mesa-libEGL1" kind="package" edition="19.3.4-44.6" arch="s390x" repository="(System Packages)"/>
solvable status="installed" name="Mesa-libGL1" kind="package" edition="19.3.4-44.6" arch="s390x" repository="(System Packages)"/>

SCRIPT_FINISHED708tO-0-
[2020-03-11T05:43:14.495 CET] [debug] >>> testapi::wait_serial: SCRIPT_FINISHED708tO-\d+-: ok

Actions #9

Updated by tinawang123 about 4 years ago

reproduce Aarch64 at: https://openqa.nue.suse.com/tests/3984081

this issue just timeout on aarch64 I've set timeout to 1200 and it still fails.

Actions #10

Updated by tinawang123 about 4 years ago

Reproduce on S390x at: https://openqa.nue.suse.com/tests/3984089

this is actually a s390x bug bsc#1166549

Actions #11

Updated by hjluo about 4 years ago

  • Status changed from In Progress to Blocked

now it blocked by bug#1166549 - P5 [Migration] [Build 155.1] openQA test fails in zypper_lifecycle on S390x - zypper lifecycle error with 'Error building the cache' - huajian

Actions #12

Updated by okurz almost 4 years ago

This is an autogenerated message for openQA integration by the openqa_review script:

This bug is still referenced in a failing openQA test: online_sles15_pscc_lp-basesys-srv-desk-dev-contm-lgm-wsm_all_full
https://openqa.suse.de/tests/4083635

To prevent further reminder comments one of the following options should be followed:

  1. The test scenario is fixed by applying the bug fix to the tested product or the test is adjusted
  2. The openQA job group is moved to "Released"
  3. The label in the openQA scenario is removed
Actions #13

Updated by leli almost 4 years ago

  • Priority changed from Urgent to Normal
Actions #14

Updated by hjluo almost 4 years ago

  • % Done changed from 0 to 40

run with fix: http://openqa.suse.de/t4117075 but still failed with timedout.
fix is:
my $overview = script_output ("zypper lifecycle", 360);

now change time out to 600 and rerun: http://openqa.suse.de/t4122648 but it still FAILED with timedout

[2020-04-16T07:42:07.313 CEST] [debug] <<< testapi::wait_serial(buffer_size=undef, quiet=undef, expect_not_found=0, timeout=600, regexp="SCRIPT_FINISHEDAwZR8-\d+-", no_regex=0, record_output=1)
[2020-04-16T07:52:08.839 CEST] [debug] >>> testapi::wait_serial: SCRIPT_FINISHEDAwZR8-\d+-: fail
[2020-04-16T07:52:08.839 CEST] [info] ::: basetest::runtest: # Test died: script timeout: zypper lifecycle at /usr/lib/os-autoinst/testapi.pm line 1104.

Actions #15

Updated by hjluo almost 4 years ago

on a real machine we run this cli with 2 modules.

ps64vt1065:~ # time zypper lifecycle

Product end of support

Codestream: SUSE Linux Enterprise Server 15 2028-07-30
SUSE Linux Enterprise Server 15 SP2 n/a*

Module end of support

Containers Module 2020-06-29
Legacy Module 2021-07-30
Python 2 Module 2021-07-30
Desktop Applications Module n/a*
Public Cloud Module n/a*
Web and Scripting Module n/a*
Development Tools Module n/a*
Basesystem Module n/a*
Server Applications Module n/a*

No packages with end of support different from product.

*) See https://www.suse.com/lifecycle for latest information

real 0m6.184s
user 0m2.676s
sys 0m0.225s

Actions #16

Updated by hjluo almost 4 years ago

latest run with a bigger timeout value=1600 http://openqa.suse.de/t4138621 still timeout at wait_serial

Actions #17

Updated by leli almost 4 years ago

  • Priority changed from Normal to High
Actions #18

Updated by hjluo almost 4 years ago

  • % Done changed from 40 to 60

[2020-04-20T07:22:50.990 CEST] [debug] >>> testapi::_handle_found_needle: found user-console-20191207, similarity 1.00 @ 145/2
[2020-04-20T07:22:50.991 CEST] [debug] tests/console/zypper_lifecycle.pm:43 called testapi::script_output
[2020-04-20T07:22:50.991 CEST] [debug] <<< testapi::type_string(string="cat - > /tmp/scriptAwZR8.sh;\n", max_interval=250, wait_screen_changes=0, wait_still_screen=0, timeout=30, similarity_level=47)
[2020-04-20T07:22:54.103 CEST] [debug] tests/console/zypper_lifecycle.pm:43 called testapi::script_output
[2020-04-20T07:22:54.103 CEST] [debug] <<< testapi::type_string(string="zypper lifecycle\n", max_interval=250, wait_screen_changes=0, wait_still_screen=0, timeout=30, similarity_level=47)
[2020-04-20T07:22:55.808 CEST] [debug] tests/console/zypper_lifecycle.pm:43 called testapi::script_output
[2020-04-20T07:22:55.808 CEST] [debug] <<< testapi::send_key(key="ctrl-d", do_wait=0, wait_screen_change=0)
[2020-04-20T07:22:56.409 CEST] [debug] tests/console/zypper_lifecycle.pm:43 called testapi::script_output
[2020-04-20T07:22:56.409 CEST] [debug] <<< testapi::type_string(string="(echo AwZR8; bash -eox pipefail /tmp/scriptAwZR8.sh ; echo SCRIPT_FINISHEDAwZR8-\$?-) | tee /dev/hvc0\n", max_interval=250, wait_screen_changes=0, wait_still_screen=0, timeout=30, similarity_level=47)
[2020-04-20T07:23:08.007 CEST] [debug] tests/console/zypper_lifecycle.pm:43 called testapi::script_output
[2020-04-20T07:23:08.007 CEST] [debug] <<< testapi::wait_serial(quiet=undef, timeout=11600, record_output=1, buffer_size=undef, expect_not_found=0, no_regex=0, regexp="SCRIPT_FINISHEDAwZR8-\d+-")
[2020-04-20T10:36:29.584 CEST] [debug] >>> testapi::wait_serial: SCRIPT_FINISHEDAwZR8-\d+-: fail
[2020-04-20T10:36:29.585 CEST] [info] ::: basetest::runtest: # Test died: script timeout: zypper lifecycle at /usr/lib/os-autoinst/testapi.pm line 1104.

Actions #19

Updated by hjluo almost 4 years ago

add script_run 'zypper lifecycle' to verify the timeout

http://openqa.suse.de/t4165134

It shows that the zypper lifecycle return error with can't create metadata cache directory.
the metadata cache needs be built for all modules, whith is a known bug

#P5 Bug 1166549 - [Migration] [Build 155.1] openQA test fails in zypper_lifecycle on S390x - zypper lifecycle error with 'Error building the cache'
http://149.44.176.58/tests/4165134#step/zypper_lifecycle/4

Actions #20

Updated by hjluo almost 4 years ago

get the error log with diag:

  • my $overview = script_output 'zypper lifecycle', 300;
  • diag '=================================';
  • my $out = script_output("zypper lifecycle", proceed_on_failure => 1);
  • diag "zypper lifecycle output: $out";
  • diag '=================================';

http://openqa.suse.de/t4166032
http://openqa.suse.de/t4166033

Actions #21

Updated by hjluo almost 4 years ago

  • Status changed from Blocked to Rejected
  • % Done changed from 60 to 100

reject this ticket cause it's actually a bug bsc#1166549
Bug 1166549 - [Migration] [Build 155.1] openQA test fails in zypper_lifecycle on S390x - zypper lifecycle error with 'Error building the cache'
https://bugzilla.suse.com/show_bug.cgi?id=1166549

Actions

Also available in: Atom PDF