internal/fuzz,testing: test_fuzz_mutator_repeat failures with "inputs are not equal"

[bcmills]

greplogs --dashboard -md -l -e '(?ms)FAIL: TestScript/test_fuzz_mutator_repeat.*inputs are not equal'

2021-10-13T16:36:59-69041c7/windows-amd64-longtest
2021-10-08T00:18:29-7cef831/linux-amd64-longtest
2021-10-05T21:25:51-6ae3afa/windows-amd64-longtest

CC @katiehockman @rolandshoemaker

[bcmills]

The inputs in these failures look very similar to me.

(Maybe this has something to do with the Unicode replacement value, if the test input happens not to be valid UTF-8?)

[gopherbot]

Change https://golang.org/cl/356649 mentions this issue: cmd/go: skip flaky fuzz tests

[katiehockman]

I don't think this is a UTF-8 issue. What this test is basically checking is that the coordinator can reconstruct the mutated input if it wasn't provided by the worker (e.g. because of a non-recoverable crash). It reconstructs it by using the count of mutations that is stored in shared memory. If that number is 1 off (either too big or too small), it would look a lot like these errors, since all of the incorrect inputs are only slightly different from the expected inputs.

I'm not able to reproduce this locally, unfortunately, which makes debugging this more difficult.

[katiehockman]

I have a theory. It's a bit of a longshot, but seems plausible?

When fuzzing, if an unrecoverable error occurs, the coordinator uses the count written to memory to reconstruct the input that caused the failure. This count is increased inside fuzzOnce right before we execute fuzzFn (the fuzz function).
The fuzz test in test_fuzz_mutator_repeat writes to a file on the 100th execution of the fuzz target, and exits in a way that is unrecoverable. If an execution of fuzzFn triggers new code coverage, then we attempt to deflake to make sure the coverage is legitimate. This calls fuzzOnce, which would in turn increase count by one before fuzzFn is called.

I see one possible way this number could be off. If the 99th execution of fuzzFn increases coverage, and a crash occurs during the de-flake (i.e. the 100th execution), then the count will accurately describe how many times the fuzz function was called, but will be 1 bigger than the number of times mutate was called.

This would explain why it happens so rarely. The fix for this isn't totally straightforward. We can't for example just not increase the count when we're deflaking, because the count is used for -fuzztime=Xx. But I have a few other ideas that should work.

[gopherbot]

Change https://golang.org/cl/358094 mentions this issue: internal/fuzz: don't deflake coverage found while fuzzing

[bcmills]

Unfortunately this test is still occasionally failing on linux-386-longtest. (Does it depend on instrumentation?)

greplogs --dashboard -md -l -e 'FAIL: TestScript/test_fuzz_mutator_repeat' --since=2021-10-23

2021-11-17T17:36:36-0555ea3/linux-386-longtest
2021-11-17T17:16:18-ab75484/linux-386-longtest

[bcmills]

From some further builds, the recent failures are looking like a regression as of CL 364214.