diff --git a/testjson/execution.go b/testjson/execution.go index 24790246..6e3dad34 100644 --- a/testjson/execution.go +++ b/testjson/execution.go @@ -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 @@ -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) @@ -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 @@ -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) @@ -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) } } diff --git a/testjson/execution_test.go b/testjson/execution_test.go index f52daff5..9fc316bc 100644 --- a/testjson/execution_test.go +++ b/testjson/execution_test.go @@ -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) @@ -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) +} diff --git a/testjson/testdata/go-test-json-missing-test-events.out b/testjson/testdata/go-test-json-missing-test-events.out new file mode 100644 index 00000000..5f080e3d --- /dev/null +++ b/testjson/testdata/go-test-json-missing-test-events.out @@ -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} \ No newline at end of file