action #92164: t/01-test-utilities.t fails in 'test would have failed' in unrelated PR - openQA Project - openSUSE Project Management Tool

Custom queries

All 'new' issues w/o assignee, sorted by version/priority
All auto_review tickets
All auto_review+force_result tickets
openQA Infrastructure Project
openqa-review - Closed tickets last updated by openqa-review, last 30 days
QA roadmap long-term
QA SLE functional
QA SLE Functional - closed in last 14 days
QA SLE Functional - High, need to be refined
QA SLE Functional - over cycle time median
QA SLE u
QA SLE y
QA tools (tag not necessary in openQA and subprojects)
QA tools tag (tag not necessary in openQA and subprojects; excluding tickets in "Ready" version as they are already on the backlog)
QAC - Backlog
QE tools team - backlog (ready issues)
QE tools team - backlog (w/o infra)
QE tools team - backlog SLA high
QE tools team - backlog SLA immediate
QE tools team - backlog SLA no immediate/urgent in feedback/blocked
QE tools team - backlog SLA normal
QE tools team - backlog SLA urgent
QE tools team - backlog SLO high
QE tools team - backlog SLO normal
QE tools team - backlog SLO urgent
QE tools team - backlog, high-level view (epics and higher)
QE tools team - backlog, non-reactive work, needs parent
QE tools team - backlog, top-level view (all sagas)
QE tools team - closed within last 14 days
QE tools team - closed within last 60 days
QE tools team - closed yesterday
QE Tools Team - Collaborative Session
QE tools team - due date forecast
QE Tools team - due soon
QE tools team - exceeding due-date
QE tools team - infrastructure backlog
QE tools team - next - sorted by update time
QE tools team - next issues
QE tools team - non-estimated (unblocked) issues (w/o infra)
QE tools team - ready issues - Workable
QE tools team - ready, not assigned/blocked/low
QE tools team - update forecast
QE tools team - updated by priority
QE tools team - what members of the team are working on - Feedback (not-low)
QE Tools Team Backlog By Assignee
Tools Team Retrospective
Tools Team Retrospective (not estimated or assigned)

Actions

Copy link

action #92164

closed

t/01-test-utilities.t fails in 'test would have failed' in unrelated PR

Added by okurz about 3 years ago. Updated almost 3 years ago.

Status:

Resolved

Priority:

Normal

Assignee:

tinita

Category:

Regressions/Crashes

Target version:

Ready

Start date:

2021-05-05

Due date:

2021-05-19

% Done:

Estimated time:

Description

Observation¶

In https://github.com/os-autoinst/openQA/pull/3877
in https://circleci.com/gh/os-autoinst/openQA/60151?utm_campaign=vcs-integration-link&utm_medium=referral&utm_source=github-build-link t/01-test-utilities.t fails with

not ok 1 - warnings in sub processes are fatal test failures
Subtest: warnings in sub processes are fatal test failures
    # PID of test-process-1: 141
    # waiting at most 42 seconds for SIGCHLD (sleep is supposed to be interrupted by SIGCHLD)
    ok 1 - warning logged
    not ok 2 - test would have failed
    ok 3 - message of test failure
    ok 4 - exit code of test failure is non-zero
    not ok 5 - manual termination via stop_service does not trigger _fail_and_exit
    1..5

History
Notes
Property changes

Actions

Copy link

Updated by okurz about 3 years ago

On my work notebook local environment 1k runs (!) have succeeded, in circleCI a second run failed: https://app.circleci.com/pipelines/github/os-autoinst/openQA/6386/workflows/ba9d9a66-05f7-4c14-b2ea-921dd5a2e272/jobs/60180/steps . Anyone an idea?

Actions

Copy link

Updated by okurz about 3 years ago

mkittler mentioned maybe it's because of coverage analysis. Trying with

runs=2000 count_fail_ratio make coverage KEEP_DB=1 TESTS=t/01-test-utilities.t

but that fails for me with Can't read /home/okurz/local/os-autoinst/openQA/cover_db/runs/1620218733.13161.31806/cover.14 with Sereal: Sereal: Error: Bad Sereal header: Not a valid Sereal document. at offset 1 of input at srl_decoder.c line 600 at /usr/lib/perl5/vendor_perl/5.26.1/x86_64-linux-thread-multi/Devel/Cover/DB/IO/Sereal.pm line 34, <$fh> chunk 1.. I think I had something like this already in the past. What's missing now?

Actions

Copy link

Updated by okurz about 3 years ago

Using https://github.com/os-autoinst/openQA/pull/3885 as workaround I can proceed. Running tests with coverage now in a loop locally …

Actions

Copy link

Updated by okurz about 3 years ago

Due date set to 2021-05-19
Status changed from In Progress to Feedback
Priority changed from High to Normal

experiment finished, runs=2000 count_fail_ratio make coverage KEEP_DB=1 TESTS=t/01-test-utilities.t yields:

## count_fail_ratio: Run: 2000. Fails: 0. Fail ratio 0%

so at least not easily reproducible this way with coverage locally, must be something else. Any other ideas what to try?

Actions

Copy link

Updated by tinita about 3 years ago

Maybe not a new observation, but at least I wanted to note it:
I ran the tests on CircleCI in a loop (with a dummy fail and RETRY), and in the failing cases the output

ok 1 - warning logged
...

always appeared around 40 seconds after the note

# waiting at most 42 seconds for SIGCHLD (sleep is supposed to be interrupted by SIGCHLD)

So at least we know that the SIGCHLD is not interrupting the sleep in this case.

Full log of 20 runs:
https://app.circleci.com/pipelines/github/perlpunk/openQA/167/workflows/a5c11032-e6b3-4bf4-a548-70a029d0f4c0/jobs/743

Actions

Copy link

Updated by tinita about 3 years ago

I added more logging, and it appears that the SIGWARN handler setup in OpenQA::Test::Utils::_setup_sub_process is simply called before the SIGCHLD handler has been installed.

Actions

Copy link