Skip to content

Commit

Permalink
Mitigate gotest bug with missing end events
Browse files Browse the repository at this point in the history 
Previously all missing events were reported. This commit omits events
for any missed subtests, so that subtests that passed do not show as
failed.

The upstream bug was fixed in go1.16, so this mitigation probably does
not need to stick around for long.

Co-Authored-By: Aaron Lehmann <alehmann@netflix.com>
  • Loading branch information
@dnephin @aaronlehmann
dnephin and aaronlehmann committed Apr 17, 2021
1 parent 50d8cb4 commit e91cbd9
Show file tree
Hide file tree
Showing 3 changed files with 118 additions and 10 deletions.
40 changes: 35 additions & 5 deletions testjson/execution.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -73,8 +73,8 @@ type Package struct {
Passed []TestCase

// mapping of root TestCase ID to all sub test IDs. Used to mitigate
// github.com/golang/go/issues/29755.
// In the future when that bug is fixed this mapping can likely be removed.
// github.com/golang/go/issues/29755, and github.com/golang/go/issues/40771.
// In the future when those bug are fixed this mapping can likely be removed.
subTests map[int][]int

// output printed by test cases, indexed by TestCase.ID. Package output is
Expand Down Expand Up @@ -221,6 +221,12 @@ const neverFinished time.Duration = -1
func (p *Package) end() []TestEvent {
result := make([]TestEvent, 0, len(p.running))
for k, tc := range p.running {
if tc.Test.IsSubTest() && rootTestPassed(p, tc) {
// mitigate github.com/golang/go/issues/40771 (gotestsum/issues/141)
// by skipping missing subtest end events when the root test passed.
continue
}

tc.Elapsed = neverFinished
p.Failed = append(p.Failed, tc)

Expand All @@ -235,6 +241,32 @@ func (p *Package) end() []TestEvent {
return result
}

// rootTestPassed looks for the root test associated with subtest and returns
// true if the root test passed. This is used to mitigate
// github.com/golang/go/issues/40771 (gotestsum/issues/141) and may be removed
// in the future since that issue was patched in go1.16.
//
// This function is slightly expensive because it has to scan every test in the
// package, but it should only run in the rare case where a subtest was missing
// an end event. Spending a little more time in that rare case is probably better
// than keeping extra mapping of tests in all cases.
func rootTestPassed(p *Package, subtest TestCase) bool {
root, _ := subtest.Test.Split()

for _, tc := range p.Passed {
if tc.Test.Name() != root {
continue
}

for _, subID := range p.subTests[tc.ID] {
if subID == subtest.ID {
return true
}
}
}
return false
}

// TestCase stores the name and elapsed time for a test case.
type TestCase struct {
// ID is unique ID for each test case. A test run may include multiple instances
Expand Down Expand Up @@ -343,7 +375,7 @@ func (p *Package) addTestEvent(event TestEvent) {
return
}

// the event.Action must be one of the three test end events
// the event.Action must be one of the three "test end" events
delete(p.running, event.Test)
tc.Elapsed = elapsedDuration(event.Elapsed)

Expand Down Expand Up @@ -373,8 +405,6 @@ func (p *Package) addTestEvent(event TestEvent) {

// Remove test output once a test passes, it wont be used.
p.removeOutput(tc.ID)
// Remove subtest mapping, it is only used when a test fails.
delete(p.subTests, tc.ID)
}
}

Expand Down
51 changes: 46 additions & 5 deletions testjson/execution_test.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -115,11 +115,6 @@ func TestPackage_AddEvent(t *testing.T) {
expected Package
}

var cmpPackage = cmp.Options{
cmp.AllowUnexported(Package{}),
cmpopts.EquateEmpty(),
}

run := func(t *testing.T, tc testCase) {
te, err := parseEvent([]byte(tc.event))
assert.NilError(t, err)
Expand Down Expand Up @@ -176,3 +171,49 @@ func TestPackage_AddEvent(t *testing.T) {
func pkgOutput(id int, line string) map[int][]string {
return map[int][]string{id: {line}}
}

func TestScanOutput_WithMissingEvents(t *testing.T) {
source := golden.Get(t, "go-test-json-missing-test-events.out")
handler := &captureHandler{}
cfg := ScanConfig{
Stdout: bytes.NewReader(source),
Handler: handler,
}
_, err := ScanTestOutput(cfg)
assert.NilError(t, err)

var cmpTestEventShallow = cmp.Options{
cmp.Comparer(func(x, y TestEvent) bool {
return x.Test == y.Test && x.Action == y.Action && x.Elapsed == y.Elapsed
}),
cmpopts.SortSlices(func(x, y TestEvent) bool {
return x.Test < y.Test
}),
}

// the package end event should come immediately before the artificial events
expected := []TestEvent{
{Action: ActionPass},
{Action: ActionFail, Test: "TestMissing", Elapsed: -1},
{Action: ActionFail, Test: "TestMissing/a", Elapsed: -1},
{Action: ActionFail, Test: "TestMissingEvent", Elapsed: -1},
{Action: ActionFail, Test: "TestFailed/a", Elapsed: -1},
{Action: ActionFail, Test: "TestFailed/a/sub", Elapsed: -1},
}
assert.Assert(t, len(handler.events) > len(expected))
start := len(handler.events) - len(expected)
assert.DeepEqual(t, expected, handler.events[start:], cmpTestEventShallow)
}

type captureHandler struct {
events []TestEvent
}

func (s *captureHandler) Event(event TestEvent, _ *Execution) error {
s.events = append(s.events, event)
return nil
}

func (s *captureHandler) Err(text string) error {
return fmt.Errorf(text)
}
37 changes: 37 additions & 0 deletions testjson/testdata/go-test-json-missing-test-events.out
View file
Original file line number Diff line number Diff line change
@@ -0,0 +1,37 @@
{"Time":"2021-04-17T14:33:35.167978423Z","Action":"run","Package":"gotest.tools/testing","Test":"TestPassed"}
{"Time":"2021-04-17T14:33:35.167999152Z","Action":"output","Package":"gotest.tools/testing","Test":"TestPassed","Output":"=== RUN TestPassed\n"}
{"Time":"2021-04-17T14:33:35.168007043Z","Action":"output","Package":"gotest.tools/testing","Test":"TestPassed","Output":"--- PASS: TestPassed (0.00s)\n"}
{"Time":"2021-04-17T14:33:35.16801113Z","Action":"pass","Package":"gotest.tools/testing","Test":"TestPassed","Elapsed":0}
{"Time":"2021-04-17T14:33:35.167978423Z","Action":"run","Package":"gotest.tools/testing","Test":"TestMissingEvent"}
{"Time":"2021-04-17T14:33:35.167999152Z","Action":"output","Package":"gotest.tools/testing","Test":"TestMissingEvent","Output":"=== RUN TestMissingEvent\n"}
{"Time":"2021-04-17T14:33:35.168007043Z","Action":"output","Package":"gotest.tools/testing","Test":"TestMissingEvent","Output":"--- PASS: TestMissingEvent (0.00s)\n"}
{"Time":"2021-04-17T14:33:35.168147969Z","Action":"run","Package":"gotest.tools/testing","Test":"TestNestedSuccess"}
{"Time":"2021-04-17T14:33:35.168150995Z","Action":"output","Package":"gotest.tools/testing","Test":"TestNestedSuccess","Output":"=== RUN TestNestedSuccess\n"}
{"Time":"2021-04-17T14:33:35.168155447Z","Action":"run","Package":"gotest.tools/testing","Test":"TestNestedSuccess/a"}
{"Time":"2021-04-17T14:33:35.168158403Z","Action":"output","Package":"gotest.tools/testing","Test":"TestNestedSuccess/a","Output":"=== RUN TestNestedSuccess/a\n"}
{"Time":"2021-04-17T14:33:35.168161668Z","Action":"run","Package":"gotest.tools/testing","Test":"TestNestedSuccess/a/sub"}
{"Time":"2021-04-17T14:33:35.168164766Z","Action":"output","Package":"gotest.tools/testing","Test":"TestNestedSuccess/a/sub","Output":"=== RUN TestNestedSuccess/a/sub\n"}
{"Time":"2021-04-17T14:33:35.168168123Z","Action":"run","Package":"gotest.tools/testing","Test":"TestNestedSuccess/b"}
{"Time":"2021-04-17T14:33:35.168170964Z","Action":"output","Package":"gotest.tools/testing","Test":"TestNestedSuccess/b","Output":"=== RUN TestNestedSuccess/b\n"}
{"Time":"2021-04-17T14:33:35.168174253Z","Action":"run","Package":"gotest.tools/testing","Test":"TestNestedSuccess/b/sub"}
{"Time":"2021-04-17T14:33:35.168177104Z","Action":"output","Package":"gotest.tools/testing","Test":"TestNestedSuccess/b/sub","Output":"=== RUN TestNestedSuccess/b/sub\n"}
{"Time":"2021-04-17T14:33:35.16820637Z","Action":"output","Package":"gotest.tools/testing","Test":"TestNestedSuccess","Output":"--- PASS: TestNestedSuccess (0.00s)\n"}
{"Time":"2021-04-17T14:33:35.168210256Z","Action":"output","Package":"gotest.tools/testing","Test":"TestNestedSuccess/a","Output":" --- PASS: TestNestedSuccess/a (0.00s)\n"}
{"Time":"2021-04-17T14:33:35.168213987Z","Action":"output","Package":"gotest.tools/testing","Test":"TestNestedSuccess/a/sub","Output":" --- PASS: TestNestedSuccess/a/sub (0.00s)\n"}
{"Time":"2021-04-17T14:33:35.168217438Z","Action":"pass","Package":"gotest.tools/testing","Test":"TestNestedSuccess/a/sub","Elapsed":0}
{"Time":"2021-04-17T14:33:35.168222153Z","Action":"pass","Package":"gotest.tools/testing","Test":"TestNestedSuccess/a","Elapsed":0}
{"Time":"2021-04-17T14:33:35.16826478Z","Action":"pass","Package":"gotest.tools/testing","Test":"TestNestedSuccess","Elapsed":0}
{"Time":"2021-04-17T14:33:35.168147969Z","Action":"run","Package":"gotest.tools/testing","Test":"TestFailed"}
{"Time":"2021-04-17T14:33:35.168150995Z","Action":"output","Package":"gotest.tools/testing","Test":"TestFailed","Output":"=== RUN TestFailed\n"}
{"Time":"2021-04-17T14:33:35.168155447Z","Action":"run","Package":"gotest.tools/testing","Test":"TestFailed/a"}
{"Time":"2021-04-17T14:33:35.168158403Z","Action":"output","Package":"gotest.tools/testing","Test":"TestFailed/a","Output":"=== RUN TestFailed/a\n"}
{"Time":"2021-04-17T14:33:35.168161668Z","Action":"run","Package":"gotest.tools/testing","Test":"TestFailed/a/sub"}
{"Time":"2021-04-17T14:33:35.168164766Z","Action":"output","Package":"gotest.tools/testing","Test":"TestFailed/a/sub","Output":"=== RUN TestFailed/a/sub\n"}
{"Time":"2021-04-17T14:33:35.16826478Z","Action":"fail","Package":"gotest.tools/testing","Test":"TestFailed","Elapsed":0}
{"Time":"2021-04-17T14:33:35.168147969Z","Action":"run","Package":"gotest.tools/testing","Test":"TestMissing"}
{"Time":"2021-04-17T14:33:35.168150995Z","Action":"output","Package":"gotest.tools/testing","Test":"TestMissing","Output":"=== RUN TestMissing\n"}
{"Time":"2021-04-17T14:33:35.168155447Z","Action":"run","Package":"gotest.tools/testing","Test":"TestMissing/a"}
{"Time":"2021-04-17T14:33:35.168158403Z","Action":"output","Package":"gotest.tools/testing","Test":"TestMissing/a","Output":"=== RUN TestMissing/a\n"}
{"Time":"2021-04-17T14:33:35.168308334Z","Action":"output","Package":"gotest.tools/testing","Output":"PASS\n"}
{"Time":"2021-04-17T14:33:35.168311492Z","Action":"output","Package":"gotest.tools/testing","Output":"ok \tgotest.tools/testing\t(cached)\n"}
{"Time":"2021-04-17T14:33:35.168316085Z","Action":"pass","Package":"gotest.tools/testing","Elapsed":0}

0 comments on commit e91cbd9

Please sign in to comment.