cmd/go: -fuzz with -json attributes fuzz output to the wrong test

[dnephin]

What version of Go are you using (go version)?

go version go1.18.1 linux/amd64

Does this issue reproduce with the latest release?

Yes

What did you do?

I wrote a fuzz test, and ran it with go test -json -fuzz Fuzz.

What did you expect to see?

I expected the JSON events for the fuzz output to have a Test name of FuzzParse. FuzzParse is the function that produced the output.

Example:

{"Action":"output","Package":"github.com/dnephin/snowid","Test":"FuzzParse","Output":"=== FUZZ  FuzzParse\n"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"FuzzParse","Output":"fuzz: elapsed: 0s, gathering baseline coverage: 0/5 completed\n"}

What did you see instead?

When I run go test -fuzz Fuzz the output looks right:

fuzz: elapsed: 0s, gathering baseline coverage: 0/5 completed
failure while testing seed corpus entry: FuzzParse/0e71390066240fd73c5eb87f27bf9cf3839d45b41771f24dc1e9e9aed9830244
fuzz: elapsed: 0s, gathering baseline coverage: 4/5 completed
--- FAIL: FuzzParse (0.04s)
    --- FAIL: FuzzParse (0.00s)
        snowid_test.go:197: assertion failed: 1 (string) !=  (normalized string)

When I run with the -json flag to get test2json output (go test -json -fuzz Fuzz), the fuzz output is attributed to the wrong test. The Test field is TestParse/l_not_allowed (the last unit test that happened to run before fuzz started), instead of the expected "Test": "FuzzParse".

{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestParse/l_not_allowed","Output":"=== FUZZ  FuzzParse\n"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestParse/l_not_allowed","Output":"fuzz: elapsed: 0s, gathering baseline coverage: 0/5 completed\n"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestParse/l_not_allowed","Output":"failure while testing seed corpus entry: FuzzParse/0e71390066240fd73c5eb87f27bf9cf3839d45b41771f24dc1e9e9aed9830244\n"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestParse/l_not_allowed","Output":"fuzz: elapsed: 0s, gathering baseline coverage: 4/5 completed\n"}
{"Action":"pass","Package":"github.com/dnephin/snowid","Test":"TestParse/l_not_allowed","Elapsed":0}
{"Action":"pass","Package":"github.com/dnephin/snowid","Test":"TestParse","Elapsed":0}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"FuzzParse","Output":"--- FAIL: FuzzParse (0.04s)\n"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"FuzzParse","Output":"    --- FAIL: FuzzParse (0.00s)\n"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"FuzzParse","Output":"        snowid_test.go:197: assertion failed: 1 (string) !=  (normalized string)\n"}

Full output (with the Time field removed) in the details below.

{"Action":"run","Package":"github.com/dnephin/snowid","Test":"TestNewNode"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestNewNode","Output":"=== RUN   TestNewNode\n"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestNewNode","Output":"--- PASS: TestNewNode (0.00s)\n"}
{"Action":"pass","Package":"github.com/dnephin/snowid","Test":"TestNewNode","Elapsed":0}
{"Action":"run","Package":"github.com/dnephin/snowid","Test":"TestGenerateDuplicateID"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestGenerateDuplicateID","Output":"=== RUN   TestGenerateDuplicateID\n"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestGenerateDuplicateID","Output":"--- PASS: TestGenerateDuplicateID (0.24s)\n"}
{"Action":"pass","Package":"github.com/dnephin/snowid","Test":"TestGenerateDuplicateID","Elapsed":0.24}
{"Action":"run","Package":"github.com/dnephin/snowid","Test":"TestRace"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestRace","Output":"=== RUN   TestRace\n"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestRace","Output":"--- PASS: TestRace (0.00s)\n"}
{"Action":"pass","Package":"github.com/dnephin/snowid","Test":"TestRace","Elapsed":0}
{"Action":"run","Package":"github.com/dnephin/snowid","Test":"TestBase58"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestBase58","Output":"=== RUN   TestBase58\n"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestBase58","Output":"--- PASS: TestBase58 (0.00s)\n"}
{"Action":"pass","Package":"github.com/dnephin/snowid","Test":"TestBase58","Elapsed":0}
{"Action":"run","Package":"github.com/dnephin/snowid","Test":"TestParse"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestParse","Output":"=== RUN   TestParse\n"}
{"Action":"run","Package":"github.com/dnephin/snowid","Test":"TestParse/ok"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestParse/ok","Output":"=== RUN   TestParse/ok\n"}
{"Action":"run","Package":"github.com/dnephin/snowid","Test":"TestParse/0_not_allowed"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestParse/0_not_allowed","Output":"=== RUN   TestParse/0_not_allowed\n"}
{"Action":"run","Package":"github.com/dnephin/snowid","Test":"TestParse/I_not_allowed"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestParse/I_not_allowed","Output":"=== RUN   TestParse/I_not_allowed\n"}
{"Action":"run","Package":"github.com/dnephin/snowid","Test":"TestParse/O_not_allowed"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestParse/O_not_allowed","Output":"=== RUN   TestParse/O_not_allowed\n"}
{"Action":"run","Package":"github.com/dnephin/snowid","Test":"TestParse/l_not_allowed"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestParse/l_not_allowed","Output":"=== RUN   TestParse/l_not_allowed\n"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestParse","Output":"--- PASS: TestParse (0.00s)\n"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestParse/ok","Output":"    --- PASS: TestParse/ok (0.00s)\n"}
{"Action":"pass","Package":"github.com/dnephin/snowid","Test":"TestParse/ok","Elapsed":0}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestParse/0_not_allowed","Output":"    --- PASS: TestParse/0_not_allowed (0.00s)\n"}
{"Action":"pass","Package":"github.com/dnephin/snowid","Test":"TestParse/0_not_allowed","Elapsed":0}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestParse/I_not_allowed","Output":"    --- PASS: TestParse/I_not_allowed (0.00s)\n"}
{"Action":"pass","Package":"github.com/dnephin/snowid","Test":"TestParse/I_not_allowed","Elapsed":0}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestParse/O_not_allowed","Output":"    --- PASS: TestParse/O_not_allowed (0.00s)\n"}
{"Action":"pass","Package":"github.com/dnephin/snowid","Test":"TestParse/O_not_allowed","Elapsed":0}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestParse/l_not_allowed","Output":"    --- PASS: TestParse/l_not_allowed (0.00s)\n"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestParse/l_not_allowed","Output":"=== FUZZ  FuzzParse\n"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestParse/l_not_allowed","Output":"fuzz: elapsed: 0s, gathering baseline coverage: 0/5 completed\n"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestParse/l_not_allowed","Output":"failure while testing seed corpus entry: FuzzParse/0e71390066240fd73c5eb87f27bf9cf3839d45b41771f24dc1e9e9aed9830244\n"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"TestParse/l_not_allowed","Output":"fuzz: elapsed: 0s, gathering baseline coverage: 4/5 completed\n"}
{"Action":"pass","Package":"github.com/dnephin/snowid","Test":"TestParse/l_not_allowed","Elapsed":0}
{"Action":"pass","Package":"github.com/dnephin/snowid","Test":"TestParse","Elapsed":0}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"FuzzParse","Output":"--- FAIL: FuzzParse (0.04s)\n"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"FuzzParse","Output":"    --- FAIL: FuzzParse (0.00s)\n"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"FuzzParse","Output":"        snowid_test.go:197: assertion failed: 1 (string) !=  (normalized string)\n"}
{"Action":"output","Package":"github.com/dnephin/snowid","Test":"FuzzParse","Output":"    \n"}
{"Action":"fail","Package":"github.com/dnephin/snowid","Test":"FuzzParse","Elapsed":0}
{"Action":"fail","Package":"github.com/dnephin/snowid","Test":"FuzzParse","Elapsed":0.04}
{"Action":"output","Package":"github.com/dnephin/snowid","Output":"FAIL\n"}
{"Action":"output","Package":"github.com/dnephin/snowid","Output":"exit status 1\n"}
{"Action":"output","Package":"github.com/dnephin/snowid","Output":"FAIL\tgithub.com/dnephin/snowid\t0.287s\n"}
{"Action":"fail","Package":"github.com/dnephin/snowid","Elapsed":0.287}

[dnephin]

I'm guessing

go/src/cmd/internal/test2json/test2json.go

Lines 150 to 154 in 1930977

	updates = [][]byte{
	[]byte("=== RUN "),
	[]byte("=== PAUSE "),
	[]byte("=== CONT "),
	}

needs to be updated to include === FUZZ. I'm not sure if anything else would need to change.

[dr2chase]

@rolandshoemaker can you give this a look?