[dev.fuzz] minimization discards crasher in favour of a non-crasher

[stevenjohnstone]

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

$ go version
go version devel go1.18-7c648e2acb3 Thu Sep 9 17:28:03 2021 +0000 linux/amd64

Does this issue reproduce with 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/stevie/.cache/go-build"
GOENV="/home/stevie/.config/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/stevie/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/stevie/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/home/stevie/sdk/gotip"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/home/stevie/sdk/gotip/pkg/tool/linux_amd64"
GOVCS=""
GOVERSION="devel go1.18-7c648e2acb3 Thu Sep 9 17:28:03 2021 +0000"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/home/stevie/minimize/go.mod"
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build1101915129=/tmp/go-build -gno-record-gcc-switches"

What did you do?

package minimize

import (
	"fmt"
	"testing"
)

//go:noinline
func branch1(i int) {
	b := []byte{1, 2, 3}
	fmt.Printf("%d\n", b[4])
}

//go:noinline
func branch2(i int) {
	panic(i)
}

func FuzzMinimizeToWrongCrash(f *testing.F) {
	f.Add(-20000) // this will force the fuzzer to crash in the the first branch
	f.Fuzz(func(t *testing.T, b int) {
		if b <= -20000 {
			branch1(b)
			return
		}

		if b > 10000 {
			// the corpus will contain a crasher for this branch
			branch2(b)
			return
		}
	})
}

$ ./minimize.test -test.fuzz=Fuzz -test.fuzzcachedir=./cache -test.run=^$
found a crash, minimizing...
gathering baseline coverage, elapsed: 0.0s, workers: 8, left: 1
--- FAIL: FuzzMinimizeToWrongCrash (0.01s)
        panic: runtime error: index out of range [4] with length 3
        goroutine 12 [running]:
        runtime/debug.Stack()
        	/home/stevie/sdk/gotip/src/runtime/debug/stack.go:24 +0x90
        testing.tRunner.func1.2({0x5ac400, 0xc000018138})
        	/home/stevie/sdk/gotip/src/testing/testing.go:1288 +0x265
        testing.tRunner.func1()
        	/home/stevie/sdk/gotip/src/testing/testing.go:1295 +0x225
        panic({0x5ac400, 0xc000018138})
        	/home/stevie/sdk/gotip/src/runtime/panic.go:814 +0x207
        minimize.branch1(0x0)
        	/home/stevie/minimize/fuzz_test.go:11 +0x2c
        minimize.FuzzMinimizeToWrongCrash.func1(0x0, 0xffffffffffffb1e0)
        	/home/stevie/minimize/fuzz_test.go:23 +0xc5
        reflect.Value.call({0x58e720, 0x5c7c78, 0x13}, {0x5ba083, 0x4}, {0xc00007ca20, 0x2, 0x2})
        	/home/stevie/sdk/gotip/src/reflect/value.go:542 +0x814
        reflect.Value.Call({0x58e720, 0x5c7c78, 0xc00007fad0}, {0xc00007ca20, 0x2, 0x2})
        	/home/stevie/sdk/gotip/src/reflect/value.go:338 +0xc5
        testing.(*F).Fuzz.func1.1(0x0)
        	/home/stevie/sdk/gotip/src/testing/fuzz.go:389 +0x1c6
        testing.tRunner(0xc000127520, 0xc000150100)
        	/home/stevie/sdk/gotip/src/testing/testing.go:1342 +0x102
        created by testing.(*F).Fuzz.func1
        	/home/stevie/sdk/gotip/src/testing/fuzz.go:378 +0x4e5
        
        --- FAIL: FuzzMinimizeToWrongCrash (0.00s)
    
    Crash written to testdata/corpus/FuzzMinimizeToWrongCrash/0c1ac182586a8c1e8819f7f8e6fae6027d9cf8ba51a15d24cec73d21a593cf26
    To re-run:
    go test minimize -run=FuzzMinimizeToWrongCrash/0c1ac182586a8c1e8819f7f8e6fae6027d9cf8ba51a15d24cec73d21a593cf26
FAIL
$ cat testdata/corpus/FuzzMinimizeToWrongCrash/0c1ac182586a8c1e8819f7f8e6fae6027d9cf8ba51a15d24cec73d21a593cf26 
go test fuzz v1
int(-19978)

The "crasher" is -19978 which doesn't cause a crash.

What did you expect to see?

Minimization failed to find an alternative similar crash. It should have a correct value in the corpus.

What did you see instead?

A crasher in the corpus which doesn't cause a crash.

[thanm]

@jayconrod @katiehockman

[katiehockman]

I was able to replicate this locally. Still diagnosing the cause of this though.

[stevenjohnstone]

When I instrument with this bpftrace script (I'm building for amd64)

uprobe:./minimize.test:"minimize.branch1" {
  printf("%d: %s %d\n", tid, probe, reg("ax"));
}
uprobe:./minimize.test:"minimize.branch2" {
  printf("%d: %s %d\n", tid, probe, reg("ax"));
}

uprobe:./minimize.test:"minimize.FuzzMinimizeToWrongCrash.func1" {
  printf("%d: %s %d\n", tid, probe, reg("bx"));
}

uprobe:./minimize.test:"internal/fuzz.(*mutator).mutateInt" {
  printf("%d: %s %d\n", tid, probe, reg("bx"));
}

failure cases look like this:

15664: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 -20000
15664: uprobe:./minimize.test:minimize.branch1 -20000
15660: uprobe:./minimize.test:internal/fuzz.(*mutator).mutateInt -20000
15664: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 -19983

It looks like a -20000 is passed to the fuzzing function and is mutated. The mutation results in the value -19983 which I then find in the corpus.

Sometimes, the next mutation is less than -20000 and the value in the corpus (18446) is a crasher:

15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 -20000
15823: uprobe:./minimize.test:minimize.branch1 -20000
15821: uprobe:./minimize.test:internal/fuzz.(*mutator).mutateInt -20000
15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 -20010
15823: uprobe:./minimize.test:minimize.branch1 -20010
15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 -20010
15823: uprobe:./minimize.test:minimize.branch1 -20010
15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 -1717988920
15823: uprobe:./minimize.test:minimize.branch2 -1717988920
15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 -171798892
15823: uprobe:./minimize.test:minimize.branch2 -171798892
15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 1271310299
15823: uprobe:./minimize.test:minimize.branch2 1271310299
15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 -1161359159
15823: uprobe:./minimize.test:minimize.branch2 -1161359159
15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 -1404626105
15823: uprobe:./minimize.test:minimize.branch2 -1404626105
15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 -140462611
15823: uprobe:./minimize.test:minimize.branch2 -140462611
15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 2133437386
15823: uprobe:./minimize.test:minimize.branch2 2133437386
15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 -216152991
15823: uprobe:./minimize.test:minimize.branch2 -216152991
15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 1266874889
15823: uprobe:./minimize.test:minimize.branch2 1266874889
15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 1844674407
15823: uprobe:./minimize.test:minimize.branch2 1844674407
15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 184467440
15823: uprobe:./minimize.test:minimize.branch2 184467440
15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 18446744
15823: uprobe:./minimize.test:minimize.branch2 18446744
15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 1844674
15823: uprobe:./minimize.test:minimize.branch2 1844674
15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 184467
15823: uprobe:./minimize.test:minimize.branch2 184467
15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 18446
15823: uprobe:./minimize.test:minimize.branch2 18446
15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 1844
15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 184
15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 18
15823: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 1

[stevenjohnstone]

I modified my script to capture the return value of mutateInt to be sure about what was going on:

uprobe:./minimize.test:"minimize.branch1" {
  printf("%d: %s %d\n", tid, probe, reg("ax"));
}
uprobe:./minimize.test:"minimize.branch2" {
  printf("%d: %s %d\n", tid, probe, reg("ax"));
}

uprobe:./minimize.test:"minimize.FuzzMinimizeToWrongCrash.func1" {
  printf("%d: %s %d\n", tid, probe, reg("bx"));
}

uprobe:./minimize.test:"internal/fuzz.(*mutator).mutateInt" {
  printf("%d: %s %d\n", tid, probe, reg("bx"));
}

uprobe:./minimize.test:"internal/fuzz.(*mutator).mutateInt" + 358 {
  printf("%d: %s %d\n", tid, probe, reg("ax"));
}

(358 is the offset of the RET instruction in mutateInt for my build).

With minimization disabled with fuzzminimizetime=0, I see

17493: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 -20000
17493: uprobe:./minimize.test:minimize.branch1 -20000
17491: uprobe:./minimize.test:internal/fuzz.(*mutator).mutateInt -20000
17491: uprobe:./minimize.test:internal/fuzz.(*mutator).mutateInt+358 -20025

and -20025 is in the corpus.

Line-by-line:

17493: uprobe:./minimize.test:minimize.FuzzMinimizeToWrongCrash.func1 -20000

-20000 is passed to the fuzzer

17493: uprobe:./minimize.test:minimize.branch1 -20000

-20000 is then passed to the branch1 where it will panic

17491: uprobe:./minimize.test:internal/fuzz.(*mutator).mutateInt -20000

-20000 is passed to mutateInt and

17491: uprobe:./minimize.test:internal/fuzz.(*mutator).mutateInt+358 -20025

mutateInt returns -20025. The fuzzer exits without calling the fuzzing functions again.

-20025 is a crasher but this has not actually been passed to the fuzzer to be tested.

[katiehockman]

This was a bit tricky to figure out, but I believe I have a fix.

The configuration in this bug was a bit different than how I would expect most people to run fuzzing: namely that the test binary was built without coverage instrumentation, which means the "coverage only" run we do at the beginning of fuzzing will never get run. We had a bug in our code that didn't allow coverage instrumentation to be fully disabled, so something that the fuzzing engine thought expanded coverage ended up being written as a crasher incorrectly. The PR I'm about to send should fix this for now, though we need to think a bit more about what the development flow should look like when a test binary is run without coverage instrumentation, and the preliminary tests of the seed corpus for the target are disabled (e.g. with -run=None). #48296 is related to this.

[gopherbot]

Change https://golang.org/cl/349630 mentions this issue: [dev.fuzz] internal/fuzz: fully disable checking coverage data if not instrumented

[stevenjohnstone]

@katiehockman I'm a bit confused about being built without coverage instrumentation. If I run this without building a test executable I get

$ gotip test -fuzz=Fuzz -run=^$
found a crash, minimizing...
gathering baseline coverage, elapsed: 0.0s, workers: 8, left: 1
--- FAIL: FuzzMinimizeToWrongCrash (0.01s)
        --- FAIL: FuzzMinimizeToWrongCrash (0.00s)
            testing.go:1241: panic: runtime error: index out of range [4] with length 3
                goroutine 24 [running]:
                runtime/debug.Stack()
                	/home/stevie/sdk/gotip/src/runtime/debug/stack.go:24 +0x90
                testing.tRunner.func1()
                	/home/stevie/sdk/gotip/src/testing/testing.go:1241 +0x545
                panic({0x5ac520, 0xc000116000})
                	/home/stevie/sdk/gotip/src/runtime/panic.go:814 +0x207
                minimize.branch1(0x0)
                	/home/stevie/minimize/fuzz_test.go:11 +0x2c
                minimize.FuzzMinimizeToWrongCrash.func1(0x0, 0xffffffffffffb1e0)
                	/home/stevie/minimize/fuzz_test.go:23 +0xc5
                reflect.Value.call({0x58e780, 0x5c7cb0, 0x13}, {0x5ba083, 0x4}, {0xc00008e9f0, 0x2, 0x2})
                	/home/stevie/sdk/gotip/src/reflect/value.go:542 +0x814
                reflect.Value.Call({0x58e780, 0x5c7cb0, 0x4f67e0}, {0xc00008e9f0, 0x2, 0x2})
                	/home/stevie/sdk/gotip/src/reflect/value.go:338 +0xc5
                testing.(*F).Fuzz.func1.1(0x0)
                	/home/stevie/sdk/gotip/src/testing/fuzz.go:411 +0x20b
                testing.tRunner(0xc000108340, 0xc0000f4100)
                	/home/stevie/sdk/gotip/src/testing/testing.go:1349 +0x102
                created by testing.(*F).Fuzz.func1
                	/home/stevie/sdk/gotip/src/testing/fuzz.go:400 +0x4e5
                
    
    Crash written to testdata/fuzz/FuzzMinimizeToWrongCrash/21a7d53a5f15477932c191f46b43ec6945e1ddf5a5440ee6fd03e2d22e4da8db
    To re-run:
    go test minimize -run=FuzzMinimizeToWrongCrash/21a7d53a5f15477932c191f46b43ec6945e1ddf5a5440ee6fd03e2d22e4da8db
FAIL
exit status 1
FAIL	minimize	0.011s
$ cat testdata/fuzz/FuzzMinimizeToWrongCrash/21a7d53a5f15477932c191f46b43ec6945e1ddf5a5440ee6fd03e2d22e4da8db 
go test fuzz v1
int(-19984)

The corpus contains a value which doesn't crash. Does running in this way mean that coverage instrumentation isn't available?

[katiehockman]

Ah sorry @stevenjohnstone I wrote my response before I saw your other comments. When I said "built without coverage instrumentation" I was referring to your first comment which is running a generated test binary.

I'll take a look at that reproducer too and see what's going on.