testing: unexpected variance in fuzzing rate

[coventry]

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

$ go version
go version go1.21.3 linux/amd64

Does this issue reproduce with the latest release?

Yes, if 1.21.3 is the latest release.

What operating system and processor architecture are you using (go env)?

go env Output

$ go env
GO111MODULE=''
GOARCH='amd64'
GOBIN=''
GOCACHE='/home/ubuntu/.cache/go-build'
GOENV='/home/ubuntu/.config/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFLAGS=''
GOHOSTARCH='amd64'
GOHOSTOS='linux'
GOINSECURE=''
GOMODCACHE='/home/ubuntu/go/pkg/mod'
GONOPROXY=''
GONOSUMDB=''
GOOS='linux'
GOPATH='/home/ubuntu/go'
GOPRIVATE=''
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/usr/local/go-1.23'
GOSUMDB='sum.golang.org'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/usr/local/go-1.23/pkg/tool/linux_amd64'
GOVCS=''
GOVERSION='go1.21.3'
GCCGO='gccgo'
GOAMD64='v1'
AR='ar'
CC='gcc'
CXX='g++'
CGO_ENABLED='1'
GOMOD='/home/ubuntu/chainlink/threshold/fuzzfail/go.mod'
GOWORK=''
CGO_CFLAGS='-O2 -g'
CGO_CPPFLAGS=''
CGO_CXXFLAGS='-O2 -g'
CGO_FFLAGS='-O2 -g'
CGO_LDFLAGS='-O2 -g'
PKG_CONFIG='pkg-config'
GOGCCFLAGS='-fPIC -m64 -pthread -Wl,--no-gc-sections -fmessage-length=0 -ffile-prefix-map=/tmp/go-build3723727294=/tmp/go-build -gno-record-gcc-switches'

What did you do?

1. Placed the following file in fuzzfail/fuzz_test.go:

package fuzzfail

import "testing"

func FuzzFail(f *testing.F) {
	f.Fuzz(func(_ *testing.T, bytes []byte) {
		chA := make(chan struct{}, 1)
		chB := make(chan struct{}, 1)

		for i := 0; i < len(bytes); i += 7 {
			if bytes[i] <= 127 {
				select {
				case chA <- struct{}{}:
				default:
					panic("chA not ready")
				}
			} else {
				select {
				case chB <- struct{}{}:
				default:
					panic("chB not ready")
				}
			}
			select {
			case <-chA:
			case <-chB:
			default:
				panic("no channel ready")
			}
		}
		close(chA)
		close(chB)
	})
}

2. Placed the following in fuzzfail/go.mod:

module example.com/fuzzfail

go 1.21.3

3. In the fuzzfail directory, ran the following commands:

$ rm -rf /home/ubuntu/.cache/go-build/fuzz/example.com/
$ GOMAXPROCS=1 go test -fuzz FuzzFail
warning: starting with empty corpus
fuzz: elapsed: 0s, execs: 0 (0/sec), new interesting: 0 (total: 0)
fuzz: elapsed: 3s, execs: 23709 (7895/sec), new interesting: 7 (total: 7)
fuzz: elapsed: 6s, execs: 23709 (0/sec), new interesting: 7 (total: 7)
fuzz: elapsed: 9s, execs: 426802 (135060/sec), new interesting: 8 (total: 8)

(This example is quite fragile, and it is often necessary to clear the fuzzing cache as shown first, for it to manifest.)

What did you expect to see?

Low variance in the fuzzing rate, and no 3s intervals with (0/sec).

What did you see instead?

High variance in the fuzzing rate, and 3s intervals WITH (0/sec) (after the first line of output, where it's expected with an empty cache.)

This is simplified from a much more complex fuzzing test where the variance in the fuzzing rate hurts more, and the fuzzing rate drops to zero for longer periods.

It happens without setting GOMAXPROCS, but happens more reliably if it's set to 1.

Incrementing the loop variable i by 7 is weird, but the issue does not occur for me if it's set to 1. (7 is an accident from what I was parsing out from the fuzzing input in the more complex test.)

[bcmills]

(attn @golang/fuzzing)

[rolandshoemaker]

Without looking too closely I believe this is caused by minimization not contributing to the "fuzzing rate", which makes it look like the fuzzer has stalled while it is minimizing a new candidate input.

[coventry]

Thanks. I will run the fuzzer on the system I reduced this example from until the new interesting value stabilizes, and see whether I still get slowdowns. That does seem the likely explanation for this example, though, given that clearing the fuzzing cache is often necessary.