Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Mitigate go test bug with missing subtest pass events #191

Merged
merged 1 commit into from
Apr 18, 2021
Merged

Mitigate go test bug with missing subtest pass events #191

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
1 commit
Select commit
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
40 changes: 35 additions & 5 deletions testjson/execution.go
View file
Open in desktop
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
Open in desktop
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
Open in desktop
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}