Skip to content

Commit

Permalink
Merge pull request #191 from dnephin/handle-missing-subtest-pass-event
Browse files Browse the repository at this point in the history
Mitigate go test bug with missing subtest pass events
  • Loading branch information
dnephin committed Apr 18, 2021
2 parents 9ad60eb + e91cbd9 commit bb9679f
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
Original file line number Diff line number Diff line change
Expand Up @@ -83,8 +83,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 @@ -239,6 +239,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 @@ -253,6 +259,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 @@ -361,7 +393,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 @@ -391,8 +423,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
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
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 bb9679f

Please sign in to comment.