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
golang/go#38382 (comment)

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,6 +305,13 @@ 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 {
@@ -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

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)
 }

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{},
 		},
 	},
 }

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)
 }
 

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,26 @@ func patchClock() (clockwork.FakeClock, func()) {
 func multiLine(s string) []string {
 	return strings.SplitAfter(s, "\n")
 }
+
+func TestPrintSummary_MissingTestFailEvent(t *testing.T) {
+	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
+}

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}

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