QA » openQA Project

I could just reproduce the problem locally easily

I lost my statistics, trying again:

echo "### Before" && OPENQA_TEST_TIMEOUT_DISABLE=1 FULLSTACK=1 count_fail_ratio timeout 120 prove -l t/33-developer_mode.t && echo "### end of before" && git stash pop  && echo "### After" && OPENQA_TEST_TIMEOUT_DISABLE=1 FULLSTACK=1 count_fail_ratio timeout 120 prove -l t/33-developer_mode.t && echo "### end of after"

shows right now ## count_fail_ratio: Run: 20. Fails: 3. Fail ratio 15.00% for "before fix".

https://github.com/os-autoinst/openQA/pull/5137

By the way, the test is not fully stable hence it's correct that the test is in "unstable" tests. I just saw one occurence of

## Run 101
t/33-developer_mode.t .. 25/?
    #   Failed test 'log file generated under /tmp/abKc0gdL7l/developer-mode/openqa/testresults/00000/00000001-tinycore-1-flavor-i386-Build1-core@coolone/autoinst-log.txt'
    #   at t/33-developer_mode.t line 345.
    # Looks like you failed 1 test of 2.

#   Failed test 'test cancelled by quitting the session'
#   at t/33-developer_mode.t line 346.
t/33-developer_mode.t .. 27/? # Looks like you failed 1 test of 27.
t/33-developer_mode.t .. Dubious, test returned 1 (wstat 256, 0x100)
Failed 1/27 subtests

The according test code is:

339 subtest 'test cancelled by quitting the session' => sub {
340     $driver->switch_to_window($first_tab);
341     $driver->get($job_page_url);
342     ok wait_for_result_panel($driver, qr/(State: cancelled|Result: (user_cancelled|passed))/),
343       'test 1 has been cancelled (if it was fast enough to actually pass that is ok, too)';
344     my $log_file_path = path($resultdir, '00000', "00000001-$job_name")->make_path->child('autoinst-log.txt');
345     ok -s $log_file_path, "log file generated under $log_file_path";
346 };

Talked about the topic within the daily 2023-05-16. I am trying to reproduce the problem with a simpler test:

25 $driver->click_element_ok('Login', 'link_text');
26 while (1) {
27     $driver->get('/logout');
28     $driver->get('/login?user=otherdeveloper');
29     $driver->element_text_is('#user-action a', 'Logged in as otherdeveloper', 'otherdeveloper logged-in');
30 }

Results after running that for 3h: 4/22959=0.0174% fails so way less than in the original test where maybe the openQA instance is "more busy" to process the logout/login. I don't consider this that useful for reproduction. However let me still try to use it with get_ok as variant.

Current state 0/(26000/3) fails. Calculation is "/3" as there are three test messages for logout&login

PR merged, back to https://github.com/os-autoinst/openQA/pull/5137

PR is clean, CI jobs passed. Local execution

echo "### Before" && OPENQA_TEST_TIMEOUT_DISABLE=1 FULLSTACK=1 runs=1000 count_fail_ratio timeout 120 prove -l t/33-developer_mode.t && echo "### end of before" && git co fix/developer_t && echo "### After" && OPENQA_TEST_TIMEOUT_DISABLE=1 FULLSTACK=1 runs=1000 count_fail_ratio timeout 120 prove -l t/33-developer_mode.t && echo "### end of after"

Before fix (aborted prematurely)
"## count_fail_ratio: Run: 53. Fails: 7. Fail ratio 13.00±0%"
After
"## count_fail_ratio: Run: 24. Fails: 4. Fail ratio 16.66±14.91%"

So no effect. I need further ideas what to do.

mkittler wrote:

Even when introducing a 5 seconds delay to /logout or to / (which /logout redirects to) this issue is not locally reproducible.

Have you seen my results in #128807-13 regarding reproduction rate? That was on my Leap 15.4 x86_64 notebook. Did you try a reasonable big sample size? Maybe your Tumbleweed(?) instance has different reproduction rates? Maybe Tumbleweed actually has a fix?

I was and I am still aiming for a stable reproducer. We have to figure out the conditions/problems that lead to this situation so we can fix the problem. If that doesn't work I would just introduce a retry loop.