Bug #16150

After hooks should be able to mark the scenario as failed in Jenkins Cucumber report

Added by bertagaz 2018-11-23 15:23:13 . Updated 2019-09-22 16:12:29 .

Status:
Confirmed
Priority:
Normal
Assignee:
Category:
Continuous Integration
Target version:
Start date:
2018-11-23
Due date:
% Done:

0%

Feature Branch:
Type of work:
Test
Blueprint:

Starter:
Affected tool:
Deliverable for:

Description

While noticing Bug #16148, it appeared that a failing @check_tor_leaks hook does not mark the concerned scenario as failed in Cucumber’s JSON output. This is only about the JSON output: on the stdout/stderr and exit code front, the test suite and Cucumber bits behave as intended and the scenario is correctly considered as failed.

The Cucumber JSON output only records per-step status, not per-scenario status, and it does not take into account the After('product’, ’check_tor_leaks') cucumber hook that runs our code. This leads to bad and misleading reporting by the Jenkins cucumber report plugin, that relies on Cucumber’s JSON output. We should make it so that a failing check_tor_leaks hook ensure the scenario is recorded as failed in Cucumber’s JSON output.

Files

cucumber.json (195 B) intrigeri, 2018-11-24 05:14:49

Subtasks

Related issues

Related to Tails - Feature #9424: Support all cucumber formatters Resolved 2015-05-18
Related to Tails - Bug #16959: Gather usability data about our current CI In Progress
Has duplicate Tails - Bug #16768: Failing scenarios in After scenario hooks can lead to inconsistency Duplicate
Blocked by Tails - Bug #17080: Upgrade Cucumber on Jenkins isotesters Resolved

History

#1 Updated by intrigeri 2018-11-23 16:22:03

  • Assignee set to bertagaz
  • QA Check set to Info Needed

bertagaz wrote:
> We should make it so that a failing @check_tor_leaks hook ensure the scenario is considered as failed by cucumber.

Well, at least on the stdout/stderr and exit code front, the test suite and Cucumber bits behave as intended and the scenario is considered as failed. On https://jenkins.tails.boum.org/view/Tails_ISO/job/test_Tails_ISO_feature-14596-automated-tests-for-asp-gui-on-stable/70/console I see:

17:56:19 Failing Scenarios:
17:56:19 cucumber features/additional_software_packages.feature:87 # Scenario: Recovering in offline mode after Additional Software previously failed to upgrade and then succeed to upgrade when online
17:56:19 
17:56:19 175 scenarios (1 failed, 174 passed)
17:56:19 1266 steps (1266 passed)
17:56:19 258m38.495s
17:56:23 Build step 'Execute shell' marked build as failure

So the way we do things in a hook seems to be at least somewhat supported by Cucumber. That’s good news :)

Then, to tell whether this is a Cucumber or Jenkins bug, the question is: is the JSON output buggy or is the Jenkins plugin failing to understanding it?

#2 Updated by intrigeri 2018-11-23 16:22:25

  • Description updated

#3 Updated by bertagaz 2018-11-23 16:48:29

intrigeri wrote:
> bertagaz wrote:
> > We should make it so that a failing @check_tor_leaks hook ensure the scenario is considered as failed by cucumber.
>
> Well, at least on the stdout/stderr and exit code front, the test suite and Cucumber bits behave as intended and the scenario is considered as failed. On https://jenkins.tails.boum.org/view/Tails_ISO/job/test_Tails_ISO_feature-14596-automated-tests-for-asp-gui-on-stable/70/console I see:
>
> […]
>
> So the way we do things in a hook seems to be at least somewhat supported by Cucumber. That’s good news :)
>
> Then, to tell whether this is a Cucumber or Jenkins bug, the question is: is the JSON output buggy or is the Jenkins plugin failing to understanding it?

Sorry if I was sloppy, I’ve checked that before reporting and indeed the cucumber json is buggy :

        "keyword":"Scenario",
        "name":"Recovering in offline mode after Additional Software previously failed to upgrade \
   and then succeed to upgrade when online",
        "line":65,
        "description":"",
        "type":"scenario",
[...]
            "result":{
              "status":"passed",
              "duration":814261910
            },
            "output":[
              "Scenario failed at time 02:56:48",
              "",[...]
            ]
          }

#4 Updated by intrigeri 2018-11-24 05:19:10

  • related to Feature #9424: Support all cucumber formatters added

#5 Updated by intrigeri 2018-11-24 05:55:37

  • File cucumber.json added
  • Subject changed from FirewallAssertionFailedError should mark the scenario as failing to FirewallAssertionFailedError should mark the scenario as failed in Jenkins Cucumber report
  • Description updated
  • Category changed from Test suite to Continuous Integration
  • Assignee deleted (bertagaz)
  • Target version deleted (Tails_3.11)
  • QA Check deleted (Info Needed)

To be clear, the Cucumber JSON output does not include per-scenario status: as the indentation suggests and a closer look at the JSON data demonstrates, this "result":{ "status":"passed" is about the last step of the scenario, not about the scenario as a whole; as you said, the code run in the After hook is not a step and not part of the scenario, so indeed that info is missing in the JSON and that does not qualify as a Cucumber bug :/ Ouch! It’s unfortunate that we did not notice that limitation when we started relying on this JSON output while using After hooks to perform additional tests; but this is totally understandable: the bug only happens in corner cases and it took us 3.5 years to notice the problem at all.

Adjusting metadata:

  • CI because:
    • Only CI is affected.
    • The After hook predates the choice of using the JSON output.
    • The reliance on the JSON output is 100% prompted by Jenkins plugin ecosystem. Were we using the junit or html output, we would not be affected. BTW, if that HTML is good enough, we could use that and ditch the Cucumber Jenkins plugin. Note that the Cucumber output landscape is going to change drastically (https://github.com/cucumber/cucumber/issues/415, https://github.com/cucumber/cucumber/issues/524) at some point.
    • AFAIK Cucumber provides no other way to do what we need here, so I don’t think we can workaround this problem in the test suite itself, short of explicitly adding a step to every scenario that needs check_tor_leaks, which is too noisy and error-prone (it will be forgotten now and then).
  • No target version because thankfully, the entire test suite run is marked as failed anyway, so there’s a chance that one notices the issue (if that’s the only failure: by looking at the console output; if there are more failures: because of the extra build artifacts).

#7 Updated by intrigeri 2019-06-01 08:42:32

  • has duplicate Bug #16768: Failing scenarios in After scenario hooks can lead to inconsistency added

#8 Updated by anonym 2019-06-06 13:15:55

  • Subject changed from FirewallAssertionFailedError should mark the scenario as failed in Jenkins Cucumber report to After hooks should be able to mark the scenario as failed in Jenkins Cucumber report

Reported upstream: https://github.com/cucumber/cucumber/issues/630

#9 Updated by anonym 2019-06-28 10:31:06

anonym wrote:
> Reported upstream: https://github.com/cucumber/cucumber/issues/630

For some reason it was moved to cucumber-jvm and someone tested but couldn’t reproduce. So I tried to make my own minimal test case for cucumber-ruby:

mkdir cucumber-test
cd cucumber-test
cucumber --init
cat > features/test.feature <<EOF
Feature: Test feature
  Scenario: Test scenario
    Given something
    Then whatever
EOF
cat > features/step_definitions/test.rb <<EOF
Given /^.*$/ do
  next
end
EOF
cat > features/support/hooks.rb <<EOF
# Note: Cucumber After hooks are executed in the *reverse* order they are
# listed
After do |scenario|
  # Check stderr for this to know the final status
  STDERR.puts "Scenario status: #{scenario.failed? ? "failed" : "passed"}"
end
After do
  raise "fail"
end
EOF
cucumber --format json features/test.feature

This results in:

Scenario status: failed
[
  {
    "uri": "features/test.feature",
    "id": "test-feature",
    "keyword": "Feature",
    "name": "Test feature",
    "description": "",
    "line": 1,
    "elements": [ 
      {
        "id": "test-feature;test-scenario",
        "keyword": "Scenario",
        "name": "Test scenario",
        "description": "",
        "line": 2,
        "type": "scenario",
        "before": [
          {
            "match": {
              "location": "/usr/lib/ruby/vendor_ruby/cucumber/filters/prepare_world.rb:27"
            },
            "result": {
              "status": "passed",
              "duration": 1598
            }
          }
        ],
        "steps": [
          {
            "keyword": "Given ",
            "name": "something",
            "line": 3,
            "match": {
              "location": "features/step_definitions/test.rb:1"
            },
            "result": {
              "status": "passed",
              "duration": 21578
            }
          },
          {
            "keyword": "Then ",
            "name": "whatever",
            "line": 4,
            "match": {
              "location": "features/step_definitions/test.rb:1"
            },
            "result": {
              "status": "passed",
              "duration": 7378
            }
          }
        ],
        "after": [
          {
            "match": {
              "location": "features/support/hooks.rb:7"
            },
            "result": {
              "status": "failed",
              "error_message": "fail (RuntimeError)\n./features/support/hooks.rb:8:in `After'",
              "duration": 80566
            }
          },
          {
            "match": {
              "location": "features/support/hooks.rb:3"
            },
            "result": {
              "status": "passed",
              "duration": 115039
            }
          }
        ]
      }
    ]
  }
]

Note the "after" field, which records the error. So it seems something is wrong with our particular test suite, after all. I quickly tried dropping in our extra_hooks.rb since it monkey-patches cucumber and certainly could be the culprit, but I still couldn’t reproduce the absence of the "after" field.

Next step is to run our test suite and progressively rip out parts and see when the "after" field reappears.

#10 Updated by intrigeri 2019-09-01 13:27:26

  • related to Bug #16959: Gather usability data about our current CI added

#11 Updated by intrigeri 2019-09-21 08:49:06

It would be interesting to know which version of cucumber was used in anonym’s tests: there’s a (small?) chance that he could not reproduce the issue because he was using cucumber 2.x, while our Jenkins testers run Jessie’s 1.3.

#12 Updated by intrigeri 2019-09-21 08:49:41

  • related to Bug #17080: Upgrade Cucumber on Jenkins isotesters added

#13 Updated by intrigeri 2019-09-22 04:37:55

  • Type of work changed from Code to Sysadmin

OK, I think I understood what’s going on. While working on Bug #17080 I’ve read https://issues.jenkins-ci.org/browse/JENKINS-29328, which explains that:

  • Cucumber up to 2.0.0 does not store before/after info in the JSON, which is why we have the problem this ticket is about in our CI; confirmed by looking at JSON on Jenkins.
  • Cucumber 2.0.1 and newer does store before/after info in the JSON, which is why anonym could not reproduce the bug.

So, to fix this bug, we need to:

  • do Bug #17080 in a way that preserves before/after info in the JSON; at this point, it’s not clear whether that will be possible but there’s a PR
  • ensure that whatever Jenkins plugin/UI we use to report Cucumber results correctly reports failure when before/after steps that are executed as part of Background fail; the PR does not fix that

#14 Updated by intrigeri 2019-09-22 04:38:09

  • related to deleted (Bug #17080: Upgrade Cucumber on Jenkins isotesters)

#15 Updated by intrigeri 2019-09-22 04:38:15

  • blocked by Bug #17080: Upgrade Cucumber on Jenkins isotesters added

#16 Updated by intrigeri 2019-09-22 16:12:29

  • Type of work changed from Sysadmin to Test

We’ve switched to Cucumber 2.4.0 on our CI, with the “Cucumber Reports” Jenkins plugin (Bug #17080#note-12). In the reports produced by this plugin, I see all the steps we run, including the “special” ones that matter here such as:

  • Before hooks run as part of Background
  • After hooks

So there’s some hope that the problem this ticket is about is now fixed. I did not test it though. It should be rather easy to create a minimal test case for this, if someone is interested.

Note that these “special” steps are not rendered very nicely: for example, I see After features/support/hooks.rb:333. That’s expected as these hooks have no name defined in our code base.