From db873a26115f2ce6bc1a3bbf4c5bbcfa7fd7a199 Mon Sep 17 00:00:00 2001 From: Daniel Nephin Date: Fri, 10 Apr 2020 16:31:56 -0400 Subject: [PATCH] Print incomplete tests as failures If a test panics it may never send a final ActionFail event. By tracking the running tests we can add any incomplete tests to Failed when the execution ends. This behaviour changed in go1.14. See https://github.com/golang/go/issues/38382#issuecomment-613003598 --- testjson/execution.go | 66 +++++++++++++------ testjson/execution_test.go | 1 + testjson/format_test.go | 16 +++-- testjson/summary.go | 5 +- testjson/summary_test.go | 26 ++++++++ .../go-test-json-missing-test-fail.err | 0 .../go-test-json-missing-test-fail.out | 21 ++++++ .../testdata/summary-missing-test-fail-event | 23 +++++++ 8 files changed, 131 insertions(+), 27 deletions(-) create mode 100644 testjson/testdata/go-test-json-missing-test-fail.err create mode 100644 testjson/testdata/go-test-json-missing-test-fail.out create mode 100644 testjson/testdata/summary-missing-test-fail-event diff --git a/testjson/execution.go b/testjson/execution.go index 130c2902..b8673cf6 100644 --- a/testjson/execution.go +++ b/testjson/execution.go @@ -65,6 +65,7 @@ func (e TestEvent) Bytes() []byte { type Package struct { // TODO: this could be Total() Total int + running map[string]TestCase Failed []TestCase Skipped []TestCase Passed []TestCase @@ -114,6 +115,16 @@ func (p Package) TestMainFailed() bool { return p.action == ActionFail && len(p.Failed) == 0 } +const neverFinished time.Duration = -1 + +func (p *Package) end() { + // Add tests that were missing an ActionFail event to Failed + for _, tc := range p.running { + tc.Elapsed = neverFinished + p.Failed = append(p.Failed, tc) + } +} + // TestCase stores the name and elapsed time for a test case. type TestCase struct { Package string @@ -122,7 +133,10 @@ type TestCase struct { } func newPackage() *Package { - return &Package{output: make(map[string][]string)} + return &Package{ + output: make(map[string][]string), + running: make(map[string]TestCase), + } } // Execution of one or more test packages @@ -165,27 +179,30 @@ func (e *Execution) addTestEvent(pkg *Package, event TestEvent) { switch event.Action { case ActionRun: pkg.Total++ - case ActionFail: - pkg.Failed = append(pkg.Failed, TestCase{ + pkg.running[event.Test] = TestCase{ Package: event.Package, Test: event.Test, - Elapsed: elapsedDuration(event.Elapsed), - }) - case ActionSkip: - pkg.Skipped = append(pkg.Skipped, TestCase{ - Package: event.Package, - Test: event.Test, - Elapsed: elapsedDuration(event.Elapsed), - }) + } + return case ActionOutput, ActionBench: // TODO: limit size of buffered test output pkg.output[event.Test] = append(pkg.output[event.Test], event.Output) + return + case ActionPause, ActionCont: + return + } + + tc := pkg.running[event.Test] + delete(pkg.running, event.Test) + tc.Elapsed = elapsedDuration(event.Elapsed) + + switch event.Action { + case ActionFail: + pkg.Failed = append(pkg.Failed, tc) + case ActionSkip: + pkg.Skipped = append(pkg.Skipped, tc) case ActionPass: - pkg.Passed = append(pkg.Passed, TestCase{ - Package: event.Package, - Test: event.Test, - Elapsed: elapsedDuration(event.Elapsed), - }) + pkg.Passed = append(pkg.Passed, tc) // Remove test output once a test passes, it wont be used delete(pkg.output, event.Test) } @@ -234,16 +251,15 @@ func (e *Execution) Elapsed() time.Duration { // Failed returns a list of all the failed test cases. func (e *Execution) Failed() []TestCase { - var failed []TestCase + var failed []TestCase //nolint:prealloc for _, name := range sortedKeys(e.packages) { pkg := e.packages[name] // Add package-level failure output if there were no failed tests. if pkg.TestMainFailed() { failed = append(failed, TestCase{Package: name}) - } else { - failed = append(failed, pkg.Failed...) } + failed = append(failed, pkg.Failed...) } return failed } @@ -289,11 +305,18 @@ func (e *Execution) Errors() []string { return e.errors } +func (e *Execution) end() { + e.done = true + for _, pkg := range e.packages { + pkg.end() + } +} + // NewExecution returns a new Execution and records the current time as the // time the test execution started. func NewExecution() *Execution { return &Execution{ - started: time.Now(), + started: clock.Now(), packages: make(map[string]*Package), } } @@ -323,7 +346,7 @@ func ScanTestOutput(config ScanConfig) (*Execution, error) { return readStderr(config, execution) }) err := group.Wait() - execution.done = true + execution.end() return execution, err } @@ -340,6 +363,7 @@ func readStdout(config ScanConfig, execution *Execution) error { case err != nil: return errors.Wrapf(err, "failed to parse test output: %s", string(raw)) } + execution.add(event) if err := config.Handler.Event(event, execution); err != nil { return err diff --git a/testjson/execution_test.go b/testjson/execution_test.go index 3d0d4969..df252c34 100644 --- a/testjson/execution_test.go +++ b/testjson/execution_test.go @@ -38,6 +38,7 @@ func TestExecution_Add_PackageCoverage(t *testing.T) { output: map[string][]string{ "": {"coverage: 33.1% of statements\n"}, }, + running: map[string]TestCase{}, } assert.DeepEqual(t, pkg, expected, cmpPackage) } diff --git a/testjson/format_test.go b/testjson/format_test.go index 8184f811..4eb79453 100644 --- a/testjson/format_test.go +++ b/testjson/format_test.go @@ -88,8 +88,9 @@ var expectedExecution = &Execution{ {Test: "TestSkipped"}, {Test: "TestSkippedWitLog"}, }, - action: ActionPass, - cached: true, + action: ActionPass, + cached: true, + running: map[string]TestCase{}, }, "github.com/gotestyourself/gotestyourself/testjson/internal/stub": { Total: 28, @@ -103,10 +104,12 @@ var expectedExecution = &Execution{ {Test: "TestSkipped"}, {Test: "TestSkippedWitLog"}, }, - action: ActionFail, + action: ActionFail, + running: map[string]TestCase{}, }, "github.com/gotestyourself/gotestyourself/testjson/internal/badmain": { - action: ActionFail, + action: ActionFail, + running: map[string]TestCase{}, }, }, } @@ -217,6 +220,7 @@ var expectedCoverageExecution = &Execution{ }, action: ActionPass, coverage: "coverage: 0.0% of statements", + running: map[string]TestCase{}, }, "gotest.tools/gotestsum/testjson/internal/stub": { Total: 28, @@ -232,9 +236,11 @@ var expectedCoverageExecution = &Execution{ }, action: ActionFail, coverage: "coverage: 0.0% of statements", + running: map[string]TestCase{}, }, "gotest.tools/gotestsum/testjson/internal/badmain": { - action: ActionFail, + action: ActionFail, + running: map[string]TestCase{}, }, }, } diff --git a/testjson/summary.go b/testjson/summary.go index 2df43602..776943da 100644 --- a/testjson/summary.go +++ b/testjson/summary.go @@ -66,7 +66,7 @@ func NewSummary(value string) (Summary, bool) { } // PrintSummary of a test Execution. Prints a section for each summary type -// followed by a DONE line. +// followed by a DONE line to out. func PrintSummary(out io.Writer, execution *Execution, opts Summary) { execSummary := newExecSummary(execution, opts) if opts.Includes(SummarizeSkipped) { @@ -111,6 +111,9 @@ func formatExecStatus(done bool) string { // FormatDurationAsSeconds formats a time.Duration as a float with an s suffix. func FormatDurationAsSeconds(d time.Duration, precision int) string { + if d == neverFinished { + return "panic" + } return fmt.Sprintf("%.[2]*[1]fs", d.Seconds(), precision) } diff --git a/testjson/summary_test.go b/testjson/summary_test.go index 80b2a83a..a2cddf72 100644 --- a/testjson/summary_test.go +++ b/testjson/summary_test.go @@ -8,6 +8,7 @@ import ( "github.com/jonboulle/clockwork" "gotest.tools/v3/assert" + "gotest.tools/v3/golden" ) func TestSummary_String(t *testing.T) { @@ -222,3 +223,28 @@ func patchClock() (clockwork.FakeClock, func()) { func multiLine(s string) []string { return strings.SplitAfter(s, "\n") } + +func TestPrintSummary_MissingTestFailEvent(t *testing.T) { + _, reset := patchClock() + defer reset() + exec, err := ScanTestOutput(ScanConfig{ + Stdout: bytes.NewReader(golden.Get(t, "go-test-json-missing-test-fail.out")), + Stderr: bytes.NewReader(nil), + Handler: noopHandler{}, + }) + assert.NilError(t, err) + + buf := new(bytes.Buffer) + PrintSummary(buf, exec, SummarizeAll) + golden.Assert(t, buf.String(), "summary-missing-test-fail-event") +} + +type noopHandler struct{} + +func (s noopHandler) Event(TestEvent, *Execution) error { + return nil +} + +func (s noopHandler) Err(string) error { + return nil +} diff --git a/testjson/testdata/go-test-json-missing-test-fail.err b/testjson/testdata/go-test-json-missing-test-fail.err new file mode 100644 index 00000000..e69de29b diff --git a/testjson/testdata/go-test-json-missing-test-fail.out b/testjson/testdata/go-test-json-missing-test-fail.out new file mode 100644 index 00000000..cbe22b90 --- /dev/null +++ b/testjson/testdata/go-test-json-missing-test-fail.out @@ -0,0 +1,21 @@ +{"Time":"2020-04-10T14:52:44.192693974-04:00","Action":"run","Package":"gotest.tools/v3/poll","Test":"TestWaitOn_WithCompare"} +{"Time":"2020-04-10T14:52:44.192822137-04:00","Action":"output","Package":"gotest.tools/v3/poll","Test":"TestWaitOn_WithCompare","Output":"=== RUN TestWaitOn_WithCompare\n"} +{"Time":"2020-04-10T14:52:44.1950981-04:00","Action":"output","Package":"gotest.tools/v3/poll","Test":"TestWaitOn_WithCompare","Output":"panic: runtime error: index out of range [1] with length 1\n"} +{"Time":"2020-04-10T14:52:44.195110282-04:00","Action":"output","Package":"gotest.tools/v3/poll","Test":"TestWaitOn_WithCompare","Output":"\n"} +{"Time":"2020-04-10T14:52:44.195116665-04:00","Action":"output","Package":"gotest.tools/v3/poll","Test":"TestWaitOn_WithCompare","Output":"goroutine 7 [running]:\n"} +{"Time":"2020-04-10T14:52:44.195120587-04:00","Action":"output","Package":"gotest.tools/v3/poll","Test":"TestWaitOn_WithCompare","Output":"gotest.tools/v3/internal/assert.ArgsFromComparisonCall(0xc0000552a0, 0x1, 0x1, 0x1, 0x0, 0x0)\n"} +{"Time":"2020-04-10T14:52:44.195301254-04:00","Action":"output","Package":"gotest.tools/v3/poll","Test":"TestWaitOn_WithCompare","Output":"\t/home/daniel/pers/code/gotest.tools/internal/assert/result.go:102 +0x9f\n"} +{"Time":"2020-04-10T14:52:44.195332206-04:00","Action":"output","Package":"gotest.tools/v3/poll","Test":"TestWaitOn_WithCompare","Output":"gotest.tools/v3/internal/assert.runComparison(0x6bcb80, 0xc00000e180, 0x67dee8, 0xc00007a9f0, 0x0, 0x0, 0x0, 0x7f7f4fb6d108)\n"} +{"Time":"2020-04-10T14:52:44.19533807-04:00","Action":"output","Package":"gotest.tools/v3/poll","Test":"TestWaitOn_WithCompare","Output":"\t/home/daniel/pers/code/gotest.tools/internal/assert/result.go:34 +0x2b1\n"} +{"Time":"2020-04-10T14:52:44.195342341-04:00","Action":"output","Package":"gotest.tools/v3/poll","Test":"TestWaitOn_WithCompare","Output":"gotest.tools/v3/internal/assert.Eval(0x6bcb80, 0xc00000e180, 0x67dee8, 0x627660, 0xc00007a9f0, 0x0, 0x0, 0x0, 0x642c60)\n"} +{"Time":"2020-04-10T14:52:44.195346449-04:00","Action":"output","Package":"gotest.tools/v3/poll","Test":"TestWaitOn_WithCompare","Output":"\t/home/daniel/pers/code/gotest.tools/internal/assert/assert.go:56 +0x2e4\n"} +{"Time":"2020-04-10T14:52:44.195350377-04:00","Action":"output","Package":"gotest.tools/v3/poll","Test":"TestWaitOn_WithCompare","Output":"gotest.tools/v3/poll.Compare(0xc00007a9f0, 0x6b74a0, 0x618a60)\n"} +{"Time":"2020-04-10T14:52:44.195356946-04:00","Action":"output","Package":"gotest.tools/v3/poll","Test":"TestWaitOn_WithCompare","Output":"\t/home/daniel/pers/code/gotest.tools/poll/poll.go:151 +0x81\n"} +{"Time":"2020-04-10T14:52:44.195360761-04:00","Action":"output","Package":"gotest.tools/v3/poll","Test":"TestWaitOn_WithCompare","Output":"gotest.tools/v3/poll.TestWaitOn_WithCompare.func1(0x6be4c0, 0xc00016c240, 0xc00016c240, 0x6be4c0)\n"} +{"Time":"2020-04-10T14:52:44.195367482-04:00","Action":"output","Package":"gotest.tools/v3/poll","Test":"TestWaitOn_WithCompare","Output":"\t/home/daniel/pers/code/gotest.tools/poll/poll_test.go:81 +0x58\n"} +{"Time":"2020-04-10T14:52:44.195371319-04:00","Action":"output","Package":"gotest.tools/v3/poll","Test":"TestWaitOn_WithCompare","Output":"gotest.tools/v3/poll.WaitOn.func1(0xc00001e3c0, 0x67df50, 0x6c1960, 0xc00016c240)\n"} +{"Time":"2020-04-10T14:52:44.195375766-04:00","Action":"output","Package":"gotest.tools/v3/poll","Test":"TestWaitOn_WithCompare","Output":"\t/home/daniel/pers/code/gotest.tools/poll/poll.go:125 +0x62\n"} +{"Time":"2020-04-10T14:52:44.195379421-04:00","Action":"output","Package":"gotest.tools/v3/poll","Test":"TestWaitOn_WithCompare","Output":"created by gotest.tools/v3/poll.WaitOn\n"} +{"Time":"2020-04-10T14:52:44.195384493-04:00","Action":"output","Package":"gotest.tools/v3/poll","Test":"TestWaitOn_WithCompare","Output":"\t/home/daniel/pers/code/gotest.tools/poll/poll.go:124 +0x16f\n"} +{"Time":"2020-04-10T14:52:44.195785223-04:00","Action":"output","Package":"gotest.tools/v3/poll","Output":"FAIL\tgotest.tools/v3/poll\t0.005s\n"} +{"Time":"2020-04-10T14:52:44.195796081-04:00","Action":"fail","Package":"gotest.tools/v3/poll","Elapsed":0.005} diff --git a/testjson/testdata/summary-missing-test-fail-event b/testjson/testdata/summary-missing-test-fail-event new file mode 100644 index 00000000..c2e7f203 --- /dev/null +++ b/testjson/testdata/summary-missing-test-fail-event @@ -0,0 +1,23 @@ + +=== Failed +=== FAIL: gotest.tools/v3/poll TestWaitOn_WithCompare (panic) +panic: runtime error: index out of range [1] with length 1 + +goroutine 7 [running]: +gotest.tools/v3/internal/assert.ArgsFromComparisonCall(0xc0000552a0, 0x1, 0x1, 0x1, 0x0, 0x0) + /home/daniel/pers/code/gotest.tools/internal/assert/result.go:102 +0x9f +gotest.tools/v3/internal/assert.runComparison(0x6bcb80, 0xc00000e180, 0x67dee8, 0xc00007a9f0, 0x0, 0x0, 0x0, 0x7f7f4fb6d108) + /home/daniel/pers/code/gotest.tools/internal/assert/result.go:34 +0x2b1 +gotest.tools/v3/internal/assert.Eval(0x6bcb80, 0xc00000e180, 0x67dee8, 0x627660, 0xc00007a9f0, 0x0, 0x0, 0x0, 0x642c60) + /home/daniel/pers/code/gotest.tools/internal/assert/assert.go:56 +0x2e4 +gotest.tools/v3/poll.Compare(0xc00007a9f0, 0x6b74a0, 0x618a60) + /home/daniel/pers/code/gotest.tools/poll/poll.go:151 +0x81 +gotest.tools/v3/poll.TestWaitOn_WithCompare.func1(0x6be4c0, 0xc00016c240, 0xc00016c240, 0x6be4c0) + /home/daniel/pers/code/gotest.tools/poll/poll_test.go:81 +0x58 +gotest.tools/v3/poll.WaitOn.func1(0xc00001e3c0, 0x67df50, 0x6c1960, 0xc00016c240) + /home/daniel/pers/code/gotest.tools/poll/poll.go:125 +0x62 +created by gotest.tools/v3/poll.WaitOn + /home/daniel/pers/code/gotest.tools/poll/poll.go:124 +0x16f + + +DONE 1 tests, 1 failure in 0.000s