Issue #100: CI tests run completes with status "SUCCESS" even though 1 test failed - general

fedora-ci / general

#100 CI tests run completes with status "SUCCESS" even though 1 test failed

Closed 4 years ago by msrb. Opened 4 years ago by tstellar.

This has been happening with the CI tests for the clang package e.g. https://jenkins-continuous-infra.apps.ci.centos.org/view/Fedora%20All%20Packages%20Pipeline/job/fedora-rawhide-pr-pipeline/2855/

The test run completes with SUCCESS even though the clang-rhbz_1657544 test fails.

jimbair commented 4 years ago

I do see the FAIL in both the console output as well as the artifacts:
https://jenkins-continuous-infra.apps.ci.centos.org/view/Fedora%20All%20Packages%20Pipeline/job/fedora-rawhide-pr-pipeline/2855/artifact/package-tests/logs/FAIL-str_clang-rhbz_1657544.log

06:18:21  TASK [standard-test-basic : Check the results] *********************************
06:18:21  changed: [/workDir/workspace/fedora-rawhide-pr-pipeline/images/test_subject.qcow2] => changed=true 
06:18:21    cmd: |-
06:18:21      log="/tmp/artifacts//test.log"
06:18:21      if [ ! -f "$log" ]; then
06:18:21          echo ERROR
06:18:21          echo "Test results not found." 1>&2
06:18:21      elif grep ^ERROR "$log" 1>&2; then
06:18:21          echo ERROR
06:18:21      elif grep ^FAIL "$log" 1>&2; then
06:18:21          echo FAIL
06:18:21      elif grep -q ^PASS "$log"; then
06:18:21          echo PASS
06:18:21      else
06:18:21          echo ERROR
06:18:21          echo "No test results found." 1>&2
06:18:21      fi
06:18:21    delta: '0:00:00.011938'
06:18:21    end: '2020-03-15 11:18:21.560883'
06:18:21    rc: 0
06:18:21    start: '2020-03-15 11:18:21.548945'
06:18:21    stderr: FAIL clang/rhbz_1657544
06:18:21    stderr_lines: <omitted>
06:18:21    stdout: FAIL
06:18:21    stdout_lines: <omitted>
06:18:21  
06:18:21  TASK [standard-test-basic : Set role result] ***********************************
06:18:21  ok: [/workDir/workspace/fedora-rawhide-pr-pipeline/images/test_subject.qcow2] => changed=false 
06:18:21    ansible_facts:
06:18:21      role_message: FAIL clang/rhbz_1657544
06:18:21      role_result: FAIL
06:18:21  
06:18:21  TASK [include_role : str-common-final] *****************************************
06:18:21  
06:18:21  TASK [str-common-final : Pull out the logs from test environment to test runner] ***
06:18:22  changed: [/workDir/workspace/fedora-rawhide-pr-pipeline/images/test_subject.qcow2] => changed=true 
06:18:22    cmd: sshpass -d3 /usr/bin/rsync --delay-updates -F --compress --archive --rsh=/usr/bin/ssh -S none -i /tmp/inventory-cloud2no8g0b5/identity -o Port=4115 -o StrictHostKeyChecking=no -o UserKnownHostsFile=/dev/null -o UserKnownHostsFile=/dev/null --out-format=<<CHANGED>>%i %n%L root@127.0.0.3:/tmp/artifacts// /workDir/workspace/fedora-rawhide-pr-pipeline/logs/
06:18:22    msg: |-
06:18:22      .d..t...... ./
06:18:22      >f+++++++++ FAIL-str_clang-rhbz_1657544.log
06:18:22      >f+++++++++ PASS-str_clang-llvm-toolchain.log
06:18:22      >f+++++++++ PASS-str_clang-rhbz_1647130.log
06:18:22      >f+++++++++ PASS-str_llvm-test-suite-abi-test-suite.log
06:18:22      >f+++++++++ PASS-str_llvm-test-suite-test-suite.log
06:18:22      >f+++++++++ PASS-str_rhbz#482491.log
06:18:22      >f+++++++++ results.yml
06:18:22      >f+++++++++ test.log
06:18:22    rc: 0
06:18:22    stdout_lines:
06:18:22    - .d..t...... ./
06:18:22    - '>f+++++++++ FAIL-str_clang-rhbz_1657544.log'
06:18:22    - '>f+++++++++ PASS-str_clang-llvm-toolchain.log'
06:18:22    - '>f+++++++++ PASS-str_clang-rhbz_1647130.log'
06:18:22    - '>f+++++++++ PASS-str_llvm-test-suite-abi-test-suite.log'
06:18:22    - '>f+++++++++ PASS-str_llvm-test-suite-test-suite.log'
06:18:22    - '>f+++++++++ PASS-str_rhbz#482491.log'
06:18:22    - '>f+++++++++ results.yml'
06:18:22    - '>f+++++++++ test.log'
06:18:22  
06:18:22  TASK [str-common-final : Report role result] ***********************************
06:18:22  ok: [/workDir/workspace/fedora-rawhide-pr-pipeline/images/test_subject.qcow2] => 
06:18:22    msg:
06:18:22    - 'Result: FAIL'
06:18:22    - FAIL clang/rhbz_1657544
06:18:22    - ''
06:18:22

I know that we did some work to change pipelines to not fail in a red state when a test failed, but it should be yellow I think? And the linked job is green, which seems odd. I need to do some looking, but I just wanted to confirm what you're seeing and share what I found with my initial inspection.

tstellar commented 4 years ago

Here is a better example of what I'm seeing:

If you look at this pull request, the CI results reports as Pass: https://src.fedoraproject.org/rpms/clang/pull-request/55

But when I click through to the jenkins job and look at the artifacts, it lists 2 tests as failing:

https://jenkins-continuous-infra.apps.ci.centos.org/blue/organizations/jenkins/fedora-f32-pr-pipeline/detail/fedora-f32-pr-pipeline/35/artifacts

jimbair commented 4 years ago

Yeah, I need to see what logic sets the report on the PR as pass/fail vs the jenkins job. The only change we made recently was to add 1 package into the image to support fonts. I'm not familiar with the logic, so I'll need to figure out what's making the decision and why it's not seeing the failures (unless another fedora ci member jumps in before I figure it out). =)

Metadata Update from @jimbair:
- Issue assigned to jimbair

4 years ago

jimbair commented 4 years ago

Monday follow-up; we are still looking into it, but haven't pin-pointed the issue yet. I'm taking the ticket to ensure we keep up on it, and as we have more updates, I'll post them here!

I know one idea was there are two testing yamls in the repo, though with different names, possibly with logic having one overwrite the others results? That shouldn't happen, but one thought that came up in this morning's IRC discussions.