testing: fix many test2json inaccuracies

Test2json is parsing the output stream from the test, which includes
package testing's own framing lines intermingled with other output,
in particular any output printed via fmt.Printf, println, and so on.
We have had recurring problems with unexpected partial output lines
causing a framing line to be missed.

A recent talk at GopherCon gave an example of an integration test
involving Docker that happened to print \r-terminated lines instead
of \n-terminated lines in some configurations, which in turn broke
test2json badly. (https://www.gophercon.com/agenda/session/944259)

There are also a variety of open reported issues with similar problems,
which this CL also addresses. The general approach is to add a new
testing flag -test.v=json that means to print additional output to help
test2json. And then test2json takes advantage of that output.

Among the fixes:

 - Identify testing framing more reliably, using ^V
   (#23036, #26325, #43683, GopherCon talk)
 - Test that output with \r\n endings is handled correctly
   (#43683, #34286)
 - Use === RUN in fuzz tests (#52636, #48132)
 - Add === RUN lines to note benchmark starts (#27764, #49505)
 - Print subtest --- PASS/FAIL lines as they happen (#29811)
 - Add === NAME lines to emit more test change events,
   such as when a subtest stops and the parent continues running.
 - Fix event shown in overall test failure (#27568)
 - Avoid interleaving of writes to os.Stdout and os.Stderr (#33419)

Fixes #23036.
Fixes #26325.
Fixes #27568.
Fixes #27764.
Fixes #29811.
Fixes #33419.
Fixes #34286.
Fixes #43683.
Fixes #49505.
Fixes #52636.

Change-Id: Id4207b746a20693f92e52d68c6e4a7f8c41cc7c6
Reviewed-on: https://go-review.googlesource.com/c/go/+/443596
Auto-Submit: Russ Cox <rsc@golang.org>
Run-TryBot: Russ Cox <rsc@golang.org>
Reviewed-by: Bryan Mills <bcmills@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>

10 files changed, 552 insertions, 19 deletions

diff --git a/src/cmd/internal/test2json/test2json.go b/src/cmd/internal/test2json/test2json.go
index 6beadae859..807dcc5102 100644
--- a/src/cmd/internal/test2json/test2json.go
+++ b/src/cmd/internal/test2json/test2json.go
@@ -49,15 +49,16 @@ func (b textBytes) MarshalText() ([]byte, error) { return b, nil }
 // It implements io.WriteCloser; the caller writes test output in,
 // and the converter writes JSON output to w.
 type Converter struct {
-	w        io.Writer  // JSON output stream
-	pkg      string     // package to name in events
-	mode     Mode       // mode bits
-	start    time.Time  // time converter started
-	testName string     // name of current test, for output attribution
-	report   []*event   // pending test result reports (nested for subtests)
-	result   string     // overall test result if seen
-	input    lineBuffer // input buffer
-	output   lineBuffer // output buffer
+	w          io.Writer  // JSON output stream
+	pkg        string     // package to name in events
+	mode       Mode       // mode bits
+	start      time.Time  // time converter started
+	testName   string     // name of current test, for output attribution
+	report     []*event   // pending test result reports (nested for subtests)
+	result     string     // overall test result if seen
+	input      lineBuffer // input buffer
+	output     lineBuffer // output buffer
+	needMarker bool       // require ^V marker to introduce test framing line
 }
 
 // inBuffer and outBuffer are the input and output buffer sizes.
@@ -136,21 +137,31 @@ func (c *Converter) Exited(err error) {
 	}
 }
 
+const marker = byte(0x16) // ^V
+
 var (
 	// printed by test on successful run.
-	bigPass = []byte("PASS\n")
+	bigPass = []byte("PASS")
 
 	// printed by test after a normal test failure.
-	bigFail = []byte("FAIL\n")
+	bigFail = []byte("FAIL")
 
 	// printed by 'go test' along with an error if the test binary terminates
 	// with an error.
 	bigFailErrorPrefix = []byte("FAIL\t")
 
+	// an === NAME line with no test name, if trailing spaces are deleted
+	emptyName     = []byte("=== NAME")
+	emptyNameLine = []byte("=== NAME  \n")
+
 	updates = [][]byte{
 		[]byte("=== RUN   "),
 		[]byte("=== PAUSE "),
 		[]byte("=== CONT  "),
+		[]byte("=== NAME  "),
+		[]byte("=== PASS  "),
+		[]byte("=== FAIL  "),
+		[]byte("=== SKIP  "),
 	}
 
 	reports = [][]byte{
@@ -163,18 +174,49 @@ var (
 	fourSpace = []byte("    ")
 
 	skipLinePrefix = []byte("?   \t")
-	skipLineSuffix = []byte("\t[no test files]\n")
+	skipLineSuffix = []byte("\t[no test files]")
 )
 
 // handleInputLine handles a single whole test output line.
 // It must write the line to c.output but may choose to do so
 // before or after emitting other events.
 func (c *Converter) handleInputLine(line []byte) {
+	if len(line) == 0 {
+		return
+	}
+	sawMarker := false
+	if c.needMarker && line[0] != marker {
+		c.output.write(line)
+		return
+	}
+	if line[0] == marker {
+		c.output.flush()
+		sawMarker = true
+		line = line[1:]
+	}
+
+	// Trim is line without \n or \r\n.
+	trim := line
+	if len(trim) > 0 && trim[len(trim)-1] == '\n' {
+		trim = trim[:len(trim)-1]
+		if len(trim) > 0 && trim[len(trim)-1] == '\r' {
+			trim = trim[:len(trim)-1]
+		}
+	}
+
+	// === CONT followed by an empty test name can lose its trailing spaces.
+	if bytes.Equal(trim, emptyName) {
+		line = emptyNameLine
+		trim = line[:len(line)-1]
+	}
+
 	// Final PASS or FAIL.
-	if bytes.Equal(line, bigPass) || bytes.Equal(line, bigFail) || bytes.HasPrefix(line, bigFailErrorPrefix) {
+	if bytes.Equal(trim, bigPass) || bytes.Equal(trim, bigFail) || bytes.HasPrefix(trim, bigFailErrorPrefix) {
 		c.flushReport(0)
+		c.testName = ""
+		c.needMarker = sawMarker
 		c.output.write(line)
-		if bytes.Equal(line, bigPass) {
+		if bytes.Equal(trim, bigPass) {
 			c.result = "pass"
 		} else {
 			c.result = "fail"
@@ -184,7 +226,7 @@ func (c *Converter) handleInputLine(line []byte) {
 
 	// Special case for entirely skipped test binary: "?   \tpkgname\t[no test files]\n" is only line.
 	// Report it as plain output but remember to say skip in the final summary.
-	if bytes.HasPrefix(line, skipLinePrefix) && bytes.HasSuffix(line, skipLineSuffix) && len(c.report) == 0 {
+	if bytes.HasPrefix(line, skipLinePrefix) && bytes.HasSuffix(trim, skipLineSuffix) && len(c.report) == 0 {
 		c.result = "skip"
 	}
 
@@ -268,6 +310,7 @@ func (c *Converter) handleInputLine(line []byte) {
 			return
 		}
 		// Flush reports at this indentation level or deeper.
+		c.needMarker = sawMarker
 		c.flushReport(indent)
 		e.Test = name
 		c.testName = name
@@ -277,9 +320,16 @@ func (c *Converter) handleInputLine(line []byte) {
 	}
 	// === update.
 	// Finish any pending PASS/FAIL reports.
+	c.needMarker = sawMarker
 	c.flushReport(0)
 	c.testName = name
 
+	if action == "name" {
+		// This line is only generated to get c.testName right.
+		// Don't emit an event.
+		return
+	}
+
 	if action == "pause" {
 		// For a pause, we want to write the pause notification before
 		// delivering the pause event, just so it doesn't look like the test
@@ -370,15 +420,15 @@ type lineBuffer struct {
 // write writes b to the buffer.
 func (l *lineBuffer) write(b []byte) {
 	for len(b) > 0 {
-		// Copy what we can into b.
+		// Copy what we can into l.b.
 		m := copy(l.b[len(l.b):cap(l.b)], b)
 		l.b = l.b[:len(l.b)+m]
 		b = b[m:]
 
-		// Process lines in b.
+		// Process lines in l.b.
 		i := 0
 		for i < len(l.b) {
-			j := bytes.IndexByte(l.b[i:], '\n')
+			j, w := indexEOL(l.b[i:])
 			if j < 0 {
 				if !l.mid {
 					if j := bytes.IndexByte(l.b[i:], '\t'); j >= 0 {
@@ -391,7 +441,7 @@ func (l *lineBuffer) write(b []byte) {
 				}
 				break
 			}
-			e := i + j + 1
+			e := i + j + w
 			if l.mid {
 				// Found the end of a partial line.
 				l.part(l.b[i:e])
@@ -421,6 +471,23 @@ func (l *lineBuffer) write(b []byte) {
 	}
 }
 
+// indexEOL finds the index of a line ending,
+// returning its position and output width.
+// A line ending is either a \n or the empty string just before a ^V not beginning a line.
+// The output width for \n is 1 (meaning it should be printed)
+// but the output width for ^V is 0 (meaning it should be left to begin the next line).
+func indexEOL(b []byte) (pos, wid int) {
+	for i, c := range b {
+		if c == '\n' {
+			return i, 1
+		}
+		if c == marker && i > 0 { // test -v=json emits ^V at start of framing lines
+			return i, 0
+		}
+	}
+	return -1, 0
+}
+
 // flush flushes the line buffer.
 func (l *lineBuffer) flush() {
 	if len(l.b) > 0 {
diff --git a/src/cmd/internal/test2json/test2json_test.go b/src/cmd/internal/test2json/test2json_test.go
index dee3920511..c1aecc85e2 100644
--- a/src/cmd/internal/test2json/test2json_test.go
+++ b/src/cmd/internal/test2json/test2json_test.go
@@ -72,6 +72,16 @@ func TestGolden(t *testing.T) {
 				diffJSON(t, buf.Bytes(), want)
 			})
 
+			// In bulk again with \r\n.
+			t.Run("crlf", func(t *testing.T) {
+				buf.Reset()
+				c = NewConverter(&buf, "", 0)
+				in = bytes.ReplaceAll(orig, []byte("\n"), []byte("\r\n"))
+				writeAndKill(c, in)
+				c.Close()
+				diffJSON(t, bytes.ReplaceAll(buf.Bytes(), []byte(`\r\n`), []byte(`\n`)), want)
+			})
+
 			// Write 2 bytes at a time on even boundaries.
 			t.Run("even2", func(t *testing.T) {
 				buf.Reset()
diff --git a/src/cmd/internal/test2json/testdata/frame.json b/src/cmd/internal/test2json/testdata/frame.json
new file mode 100644
index 0000000000..d2a65fc36b
--- /dev/null
+++ b/src/cmd/internal/test2json/testdata/frame.json
@@ -0,0 +1,9 @@
+{"Action":"run","Test":"TestAscii"}
+{"Action":"output","Test":"TestAscii","Output":"=== RUN   TestAscii\n"}
+{"Action":"output","Test":"TestAscii","Output":"=== RUN   TestNotReally\n"}
+{"Action":"output","Test":"TestAscii","Output":"--- PASS: TestAscii\n"}
+{"Action":"output","Test":"TestAscii","Output":"    i can eat glass, and it doesn't hurt me. i can eat glass, and it doesn't hurt me.\n"}
+{"Action":"output","Test":"TestAscii","Output":"FAIL\n"}
+{"Action":"pass","Test":"TestAscii"}
+{"Action":"output","Output":"PASS\n"}
+{"Action":"pass"}
diff --git a/src/cmd/internal/test2json/testdata/frame.test b/src/cmd/internal/test2json/testdata/frame.test
new file mode 100644
index 0000000000..ec7d453027
--- /dev/null
+++ b/src/cmd/internal/test2json/testdata/frame.test
@@ -0,0 +1,6 @@
+=== RUN   TestAscii
+=== RUN   TestNotReally
+--- PASS: TestAscii
+    i can eat glass, and it doesn't hurt me. i can eat glass, and it doesn't hurt me.
+FAIL
+PASS
diff --git a/src/cmd/internal/test2json/testdata/framebig.json b/src/cmd/internal/test2json/testdata/framebig.json
new file mode 100644
index 0000000000..ebb9bdf3f1
--- /dev/null
+++ b/src/cmd/internal/test2json/testdata/framebig.json
@@ -0,0 +1,167 @@
+{"Action":"run","Test":"TestIndex"}
+{"Action":"output","Test":"TestIndex","Output":"=== RUN   TestIndex\n"}
+{"Action":"output","Test":"TestIndex","Output":"--- PASS: TestIndex (0.00s)\n"}
+{"Action":"pass","Test":"TestIndex"}
+{"Action":"pass","Test":"TestIndex"}
+{"Action":"output","Test":"TestIndex","Output":"=== PASS  TestIndex\n"}
+{"Action":"run","Test":"TestLastIndex"}
+{"Action":"output","Test":"TestLastIndex","Output":"=== RUN   TestLastIndex\n"}
+{"Action":"output","Test":"TestLastIndex","Output":"--- PASS: TestLastIndex (0.00s)\n"}
+{"Action":"pass","Test":"TestLastIndex"}
+{"Action":"pass","Test":"TestLastIndex"}
+{"Action":"output","Test":"TestLastIndex","Output":"=== PASS  TestLastIndex\n"}
+{"Action":"run","Test":"TestIndexAny"}
+{"Action":"output","Test":"TestIndexAny","Output":"=== RUN   TestIndexAny\n"}
+{"Action":"output","Test":"TestIndexAny","Output":"--- PASS: TestIndexAny (0.00s)\n"}
+{"Action":"pass","Test":"TestIndexAny"}
+{"Action":"pass","Test":"TestIndexAny"}
+{"Action":"output","Test":"TestIndexAny","Output":"=== PASS  TestIndexAny\n"}
+{"Action":"run","Test":"TestLastIndexAny"}
+{"Action":"output","Test":"TestLastIndexAny","Output":"=== RUN   TestLastIndexAny\n"}
+{"Action":"output","Test":"TestLastIndexAny","Output":"--- PASS: TestLastIndexAny (0.00s)\n"}
+{"Action":"pass","Test":"TestLastIndexAny"}
+{"Action":"pass","Test":"TestLastIndexAny"}
+{"Action":"output","Test":"TestLastIndexAny","Output":"=== PASS  TestLastIndexAny\n"}
+{"Action":"run","Test":"TestIndexByte"}
+{"Action":"output","Test":"TestIndexByte","Output":"=== RUN   TestIndexByte\n"}
+{"Action":"output","Test":"TestIndexByte","Output":"--- PASS: TestIndexByte (0.00s)\n"}
+{"Action":"pass","Test":"TestIndexByte"}
+{"Action":"pass","Test":"TestIndexByte"}
+{"Action":"output","Test":"TestIndexByte","Output":"=== PASS  TestIndexByte\n"}
+{"Action":"run","Test":"TestLastIndexByte"}
+{"Action":"output","Test":"TestLastIndexByte","Output":"=== RUN   TestLastIndexByte\n"}
+{"Action":"output","Test":"TestLastIndexByte","Output":"--- PASS: TestLastIndexByte (0.00s)\n"}
+{"Action":"pass","Test":"TestLastIndexByte"}
+{"Action":"pass","Test":"TestLastIndexByte"}
+{"Action":"output","Test":"TestLastIndexByte","Output":"=== PASS  TestLastIndexByte\n"}
+{"Action":"run","Test":"TestIndexRandom"}
+{"Action":"output","Test":"TestIndexRandom","Output":"=== RUN   TestIndexRandom\n"}
+{"Action":"output","Test":"TestIndexRandom","Output":"--- PASS: TestIndexRandom (0.00s)\n"}
+{"Action":"pass","Test":"TestIndexRandom"}
+{"Action":"pass","Test":"TestIndexRandom"}
+{"Action":"output","Test":"TestIndexRandom","Output":"=== PASS  TestIndexRandom\n"}
+{"Action":"run","Test":"TestIndexRune"}
+{"Action":"output","Test":"TestIndexRune","Output":"=== RUN   TestIndexRune\n"}
+{"Action":"output","Test":"TestIndexRune","Output":"--- PASS: TestIndexRune (0.00s)\n"}
+{"Action":"pass","Test":"TestIndexRune"}
+{"Action":"pass","Test":"TestIndexRune"}
+{"Action":"output","Test":"TestIndexRune","Output":"=== PASS  TestIndexRune\n"}
+{"Action":"run","Test":"TestIndexFunc"}
+{"Action":"output","Test":"TestIndexFunc","Output":"=== RUN   TestIndexFunc\n"}
+{"Action":"output","Test":"TestIndexFunc","Output":"--- PASS: TestIndexFunc (0.00s)\n"}
+{"Action":"pass","Test":"TestIndexFunc"}
+{"Action":"pass","Test":"TestIndexFunc"}
+{"Action":"output","Test":"TestIndexFunc","Output":"=== PASS  TestIndexFunc\n"}
+{"Action":"run","Test":"ExampleIndex"}
+{"Action":"output","Test":"ExampleIndex","Output":"=== RUN   ExampleIndex\n"}
+{"Action":"output","Test":"ExampleIndex","Output":"--- PASS: ExampleIndex (0.00s)\n"}
+{"Action":"pass","Test":"ExampleIndex"}
+{"Action":"run","Test":"ExampleIndexFunc"}
+{"Action":"output","Test":"ExampleIndexFunc","Output":"=== RUN   ExampleIndexFunc\n"}
+{"Action":"output","Test":"ExampleIndexFunc","Output":"--- PASS: ExampleIndexFunc (0.00s)\n"}
+{"Action":"pass","Test":"ExampleIndexFunc"}
+{"Action":"run","Test":"ExampleIndexAny"}
+{"Action":"output","Test":"ExampleIndexAny","Output":"=== RUN   ExampleIndexAny\n"}
+{"Action":"output","Test":"ExampleIndexAny","Output":"--- PASS: ExampleIndexAny (0.00s)\n"}
+{"Action":"pass","Test":"ExampleIndexAny"}
+{"Action":"run","Test":"ExampleIndexByte"}
+{"Action":"output","Test":"ExampleIndexByte","Output":"=== RUN   ExampleIndexByte\n"}
+{"Action":"output","Test":"ExampleIndexByte","Output":"--- PASS: ExampleIndexByte (0.00s)\n"}
+{"Action":"pass","Test":"ExampleIndexByte"}
+{"Action":"run","Test":"ExampleIndexRune"}
+{"Action":"output","Test":"ExampleIndexRune","Output":"=== RUN   ExampleIndexRune\n"}
+{"Action":"output","Test":"ExampleIndexRune","Output":"--- PASS: ExampleIndexRune (0.00s)\n"}
+{"Action":"pass","Test":"ExampleIndexRune"}
+{"Action":"run","Test":"ExampleLastIndex"}
+{"Action":"output","Test":"ExampleLastIndex","Output":"=== RUN   ExampleLastIndex\n"}
+{"Action":"output","Test":"ExampleLastIndex","Output":"--- PASS: ExampleLastIndex (0.00s)\n"}
+{"Action":"pass","Test":"ExampleLastIndex"}
+{"Action":"run","Test":"ExampleLastIndexAny"}
+{"Action":"output","Test":"ExampleLastIndexAny","Output":"=== RUN   ExampleLastIndexAny\n"}
+{"Action":"output","Test":"ExampleLastIndexAny","Output":"--- PASS: ExampleLastIndexAny (0.00s)\n"}
+{"Action":"pass","Test":"ExampleLastIndexAny"}
+{"Action":"run","Test":"ExampleLastIndexByte"}
+{"Action":"output","Test":"ExampleLastIndexByte","Output":"=== RUN   ExampleLastIndexByte\n"}
+{"Action":"output","Test":"ExampleLastIndexByte","Output":"--- PASS: ExampleLastIndexByte (0.00s)\n"}
+{"Action":"pass","Test":"ExampleLastIndexByte"}
+{"Action":"run","Test":"ExampleLastIndexFunc"}
+{"Action":"output","Test":"ExampleLastIndexFunc","Output":"=== RUN   ExampleLastIndexFunc\n"}
+{"Action":"output","Test":"ExampleLastIndexFunc","Output":"--- PASS: ExampleLastIndexFunc (0.00s)\n"}
+{"Action":"pass","Test":"ExampleLastIndexFunc"}
+{"Action":"output","Output":"goos: darwin\n"}
+{"Action":"output","Output":"goarch: amd64\n"}
+{"Action":"output","Output":"pkg: strings\n"}
+{"Action":"output","Output":"cpu: Intel(R) Core(TM) i9-9980HK CPU @ 2.40GHz\n"}
+{"Action":"run","Test":"BenchmarkIndexRune"}
+{"Action":"output","Test":"BenchmarkIndexRune","Output":"=== RUN   BenchmarkIndexRune\n"}
+{"Action":"output","Test":"BenchmarkIndexRune","Output":"BenchmarkIndexRune\n"}
+{"Action":"output","Test":"BenchmarkIndexRune","Output":"BenchmarkIndexRune-16              \t87335496\t        14.27 ns/op\n"}
+{"Action":"run","Test":"BenchmarkIndexRuneLongString"}
+{"Action":"output","Test":"BenchmarkIndexRuneLongString","Output":"=== RUN   BenchmarkIndexRuneLongString\n"}
+{"Action":"output","Test":"BenchmarkIndexRuneLongString","Output":"BenchmarkIndexRuneLongString\n"}
+{"Action":"output","Test":"BenchmarkIndexRuneLongString","Output":"BenchmarkIndexRuneLongString-16    \t57104472\t        18.66 ns/op\n"}
+{"Action":"run","Test":"BenchmarkIndexRuneFastPath"}
+{"Action":"output","Test":"BenchmarkIndexRuneFastPath","Output":"=== RUN   BenchmarkIndexRuneFastPath\n"}
+{"Action":"output","Test":"BenchmarkIndexRuneFastPath","Output":"BenchmarkIndexRuneFastPath\n"}
+{"Action":"output","Test":"BenchmarkIndexRuneFastPath","Output":"BenchmarkIndexRuneFastPath-16      \t262380160\t         4.499 ns/op\n"}
+{"Action":"run","Test":"BenchmarkIndex"}
+{"Action":"output","Test":"BenchmarkIndex","Output":"=== RUN   BenchmarkIndex\n"}
+{"Action":"output","Test":"BenchmarkIndex","Output":"BenchmarkIndex\n"}
+{"Action":"output","Test":"BenchmarkIndex","Output":"BenchmarkIndex-16                  \t248529364\t         4.697 ns/op\n"}
+{"Action":"run","Test":"BenchmarkLastIndex"}
+{"Action":"output","Test":"BenchmarkLastIndex","Output":"=== RUN   BenchmarkLastIndex\n"}
+{"Action":"output","Test":"BenchmarkLastIndex","Output":"BenchmarkLastIndex\n"}
+{"Action":"output","Test":"BenchmarkLastIndex","Output":"BenchmarkLastIndex-16              \t293688756\t         4.166 ns/op\n"}
+{"Action":"run","Test":"BenchmarkIndexByte"}
+{"Action":"output","Test":"BenchmarkIndexByte","Output":"=== RUN   BenchmarkIndexByte\n"}
+{"Action":"output","Test":"BenchmarkIndexByte","Output":"BenchmarkIndexByte\n"}
+{"Action":"output","Test":"BenchmarkIndexByte","Output":"BenchmarkIndexByte-16              \t310338391\t         3.608 ns/op\n"}
+{"Action":"run","Test":"BenchmarkIndexHard1"}
+{"Action":"output","Test":"BenchmarkIndexHard1","Output":"=== RUN   BenchmarkIndexHard1\n"}
+{"Action":"output","Test":"BenchmarkIndexHard1","Output":"BenchmarkIndexHard1\n"}
+{"Action":"output","Test":"BenchmarkIndexHard1","Output":"BenchmarkIndexHard1-16             \t   12852\t     92380 ns/op\n"}
+{"Action":"run","Test":"BenchmarkIndexHard2"}
+{"Action":"output","Test":"BenchmarkIndexHard2","Output":"=== RUN   BenchmarkIndexHard2\n"}
+{"Action":"output","Test":"BenchmarkIndexHard2","Output":"BenchmarkIndexHard2\n"}
+{"Action":"output","Test":"BenchmarkIndexHard2","Output":"BenchmarkIndexHard2-16             \t    8977\t    135080 ns/op\n"}
+{"Action":"run","Test":"BenchmarkIndexHard3"}
+{"Action":"output","Test":"BenchmarkIndexHard3","Output":"=== RUN   BenchmarkIndexHard3\n"}
+{"Action":"output","Test":"BenchmarkIndexHard3","Output":"BenchmarkIndexHard3\n"}
+{"Action":"output","Test":"BenchmarkIndexHard3","Output":"BenchmarkIndexHard3-16             \t    1885\t    532079 ns/op\n"}
+{"Action":"run","Test":"BenchmarkIndexHard4"}
+{"Action":"output","Test":"BenchmarkIndexHard4","Output":"=== RUN   BenchmarkIndexHard4\n"}
+{"Action":"output","Test":"BenchmarkIndexHard4","Output":"BenchmarkIndexHard4\n"}
+{"Action":"output","Test":"BenchmarkIndexHard4","Output":"BenchmarkIndexHard4-16             \t    2298\t    533435 ns/op\n"}
+{"Action":"run","Test":"BenchmarkLastIndexHard1"}
+{"Action":"output","Test":"BenchmarkLastIndexHard1","Output":"=== RUN   BenchmarkLastIndexHard1\n"}
+{"Action":"output","Test":"BenchmarkLastIndexHard1","Output":"BenchmarkLastIndexHard1\n"}
+{"Action":"output","Test":"BenchmarkLastIndexHard1","Output":"BenchmarkLastIndexHard1-16         \t     813\t   1295767 ns/op\n"}
+{"Action":"run","Test":"BenchmarkLastIndexHard2"}
+{"Action":"output","Test":"BenchmarkLastIndexHard2","Output":"=== RUN   BenchmarkLastIndexHard2\n"}
+{"Action":"output","Test":"BenchmarkLastIndexHard2","Output":"BenchmarkLastIndexHard2\n"}
+{"Action":"output","Test":"BenchmarkLastIndexHard2","Output":"BenchmarkLastIndexHard2-16         \t     784\t   1389403 ns/op\n"}
+{"Action":"run","Test":"BenchmarkLastIndexHard3"}
+{"Action":"output","Test":"BenchmarkLastIndexHard3","Output":"=== RUN   BenchmarkLastIndexHard3\n"}
+{"Action":"output","Test":"BenchmarkLastIndexHard3","Output":"BenchmarkLastIndexHard3\n"}
+{"Action":"output","Test":"BenchmarkLastIndexHard3","Output":"BenchmarkLastIndexHard3-16         \t     913\t   1316608 ns/op\n"}
+{"Action":"run","Test":"BenchmarkIndexTorture"}
+{"Action":"output","Test":"BenchmarkIndexTorture","Output":"=== RUN   BenchmarkIndexTorture\n"}
+{"Action":"output","Test":"BenchmarkIndexTorture","Output":"BenchmarkIndexTorture\n"}
+{"Action":"output","Test":"BenchmarkIndexTorture","Output":"BenchmarkIndexTorture-16           \t   98090\t     10201 ns/op\n"}
+{"Action":"run","Test":"BenchmarkIndexAnyASCII"}
+{"Action":"output","Test":"BenchmarkIndexAnyASCII","Output":"=== RUN   BenchmarkIndexAnyASCII\n"}
+{"Action":"output","Test":"BenchmarkIndexAnyASCII","Output":"BenchmarkIndexAnyASCII\n"}
+{"Action":"run","Test":"BenchmarkIndexAnyASCII/1:1"}
+{"Action":"output","Test":"BenchmarkIndexAnyASCII/1:1","Output":"=== RUN   BenchmarkIndexAnyASCII/1:1\n"}
+{"Action":"output","Test":"BenchmarkIndexAnyASCII/1:1","Output":"BenchmarkIndexAnyASCII/1:1\n"}
+{"Action":"output","Test":"BenchmarkIndexAnyASCII/1:1","Output":"BenchmarkIndexAnyASCII/1:1-16      \t214829462\t         5.592 ns/op\n"}
+{"Action":"run","Test":"BenchmarkIndexAnyASCII/1:2"}
+{"Action":"output","Test":"BenchmarkIndexAnyASCII/1:2","Output":"=== RUN   BenchmarkIndexAnyASCII/1:2\n"}
+{"Action":"output","Test":"BenchmarkIndexAnyASCII/1:2","Output":"BenchmarkIndexAnyASCII/1:2\n"}
+{"Action":"output","Test":"BenchmarkIndexAnyASCII/1:2","Output":"BenchmarkIndexAnyASCII/1:2-16      \t155499682\t         7.214 ns/op\n"}
+{"Action":"run","Test":"BenchmarkIndexAnyASCII/1:4"}
+{"Action":"output","Test":"BenchmarkIndexAnyASCII/1:4","Output":"=== RUN   BenchmarkIndexAnyASCII/1:4\n"}
+{"Action":"output","Test":"BenchmarkIndexAnyASCII/1:4","Output":"BenchmarkIndexAnyASCII/1:4\n"}
+{"Action":"output","Test":"BenchmarkIndexAnyASCII/1:4","Output":"BenchmarkIndexAnyASCII/1:4-16      \t172757770\t         7.092 ns/op\n"}
+{"Action":"output","Output":"PASS\n"}
+{"Action":"pass"}
diff --git a/src/cmd/internal/test2json/testdata/framebig.test b/src/cmd/internal/test2json/testdata/framebig.test
new file mode 100644
index 0000000000..cb0b11a6a0
--- /dev/null
+++ b/src/cmd/internal/test2json/testdata/framebig.test
@@ -0,0 +1,138 @@
+=== RUN   TestIndex
+--- PASS: TestIndex (0.00s)
+=== PASS  TestIndex
+=== NAME
+=== RUN   TestLastIndex
+--- PASS: TestLastIndex (0.00s)
+=== PASS  TestLastIndex
+=== NAME
+=== RUN   TestIndexAny
+--- PASS: TestIndexAny (0.00s)
+=== PASS  TestIndexAny
+=== NAME
+=== RUN   TestLastIndexAny
+--- PASS: TestLastIndexAny (0.00s)
+=== PASS  TestLastIndexAny
+=== NAME
+=== RUN   TestIndexByte
+--- PASS: TestIndexByte (0.00s)
+=== PASS  TestIndexByte
+=== NAME
+=== RUN   TestLastIndexByte
+--- PASS: TestLastIndexByte (0.00s)
+=== PASS  TestLastIndexByte
+=== NAME
+=== RUN   TestIndexRandom
+--- PASS: TestIndexRandom (0.00s)
+=== PASS  TestIndexRandom
+=== NAME
+=== RUN   TestIndexRune
+--- PASS: TestIndexRune (0.00s)
+=== PASS  TestIndexRune
+=== NAME
+=== RUN   TestIndexFunc
+--- PASS: TestIndexFunc (0.00s)
+=== PASS  TestIndexFunc
+=== NAME
+=== RUN   ExampleIndex
+--- PASS: ExampleIndex (0.00s)
+=== NAME
+=== RUN   ExampleIndexFunc
+--- PASS: ExampleIndexFunc (0.00s)
+=== NAME
+=== RUN   ExampleIndexAny
+--- PASS: ExampleIndexAny (0.00s)
+=== NAME
+=== RUN   ExampleIndexByte
+--- PASS: ExampleIndexByte (0.00s)
+=== NAME
+=== RUN   ExampleIndexRune
+--- PASS: ExampleIndexRune (0.00s)
+=== NAME
+=== RUN   ExampleLastIndex
+--- PASS: ExampleLastIndex (0.00s)
+=== NAME
+=== RUN   ExampleLastIndexAny
+--- PASS: ExampleLastIndexAny (0.00s)
+=== NAME
+=== RUN   ExampleLastIndexByte
+--- PASS: ExampleLastIndexByte (0.00s)
+=== NAME
+=== RUN   ExampleLastIndexFunc
+--- PASS: ExampleLastIndexFunc (0.00s)
+=== NAME
+goos: darwin
+goarch: amd64
+pkg: strings
+cpu: Intel(R) Core(TM) i9-9980HK CPU @ 2.40GHz
+=== RUN   BenchmarkIndexRune
+BenchmarkIndexRune
+BenchmarkIndexRune-16              	87335496	        14.27 ns/op
+=== NAME
+=== RUN   BenchmarkIndexRuneLongString
+BenchmarkIndexRuneLongString
+BenchmarkIndexRuneLongString-16    	57104472	        18.66 ns/op
+=== NAME
+=== RUN   BenchmarkIndexRuneFastPath
+BenchmarkIndexRuneFastPath
+BenchmarkIndexRuneFastPath-16      	262380160	         4.499 ns/op
+=== NAME
+=== RUN   BenchmarkIndex
+BenchmarkIndex
+BenchmarkIndex-16                  	248529364	         4.697 ns/op
+=== NAME
+=== RUN   BenchmarkLastIndex
+BenchmarkLastIndex
+BenchmarkLastIndex-16              	293688756	         4.166 ns/op
+=== NAME
+=== RUN   BenchmarkIndexByte
+BenchmarkIndexByte
+BenchmarkIndexByte-16              	310338391	         3.608 ns/op
+=== NAME
+=== RUN   BenchmarkIndexHard1
+BenchmarkIndexHard1
+BenchmarkIndexHard1-16             	   12852	     92380 ns/op
+=== NAME
+=== RUN   BenchmarkIndexHard2
+BenchmarkIndexHard2
+BenchmarkIndexHard2-16             	    8977	    135080 ns/op
+=== NAME
+=== RUN   BenchmarkIndexHard3
+BenchmarkIndexHard3
+BenchmarkIndexHard3-16             	    1885	    532079 ns/op
+=== NAME
+=== RUN   BenchmarkIndexHard4
+BenchmarkIndexHard4
+BenchmarkIndexHard4-16             	    2298	    533435 ns/op
+=== NAME
+=== RUN   BenchmarkLastIndexHard1
+BenchmarkLastIndexHard1
+BenchmarkLastIndexHard1-16         	     813	   1295767 ns/op
+=== NAME
+=== RUN   BenchmarkLastIndexHard2
+BenchmarkLastIndexHard2
+BenchmarkLastIndexHard2-16         	     784	   1389403 ns/op
+=== NAME
+=== RUN   BenchmarkLastIndexHard3
+BenchmarkLastIndexHard3
+BenchmarkLastIndexHard3-16         	     913	   1316608 ns/op
+=== NAME
+=== RUN   BenchmarkIndexTorture
+BenchmarkIndexTorture
+BenchmarkIndexTorture-16           	   98090	     10201 ns/op
+=== NAME
+=== RUN   BenchmarkIndexAnyASCII
+BenchmarkIndexAnyASCII
+=== RUN   BenchmarkIndexAnyASCII/1:1
+BenchmarkIndexAnyASCII/1:1
+BenchmarkIndexAnyASCII/1:1-16      	214829462	         5.592 ns/op
+=== NAME
+=== RUN   BenchmarkIndexAnyASCII/1:2
+BenchmarkIndexAnyASCII/1:2
+BenchmarkIndexAnyASCII/1:2-16      	155499682	         7.214 ns/op
+=== NAME
+=== RUN   BenchmarkIndexAnyASCII/1:4
+BenchmarkIndexAnyASCII/1:4
+BenchmarkIndexAnyASCII/1:4-16      	172757770	         7.092 ns/op
+=== NAME
+PASS
diff --git a/src/cmd/internal/test2json/testdata/framefuzz.json b/src/cmd/internal/test2json/testdata/framefuzz.json
new file mode 100644
index 0000000000..ea2eafa717
--- /dev/null
+++ b/src/cmd/internal/test2json/testdata/framefuzz.json
@@ -0,0 +1,68 @@
+{"Action":"run","Test":"TestAddrStringAllocs"}
+{"Action":"output","Test":"TestAddrStringAllocs","Output":"=== RUN   TestAddrStringAllocs\n"}
+{"Action":"run","Test":"TestAddrStringAllocs/zero"}
+{"Action":"output","Test":"TestAddrStringAllocs/zero","Output":"=== RUN   TestAddrStringAllocs/zero\n"}
+{"Action":"run","Test":"TestAddrStringAllocs/ipv4"}
+{"Action":"output","Test":"TestAddrStringAllocs/ipv4","Output":"=== RUN   TestAddrStringAllocs/ipv4\n"}
+{"Action":"run","Test":"TestAddrStringAllocs/ipv6"}
+{"Action":"output","Test":"TestAddrStringAllocs/ipv6","Output":"=== RUN   TestAddrStringAllocs/ipv6\n"}
+{"Action":"run","Test":"TestAddrStringAllocs/ipv6+zone"}
+{"Action":"output","Test":"TestAddrStringAllocs/ipv6+zone","Output":"=== RUN   TestAddrStringAllocs/ipv6+zone\n"}
+{"Action":"run","Test":"TestAddrStringAllocs/ipv4-in-ipv6"}
+{"Action":"output","Test":"TestAddrStringAllocs/ipv4-in-ipv6","Output":"=== RUN   TestAddrStringAllocs/ipv4-in-ipv6\n"}
+{"Action":"run","Test":"TestAddrStringAllocs/ipv4-in-ipv6+zone"}
+{"Action":"output","Test":"TestAddrStringAllocs/ipv4-in-ipv6+zone","Output":"=== RUN   TestAddrStringAllocs/ipv4-in-ipv6+zone\n"}
+{"Action":"output","Test":"TestAddrStringAllocs","Output":"--- PASS: TestAddrStringAllocs (0.00s)\n"}
+{"Action":"output","Test":"TestAddrStringAllocs/zero","Output":"    --- PASS: TestAddrStringAllocs/zero (0.00s)\n"}
+{"Action":"pass","Test":"TestAddrStringAllocs/zero"}
+{"Action":"output","Test":"TestAddrStringAllocs/ipv4","Output":"    --- PASS: TestAddrStringAllocs/ipv4 (0.00s)\n"}
+{"Action":"pass","Test":"TestAddrStringAllocs/ipv4"}
+{"Action":"output","Test":"TestAddrStringAllocs/ipv6","Output":"    --- PASS: TestAddrStringAllocs/ipv6 (0.00s)\n"}
+{"Action":"pass","Test":"TestAddrStringAllocs/ipv6"}
+{"Action":"output","Test":"TestAddrStringAllocs/ipv6+zone","Output":"    --- PASS: TestAddrStringAllocs/ipv6+zone (0.00s)\n"}
+{"Action":"pass","Test":"TestAddrStringAllocs/ipv6+zone"}
+{"Action":"output","Test":"TestAddrStringAllocs/ipv4-in-ipv6","Output":"    --- PASS: TestAddrStringAllocs/ipv4-in-ipv6 (0.00s)\n"}
+{"Action":"pass","Test":"TestAddrStringAllocs/ipv4-in-ipv6"}
+{"Action":"output","Test":"TestAddrStringAllocs/ipv4-in-ipv6+zone","Output":"    --- PASS: TestAddrStringAllocs/ipv4-in-ipv6+zone (0.00s)\n"}
+{"Action":"pass","Test":"TestAddrStringAllocs/ipv4-in-ipv6+zone"}
+{"Action":"pass","Test":"TestAddrStringAllocs"}
+{"Action":"run","Test":"TestPrefixString"}
+{"Action":"output","Test":"TestPrefixString","Output":"=== RUN   TestPrefixString\n"}
+{"Action":"output","Test":"TestPrefixString","Output":"--- PASS: TestPrefixString (0.00s)\n"}
+{"Action":"pass","Test":"TestPrefixString"}
+{"Action":"run","Test":"TestInvalidAddrPortString"}
+{"Action":"output","Test":"TestInvalidAddrPortString","Output":"=== RUN   TestInvalidAddrPortString\n"}
+{"Action":"output","Test":"TestInvalidAddrPortString","Output":"--- PASS: TestInvalidAddrPortString (0.00s)\n"}
+{"Action":"pass","Test":"TestInvalidAddrPortString"}
+{"Action":"run","Test":"TestAsSlice"}
+{"Action":"output","Test":"TestAsSlice","Output":"=== RUN   TestAsSlice\n"}
+{"Action":"output","Test":"TestAsSlice","Output":"--- PASS: TestAsSlice (0.00s)\n"}
+{"Action":"pass","Test":"TestAsSlice"}
+{"Action":"output","Test":"TestInlining","Output":"    inlining_test.go:102: not in expected set, but also inlinable: \"Addr.string4\"\n"}
+{"Action":"output","Test":"TestInlining","Output":"    inlining_test.go:102: not in expected set, but also inlinable: \"Prefix.isZero\"\n"}
+{"Action":"output","Test":"TestInlining","Output":"    inlining_test.go:102: not in expected set, but also inlinable: \"IPv4Unspecified\"\n"}
+{"Action":"output","Test":"TestInlining","Output":"    inlining_test.go:102: not in expected set, but also inlinable: \"joinHostPort\"\n"}
+{"Action":"output","Test":"TestInlining","Output":"    inlining_test.go:102: not in expected set, but also inlinable: \"Addr.MarshalBinary\"\n"}
+{"Action":"output","Test":"TestInlining","Output":"    inlining_test.go:102: not in expected set, but also inlinable: \"bePutUint64\"\n"}
+{"Action":"output","Test":"TestInlining","Output":"    inlining_test.go:102: not in expected set, but also inlinable: \"mask6\"\n"}
+{"Action":"output","Test":"TestInlining","Output":"    inlining_test.go:102: not in expected set, but also inlinable: \"AddrPort.isZero\"\n"}
+{"Action":"output","Test":"TestInlining","Output":"    inlining_test.go:102: not in expected set, but also inlinable: \"stringsLastIndexByte\"\n"}
+{"Action":"output","Test":"TestInlining","Output":"    inlining_test.go:102: not in expected set, but also inlinable: \"Addr.isZero\"\n"}
+{"Action":"output","Test":"TestInlining","Output":"    inlining_test.go:102: not in expected set, but also inlinable: \"bePutUint32\"\n"}
+{"Action":"output","Test":"TestInlining","Output":"    inlining_test.go:102: not in expected set, but also inlinable: \"leUint16\"\n"}
+{"Action":"output","Test":"TestInlining","Output":"    inlining_test.go:102: not in expected set, but also inlinable: \"Addr.string6\"\n"}
+{"Action":"output","Test":"TestInlining","Output":"    inlining_test.go:102: not in expected set, but also inlinable: \"beUint64\"\n"}
+{"Action":"output","Test":"TestInlining","Output":"    inlining_test.go:102: not in expected set, but also inlinable: \"appendHexPad\"\n"}
+{"Action":"output","Test":"TestInlining","Output":"    inlining_test.go:102: not in expected set, but also inlinable: \"lePutUint16\"\n"}
+{"Action":"output","Test":"TestInlining","Output":"--- PASS: TestInlining (0.10s)\n"}
+{"Action":"pass","Test":"TestInlining"}
+{"Action":"run","Test":"FuzzParse"}
+{"Action":"output","Test":"FuzzParse","Output":"=== RUN   FuzzParse\n"}
+{"Action":"output","Test":"FuzzParse","Output":"fuzz: elapsed: 0s, gathering baseline coverage: 0/390 completed\n"}
+{"Action":"output","Test":"FuzzParse","Output":"fuzz: elapsed: 0s, gathering baseline coverage: 390/390 completed, now fuzzing with 16 workers\n"}
+{"Action":"output","Test":"FuzzParse","Output":"fuzz: elapsed: 3s, execs: 438666 (146173/sec), new interesting: 12 (total: 402)\n"}
+{"Action":"output","Test":"FuzzParse","Output":"\u0003fuzz: elapsed: 4s, execs: 558467 (147850/sec), new interesting: 15 (total: 405)\n"}
+{"Action":"output","Test":"FuzzParse","Output":"--- PASS: FuzzParse (3.85s)\n"}
+{"Action":"pass","Test":"FuzzParse"}
+{"Action":"output","Output":"PASS\n"}
+{"Action":"pass"}
diff --git a/src/cmd/internal/test2json/testdata/framefuzz.test b/src/cmd/internal/test2json/testdata/framefuzz.test
new file mode 100644
index 0000000000..1eb3a125e2
--- /dev/null
+++ b/src/cmd/internal/test2json/testdata/framefuzz.test
@@ -0,0 +1,56 @@
+=== RUN   TestAddrStringAllocs
+=== RUN   TestAddrStringAllocs/zero
+=== NAME  TestAddrStringAllocs
+=== RUN   TestAddrStringAllocs/ipv4
+=== NAME  TestAddrStringAllocs
+=== RUN   TestAddrStringAllocs/ipv6
+=== NAME  TestAddrStringAllocs
+=== RUN   TestAddrStringAllocs/ipv6+zone
+=== NAME  TestAddrStringAllocs
+=== RUN   TestAddrStringAllocs/ipv4-in-ipv6
+=== NAME  TestAddrStringAllocs
+=== RUN   TestAddrStringAllocs/ipv4-in-ipv6+zone
+=== NAME  TestAddrStringAllocs
+--- PASS: TestAddrStringAllocs (0.00s)
+    --- PASS: TestAddrStringAllocs/zero (0.00s)
+    --- PASS: TestAddrStringAllocs/ipv4 (0.00s)
+    --- PASS: TestAddrStringAllocs/ipv6 (0.00s)
+    --- PASS: TestAddrStringAllocs/ipv6+zone (0.00s)
+    --- PASS: TestAddrStringAllocs/ipv4-in-ipv6 (0.00s)
+    --- PASS: TestAddrStringAllocs/ipv4-in-ipv6+zone (0.00s)
+=== NAME
+=== RUN   TestPrefixString
+--- PASS: TestPrefixString (0.00s)
+=== NAME
+=== RUN   TestInvalidAddrPortString
+--- PASS: TestInvalidAddrPortString (0.00s)
+=== NAME
+=== RUN   TestAsSlice
+--- PASS: TestAsSlice (0.00s)
+=== NAME
+=== NAME  TestInlining
+    inlining_test.go:102: not in expected set, but also inlinable: "Addr.string4"
+    inlining_test.go:102: not in expected set, but also inlinable: "Prefix.isZero"
+    inlining_test.go:102: not in expected set, but also inlinable: "IPv4Unspecified"
+    inlining_test.go:102: not in expected set, but also inlinable: "joinHostPort"
+    inlining_test.go:102: not in expected set, but also inlinable: "Addr.MarshalBinary"
+    inlining_test.go:102: not in expected set, but also inlinable: "bePutUint64"
+    inlining_test.go:102: not in expected set, but also inlinable: "mask6"
+    inlining_test.go:102: not in expected set, but also inlinable: "AddrPort.isZero"
+    inlining_test.go:102: not in expected set, but also inlinable: "stringsLastIndexByte"
+    inlining_test.go:102: not in expected set, but also inlinable: "Addr.isZero"
+    inlining_test.go:102: not in expected set, but also inlinable: "bePutUint32"
+    inlining_test.go:102: not in expected set, but also inlinable: "leUint16"
+    inlining_test.go:102: not in expected set, but also inlinable: "Addr.string6"
+    inlining_test.go:102: not in expected set, but also inlinable: "beUint64"
+    inlining_test.go:102: not in expected set, but also inlinable: "appendHexPad"
+    inlining_test.go:102: not in expected set, but also inlinable: "lePutUint16"
+--- PASS: TestInlining (0.10s)
+=== RUN   FuzzParse
+fuzz: elapsed: 0s, gathering baseline coverage: 0/390 completed
+fuzz: elapsed: 0s, gathering baseline coverage: 390/390 completed, now fuzzing with 16 workers
+fuzz: elapsed: 3s, execs: 438666 (146173/sec), new interesting: 12 (total: 402)
+fuzz: elapsed: 4s, execs: 558467 (147850/sec), new interesting: 15 (total: 405)
+--- PASS: FuzzParse (3.85s)
+=== NAME
+PASS
diff --git a/src/cmd/internal/test2json/testdata/timeout.json b/src/cmd/internal/test2json/testdata/timeout.json
new file mode 100644
index 0000000000..162a5bde44
--- /dev/null
+++ b/src/cmd/internal/test2json/testdata/timeout.json
@@ -0,0 +1,7 @@
+{"Action":"run","Test":"Test"}
+{"Action":"output","Test":"Test","Output":"=== RUN   Test\n"}
+{"Action":"output","Test":"Test","Output":"panic: test timed out after 1s\n"}
+{"Action":"output","Test":"Test","Output":"\n"}
+{"Action":"output","Output":"FAIL\tp\t1.111s\n"}
+{"Action":"output","Output":"FAIL\n"}
+{"Action":"fail"}
diff --git a/src/cmd/internal/test2json/testdata/timeout.test b/src/cmd/internal/test2json/testdata/timeout.test
new file mode 100644
index 0000000000..7f3debf37d
--- /dev/null
+++ b/src/cmd/internal/test2json/testdata/timeout.test
@@ -0,0 +1,5 @@
+=== RUN   Test
+panic: test timed out after 1s
+
+FAIL	p	1.111s
+FAIL