Project

General

Profile

Actions

action #113138

closed

sporadic failure in openQA test "t/ui/23-audit-log.t" size:M

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

Status:
Resolved
Priority:
High
Assignee:
Category:
Regressions/Crashes
Target version:
Start date:
2022-07-01
Due date:
% Done:

0%

Estimated time:

Description

Observation

https://app.circleci.com/pipelines/github/os-autoinst/openQA/9895/workflows/bd749c46-c563-4fcd-9d17-6195780465f3/jobs/93334/steps shows

[06:59:35] t/ui/23-audit-log.t ........................ 12/? 
    #   Failed test 'correct number of elements'
    #   at t/ui/23-audit-log.t line 132.
    #          got: '9'
    #     expected: '1'
    # less than a minute ago Demo job_create {
    #   "TEST": "foo",
    #   "id": 1
    # }, less than a minute ago Demo comment_create {
    #   "id": 1,
    #   "job_id": 1
    # }, less than a minute ago Demo table_create {
    #   "backend": "qemu",
    #   "description": null,
    #   "id": 1,
    #   "name": "foo",
    #   "settings": [],
    #   "table": "Machines"
    # }, less than a minute ago Demo table_create {
    #   "description": null,
    #   "id": 1,
    #   "name": "testsuite",
    #   "settings": [],
    #   "table": "TestSuites"
    # }, less than a minute ago Demo table_create {
    #   "arch": "x86_64",
    #   "description": null,
    #   "distri": "opensuse",
    #   "flavor": "DVD",
    #   "id": 1,
    #   "name": "",
    #   "settings": [],
    #   "table": "Products",
    #   "version": "13.2"
    # }, less than a minute ago Demo user_login null, less than a minute ago system startup openQA restarted, less than a minute ago Demo user_login null, less than a minute ago system startup openQA restarted
    # Looks like you failed 1 test of 18.
[06:59:35] t/ui/23-audit-log.t ........................ 13/? 
#   Failed test 'clickable events'
#   at t/ui/23-audit-log.t line 140.
[06:59:35] t/ui/23-audit-log.t ........................ 14/? # Looks like you failed 1 test of 14.
                                                              [06:59:35] t/ui/23-audit-log.t ........................ Dubious, test returned 1 (wstat 256, 0x100)

Acceptance criteria

  • AC1: t/ui/23-audit-log.t stable in many runs
  • AC2: t/ui/23-audit-log.t is not included in tools/unstable_tests.txt

Suggestions

  • Read about the history of latest changes in https://progress.opensuse.org/issues/111539, maybe okurz already tried to run 1000 runs locally and couldn't reproduce or something.
  • Try it out locally with coverage enabled and see if it can be reproduced. Maybe try NON_HEADLESS=1. Or try to spot the mistake by code analysis.
  • Fix the test race-free
  • Remove test module from tools/unstable_tests.txt
  • Optional: Try to gather statistics from circleCI because we have similar problems reappearing
Actions #1

Updated by okurz over 2 years ago

  • Subject changed from sporadic failure in openQA test "t/ui/23-audit-log.t" to sporadic failure in openQA test "t/ui/23-audit-log.t" size:M
  • Description updated (diff)
  • Status changed from New to Workable
Actions #2

Updated by mkittler over 2 years ago

  • Assignee set to mkittler
Actions #3

Updated by mkittler over 2 years ago

  • Status changed from Workable to In Progress

The problem is actually quite clear (hard-coded sleep 1), there was even a TODO in the code. This PR should fix the issue: https://github.com/os-autoinst/openQA/pull/4737

Actions #4

Updated by mkittler over 2 years ago

  • Status changed from In Progress to Resolved

The PR has been merged. It also removed the test out of the unstable ones. I have tested locally whether it works by running the test in a loop. That should be good enough although my local system is likely too fast to see the problem anyways. (The problem could be pinned down quite easily so I'm still confident that my change worked. Hopefully there are no further instabilities but then we can reopen.)

Actions #5

Updated by okurz over 2 years ago

  • Status changed from Resolved to Feedback

Seems like I hit the exact same problem again:

https://app.circleci.com/pipelines/github/os-autoinst/openQA/9992/workflows/f8d26d1f-aab6-44bc-918e-c4d70661e814/jobs/94204/steps

[13:16:30] t/ui/23-audit-log.t ........................ 12/? 
    #   Failed test 'one row for comment create events'
    #   at t/ui/23-audit-log.t line 36.
    #          got: '9'
    #     expected: '1'

    #   Failed test 'one comment'
    #   at t/ui/23-audit-log.t line 134.
    #          got: '0'
    #     expected: '1'
    # Looks like you failed 2 tests of 18.
[13:16:30] t/ui/23-audit-log.t ........................ 13/? 
#   Failed test 'clickable events'
#   at t/ui/23-audit-log.t line 136.
Can't call method "get_text" on an undefined value at t/ui/23-audit-log.t line 135.
[13:16:30] t/ui/23-audit-log.t ........................ 14/? # Tests were run but no plan was declared and done_testing() was not seen.
                                                              [13:16:30] t/ui/23-audit-log.t ........................ Dubious, test returned 1 (wstat 256, 0x100)
Failed 1/14 subtests 

can you please check?

Actions #6

Updated by mkittler over 2 years ago

  • Status changed from Feedback to In Progress

Looks like that PR was correctly rebase so I'll have a look.

Actions #7

Updated by mkittler over 2 years ago

  • Status changed from In Progress to Feedback

Let's see whether the following PR fixes it: https://github.com/os-autoinst/openQA/pull/4763

Actions #8

Updated by mkittler over 2 years ago

  • Status changed from Feedback to Resolved

I've asked in the chat but nobody has been seeing an occurrence lately so I'm resolving the ticket for now.

Actions

Also available in: Atom PDF