False positive when sending SIGTERM to Ginkgo test suite

Question

While writing tests using Ginkgo framework I noticed, that pressing C-c to terminate a running suite generates false positive.

note the green "1 Passed"

When you look at the code you will notice this test should fail after 5 seconds. When I terminate it after 2 seconds, the suite fails, but in the results, there is 1 passed test and 0 failed.

Same behavior for go versions 1.11.4 and 1.12.4 on Debian Stretch and Ubuntu 18.04.

Suite code (autogenerated using ginkgo bootstrap):

package hmmm_test

import (
    "testing"

    . "github.com/onsi/ginkgo"
    . "github.com/onsi/gomega"
)

func TestHmmm(t *testing.T) {
    RegisterFailHandler(Fail)
    RunSpecs(t, "Hmmm Suite")
}

Test code:

package hmmm_test

import (
    "time"

    . "github.com/onsi/ginkgo"
    . "github.com/onsi/gomega"
)

var _ = Describe("Hmmm", func() {
    Context("Dummy test", func() {
        It("should fail after 5 seconds", func() {
            time.Sleep(5 * time.Second)
            Expect(1).NotTo(Equal(1))
        })
    })
})

Output when the test runs for 5 seconds (correct one):

$ ginkgo

Running Suite: Hmmm Suite
=========================
Random Seed: 1555580607
Will run 1 of 1 specs
• Failure [5.001 seconds]
Hmmm
/tmp/hmmm/hmmm_test.go:10
  Dummy test
  /tmp/hmmm/hmmm_test.go:11
    should fail after 5 seconds [It]
    /tmp/hmmm/hmmm_test.go:12
    Expected
        <int>: 1
    not to equal
        <int>: 1
    /tmp/hmmm/hmmm_test.go:14
------------------------------
Summarizing 1 Failure:
[Fail] Hmmm Dummy test [It] should fail after 5 seconds
/tmp/hmmm/hmmm_test.go:14
Ran 1 of 1 Specs in 5.002 seconds
FAIL! -- 0 Passed | 1 Failed | 0 Pending | 0 Skipped
--- FAIL: TestHmmm (5.00s)
FAIL
Ginkgo ran 1 suite in 5.665592703s
Test Suite Failed

Output when the test is terminated before it finishes (false positive):

$ ginkgo

Running Suite: Hmmm Suite
=========================
Random Seed: 1555580763
Will run 1 of 1 specs
^C
Ran 1 of 1 Specs in 1.187 seconds
FAIL! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped
Ginkgo ran 1 suite in 1.85541211s
Test Suite Failed

I expect the output to be something like: FAIL! -- 0 Passed | 1 Failed | 0 Pending | 0 Skipped Or 1 skipped or pending, but not Passed especially that the test is written to fail.

Actual output suggests failure, but also that all tests... passed: FAIL! -- 1 Passed | 0 Failed | 0 Pending | 0 Skipped

Am I missing something?

I don't understand why you find this surprising. Obviously the test doesn't fail before 5 seconds have passed, so there shouldn't be a failure before that. One could argue that Ginkgo should always fail if it's interrupted, but you'll have to take that to the issue tracker. — Peter, Apr 18 '19 at 09:54
As I said don't strictly expect failure - it could be reported as `Pending` or even `Skipped`, but I certainly would not expect `Passed` to be the outcome. Anyways, I will link this to Ginkgo issue tracker and see what they say. — karmazyn, Apr 18 '19 at 10:44

score 0 · Answer 1 · answered Apr 18 '19 at 14:34

This is expected behaviour, but I wouldn't necessarily claim it was intentional, clear or correct. This occurs because tests start their running lifecycle as passing¹ and change states on other events (failure/panic).

When Ginkgo receives a SIGTERM it won't stop the currently running test (though it will prevent any more tests from running²). In parallel, it will collect a report for the tests that have run so far³. This collection will iterate over any nodes that have begun "processing"⁴ (loosely correlated with but starting slightly earlier than running). As the test started in a passed state and that has not changed, it is reported as passed.

This question is not the place to discuss the validity of this approach (and there may well be a better one). Please use the issue that you opened if you would like to request a change to this behaviour⁵.

False positive when sending SIGTERM to Ginkgo test suite

1 Answers1