Project

General

Profile

Actions

action #67075

closed

test fails in updates_packagekit_gpk because assert_screen timeout because select_console x11 too long

Added by michel_mno almost 4 years ago. Updated almost 4 years ago.

Status:
Rejected
Priority:
Normal
Assignee:
-
Category:
Bugs in existing tests
Target version:
-
Start date:
2020-05-20
Due date:
% Done:

0%

Estimated time:
Difficulty:

Description

test fails in updates_packagekit_gpk because assert_screen timeout because select_console x11 too long
despite a 90s timeout.

I hit the problem two times on TW 20200517 snapshot
https://openqa.opensuse.org/tests/1272417#step/updates_packagekit_gpk/3
https://openqa.opensuse.org/tests/1272711#step/updates_packagekit_gpk/3

extract of related autoinst.log

[2020-05-19T14:06:33.973 UTC] [debug] Snapshot complete
[2020-05-19T14:06:34.036 UTC] [debug] EVENT {"event":"RESUME","timestamp":{"microseconds":36453,"seconds":1589897194}}
[2020-05-19T14:06:34.043 UTC] [debug] ||| starting updates_packagekit_gpk tests/update/updates_packagekit_gpk.pm
[2020-05-19T14:06:34.048 UTC] [debug] QEMU: Formatting '/var/lib/openqa/pool/2/raid/hd0-overlay3', fmt=qcow2 size=42949672960 backing_file=/var/lib/openqa/pool/2/raid/hd0-overlay2 backing_fmt=qcow2 cluster_size=65536 lazy_refcounts=off refcount_bits=16
[2020-05-19T14:06:34.048 UTC] [debug] QEMU: Formatting '/var/lib/openqa/pool/2/raid/cd0-overlay3', fmt=qcow2 size=3785537536 backing_file=/var/lib/openqa/pool/2/raid/cd0-overlay2 backing_fmt=qcow2 cluster_size=65536 lazy_refcounts=off refcount_bits=16
[2020-05-19T14:06:34.049 UTC] [debug] tests/update/updates_packagekit_gpk.pm:65 called testapi::select_console
[2020-05-19T14:06:34.049 UTC] [debug] <<< testapi::select_console(testapi_console="x11", await_console=0)
[2020-05-19T14:06:34.856 UTC] [debug] activate_console, console: x11, type:
[2020-05-19T14:06:34.856 UTC] [debug] activate_console called with generic type, no action
[2020-05-19T14:06:34.856 UTC] [debug] tests/update/updates_packagekit_gpk.pm:66 called x11utils::ensure_unlocked_desktop -> lib/x11utils.pm:79 called testapi::assert_screen
[2020-05-19T14:06:34.856 UTC] [debug] <<< testapi::assert_screen(mustmatch=[
  "displaymanager",
  "displaymanager-password-prompt",
  "generic-desktop",
  "screenlock",
  "screenlock-password",
  "authentication-required-user-settings",
  "authentication-required-modify-system",
  "guest-disabled-display"
], timeout=30, no_wait=1)
[2020-05-19T14:06:38.197 UTC] [debug] WARNING: check_asserted_screen took 3.34 seconds for 103 candidate needles - make your needles more specific
[2020-05-19T14:06:38.197 UTC] [debug] no match: 89.9s, best candidate: XFCE-blackscreen-leap15.2-20200403 (0.99)
...
[2020-05-19T14:08:13.847 UTC] [debug] no match: -0.1s, best candidate: XFCE-blackscreen-leap15.2-20200403 (0.99)
[2020-05-19T14:08:14.109 UTC] [debug] >>> testapi::_check_backend_response: match=authentication-required-modify-system,authentication-required-user-settings,displaymanager,displaymanager-password-prompt,generic-desktop,guest-disabled-display,screenlock,screenlock-password timed out after 90 (assert_screen)
[2020-05-19T14:08:14.170 UTC] [info] ::: basetest::runtest: # Test died: no candidate needle with tag(s) 'displaymanager, displaymanager-password-prompt, generic-desktop, screenlock, screenlock-password, authentication-required-user-settings, authentication-required-modify-system, guest-disabled-display' matched
[2020-05-19T14:08:14.171 UTC] [debug] tests/update/updates_packagekit_gpk.pm:132 called opensusebasetest::post_fail_hook -> lib/opensusebasetest.pm:1162 called utils::show_tasks_in_blocked_state -> lib/utils.pm:1379 called testapi::send_key
[2020-05-19T14:08:14.171 UTC] [debug] <<< testapi::send_key(key="alt-sysrq-w", do_wait=0, wait_screen_change=0)

Observation

openQA test in scenario opensuse-Tumbleweed-DVD-ppc64le-gnome@ppc64le fails in
updates_packagekit_gpk

Test suite description

Reproducible

Fails since (at least) Build 20200517

Expected result

Last good: 20200516 (or more recent)

Further details

Always latest result in this scenario: latest

Actions #1

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: gnome
https://openqa.opensuse.org/tests/1286348

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

Updated by michel_mno almost 4 years ago

  • Status changed from New to Rejected

The problem disappeared between TW 20200520 & 20200523 snapshots.

The above reference made by openqa_review script caused by poo#67075 ref added by automatic takeover in openQA test comments despite passed tests.

Actions #3

Updated by apappas almost 4 years ago

  • Status changed from Rejected to New

This still happens.

Relevant excrepts:

2020-06-25T02:28:59.372 CEST] [debug] tests/update/updates_packagekit_gpk.pm:66 called x11utils::ensure_unlocked_desktop -> lib/x11utils.pm:121 called testapi::check_screen
[2020-06-25T02:28:59.372 CEST] [debug] <<< testapi::check_screen(mustmatch="desktop-runner", timeout=30)
[2020-06-25T02:28:59.736 CEST] [debug] no match: 29.9s, best candidate: desktop-runner-gnome-3.16+-20150325 (0.00)
[2020-06-25T02:29:00.375 CEST] [debug] no change: 28.9s
[2020-06-25T02:29:01.551 CEST] [debug] no match: 27.9s, best candidate: desktop-runner-gnome-3.16+-20150325 (0.00)
[2020-06-25T02:29:02.377 CEST] [debug] no change: 26.9s
[2020-06-25T02:29:03.976 CEST] [debug] WARNING: check_asserted_screen took 0.60 seconds for 17 candidate needles - make your needles more specific
[2020-06-25T02:29:03.976 CEST] [debug] no match: 25.9s, best candidate: desktop-runner-gnome-3.16+-20150325 (0.00)
[2020-06-25T02:29:28.404 CEST] [debug] no change: 0.9s
[2020-06-25T02:29:29.974 CEST] [debug] WARNING: check_asserted_screen took 0.57 seconds for 17 candidate needles - make your needles more specific
[2020-06-25T02:29:29.974 CEST] [debug] no match: -0.1s, best candidate: desktop-runner-gnome-3.16+-20150325 (0.00)
[2020-06-25T02:29:30.123 CEST] [debug] >>> testapi::_check_backend_response: match=desktop-runner timed out after 30 (check_screen)
[2020-06-25T02:29:30.141 CEST] [debug] Next loop (9), Generic desktop didn't match
[2020-06-25T02:29:30.141 CEST] [debug] tests/update/updates_packagekit_gpk.pm:66 called x11utils::ensure_unlocked_desktop -> lib/x11utils.pm:79 called testapi::assert_screen
[2020-06-25T02:29:30.141 CEST] [debug] <<< testapi::assert_screen(mustmatch=[
  "displaymanager",
  "displaymanager-password-prompt",
  "generic-desktop",
  "screenlock",
  "screenlock-password",
  "authentication-required-user-settings",
  "authentication-required-modify-system",
  "guest-disabled-display"
], no_wait=1, timeout=30)
[2020-06-25T02:29:32.488 CEST] [debug] WARNING: check_asserted_screen took 2.35 seconds for 92 candidate needles - make your needles more specific
[2020-06-25T02:29:32.488 CEST] [debug] no match: 29.9s, best candidate: XFCE-blackscreen-leap15.2-20200403 (0.87)
[2020-06-25T02:29:32.590 CEST] [debug] no change: 27.5s
[2020-06-25T02:29:32.690 CEST] [debug] no change: 27.4s
[2020-06-25T02:29:32.739 CEST] [debug] considering VNC stalled, no update for 4.49 seconds
[2020-06-25T02:29:32.791 CEST] [debug] no change: 27.3s
[2020-06-25T02:29:32.892 CEST] [debug] no change: 27.2s
[2020-06-25T02:29:32.989 CEST] [debug] pointer type 1 0 1024 768 -257
[2020-06-25T02:29:32.990 CEST] [debug] led state 0 1 1 -261
[2020-06-25T02:29:32.995 CEST] [debug] no change: 27.1s
[2020-06-25T02:29:34.103 CEST] [debug] no change: 26.0s
[2020-06-25T02:29:41.078 CEST] [debug] WARNING: check_asserted_screen took 6.87 seconds for 92 candidate needles - make your needles more specific
[2020-06-25T02:29:41.078 CEST] [debug] no match: 25.9s, best candidate: XFCE-blackscreen-leap15.2-20200403 (0.87)
[2020-06-25T02:29:41.179 CEST] [debug] no change: 18.9s
[2020-06-25T02:29:41.280 CEST] [debug] no change: 18.8s
[2020-06-25T02:29:41.329 CEST] [debug] considering VNC stalled, no update for 8.09 seconds
[2020-06-25T02:29:41.380 CEST] [debug] no change: 18.7s
[2020-06-25T02:29:41.481 CEST] [debug] no change: 18.6s
[2020-06-25T02:29:41.579 CEST] [debug] pointer type 1 0 1024 768 -257
[2020-06-25T02:29:41.579 CEST] [debug] led state 0 1 1 -261
[2020-06-25T02:29:41.585 CEST] [debug] no change: 18.5s
...
[2020-06-25T02:30:00.042 CEST] [debug] no change: 0.1s
[2020-06-25T02:30:06.805 CEST] [debug] WARNING: check_asserted_screen took 6.66 seconds for 92 candidate needles - make your needles more specific
[2020-06-25T02:30:06.806 CEST] [debug] no match: -0.1s, best candidate: XFCE-blackscreen-leap15.2-20200403 (0.87)
[2020-06-25T02:30:06.985 CEST] [debug] >>> testapi::_check_backend_response: match=authentication-required-modify-system,authentication-required-user-settings,displaymanager,displaymanager-password-prompt,generic-desktop,guest-disabled-display,screenlock,screenlock-password timed out after 30 (assert_screen)
[2020-06-25T02:30:07.023 CEST] [info] ::: basetest::runtest: # Test died: no candidate needle with tag(s) 'displaymanager, displaymanager-password-prompt, generic-desktop, screenlock, screenlock-password, authentication-required-user-settings, authentication-required-modify-system, guest-disabled-display' matched
Actions #4

Updated by michel_mno almost 4 years ago

not sure last reported occurrence is same issue:

  • original problem was ppc64le, new occurrence is x86_64
  • original problem did not started with a Desktop screen, while new occurrence is.
Actions #5

Updated by apappas almost 4 years ago

  • Status changed from New to Rejected

michel_mno wrote:

not sure last reported occurrence is same issue:

  • original problem was ppc64le, new occurrence is x86_64
  • original problem did not started with a Desktop screen, while new occurrence is.

You are right. I 'll open a new issue

Actions

Also available in: Atom PDF