search

golang / go

The Go programming language
https://go.dev
BSD 3-Clause "New" or "Revised" License
123.33k stars 17.58k forks source link

testing: fuzzer aborts with "fuzzing process hung or terminated unexpectedly while minimizing: EOF" #52569

Open lmb opened 2 years ago

lmb commented 2 years ago

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

go version go1.18.1 linux/arm64

Does this issue reproduce with the latest release?

Yes.

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

go env Output
GO111MODULE=""
GOARCH="arm64"
GOBIN="/home/lorenz/.local/bin"
GOCACHE="/home/lorenz/.cache/go-build"
GOENV="/home/lorenz/.config/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="arm64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/lorenz/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/lorenz/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_arm64"
GOVCS=""
GOVERSION="go1.18.1"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/home/lorenz/ebpf/go.mod"
GOWORK=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build640695223=/tmp/go-build -gno-record-gcc-switches"

What did you do?

I ran the following in the https://github.com/cilium/ebpf repo at d4e048f8a6d8d213b452c61573bd8150c35b557c.

$ go test -fuzz FuzzSpec -run XXX ./internal/btf/
WARNING: Failed to adjust rlimit, tests may fail
fuzz: elapsed: 0s, gathering baseline coverage: 0/14 completed
fuzz: elapsed: 0s, gathering baseline coverage: 14/14 completed, now fuzzing with 4 workers
fuzz: elapsed: 3s, execs: 21471 (7155/sec), new interesting: 1 (total: 15)
fuzz: elapsed: 5s, execs: 22115 (279/sec), new interesting: 1 (total: 15)
--- FAIL: FuzzSpec (5.31s)
    fuzzing process hung or terminated unexpectedly while minimizing: EOF
    Failing input written to testdata/fuzz/FuzzSpec/a2142308b78fc52a699d1f6e6c6e6552ed94b5ff5c376733a080dfb12fd98cd4
    To re-run:
    go test -run=FuzzSpec/a2142308b78fc52a699d1f6e6c6e6552ed94b5ff5c376733a080dfb12fd98cd4
FAIL
exit status 1
FAIL    github.com/cilium/ebpf/internal/btf 5.324s

What did you expect to see?

I expected the command given to reproduce the issue to result in a crash.

What did you see instead?

go test -run=FuzzSpec/a2142308b78fc52a699d1f6e6c6e6552ed94b5ff5c376733a080dfb12fd98cd4 -v
WARNING: Failed to adjust rlimit, tests may fail
testing: warning: no tests to run
PASS
ok      github.com/cilium/ebpf  0.004s

The contents of the file are:

$ cat internal/btf/testdata/fuzz/FuzzSpec/a2142308b78fc52a699d1f6e6c6e6552ed94b5ff5c376733a080dfb12fd98cd4
go test fuzz v1
[]byte("\x9f\xeb\x01\x00\x18\x00\x00\x000000000000000\x00\x009")
dr2chase commented 2 years ago

@rolandshoemaker can you give this a look? I read this as the fuzzer found a sporadic issue that will not repeat itself on command, but maybe something else is going on.

alexstan12 commented 2 years ago

I am experiencing the same behavior. The data included in testdata successfully passes the unit test, so data is not the issue.

klauspost commented 2 years ago

Seeing the same issue.

It fails consistently, except when using -parallel=1. Obviously that is wasting 15 cores, so far from optimal.

Edit: Further investigation leads me to believe that the cause of this is an OOM condition. Limiting memory use appears to fix this issue.

dagood commented 2 years ago

Further investigation leads me to believe that the cause of this is an OOM condition. Limiting memory use appears to fix this issue.

How did you limit memory use? Do you mean reducing the memory the test itself uses, or some more general limit?

I'm also running into this error on windows-amd64 and linux-amd64 with a Go build based on f4becf15bdbcb098ec6cfb5373ad113b3d991d43, recent master branch. Currently I'm running with GOMAXPROCS=1 GOGC=10 GOMEMLIMIT=1GiB and -parallel=1 (a wild guess based on this thread) and the error still occurs in seemingly the same way if I let the fuzz tests run for long enough.

(I haven't been able to reproduce on a machine I fully control yet, so I'm having a hard time monitoring what about my system might be causing crashes.)

Edit: Since posting, I've been able to reproduce the OOM killer causing this error on Linux by running with very little available memory in a VM. We've also been able to fix it by changing the fuzz tests themselves to use less memory. I was under the impression the memory usage of the fuzz test infra was the problem, but it seems (at least partially) under our control.

I do wish the error were a little clearer--EOF is one of those errors where at first glance it seems to be about files, but it could actually be just about anything.

belimawr commented 1 year ago

I'm also seeing the same issue on Linux.

go version

``` go version go version go1.20.5 linux/amd64 ```

go env

``` go env GO111MODULE="" GOARCH="amd64" GOBIN="" GOCACHE="/home/tiago/.cache/go-build" GOENV="/home/tiago/.config/go/env" GOEXE="" GOEXPERIMENT="" GOFLAGS="" GOHOSTARCH="amd64" GOHOSTOS="linux" GOINSECURE="" GOMODCACHE="/home/tiago/go/pkg/mod" GONOPROXY="" GONOSUMDB="" GOOS="linux" GOPATH="/home/tiago/go" GOPRIVATE="" GOPROXY="https://proxy.golang.org,direct" GOROOT="/usr/local/go" GOSUMDB="sum.golang.org" GOTMPDIR="" GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64" GOVCS="" GOVERSION="go1.20.5" GCCGO="gccgo" GOAMD64="v1" AR="ar" CC="gcc" CXX="g++" CGO_ENABLED="1" GOMOD="/dev/null" 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 -fdebug-prefix-map=/tmp/go-build362825651=/tmp/go-build -gno-record-gcc-switches" ``` 

=== RUN   FuzzFilestreamID
fuzz: elapsed: 0s, gathering baseline coverage: 0/41 completed
fuzz: elapsed: 3s, gathering baseline coverage: 30/41 completed
fuzz: elapsed: 4s, gathering baseline coverage: 41/41 completed, now fuzzing with 16 workers
fuzz: elapsed: 6s, execs: 67 (12/sec), new interesting: 0 (total: 41)
fuzz: elapsed: 9s, execs: 368 (100/sec), new interesting: 0 (total: 41)
fuzz: elapsed: 12s, execs: 383 (5/sec), new interesting: 0 (total: 41)
fuzz: elapsed: 15s, execs: 395 (4/sec), new interesting: 0 (total: 41)
fuzz: minimizing 33-byte failing input file
fuzz: elapsed: 18s, minimizing
fuzz: elapsed: 20s, minimizing
--- FAIL: FuzzFilestreamID (19.67s)
    fuzzing process hung or terminated unexpectedly while minimizing: EOF
    Failing input written to testdata/fuzz/FuzzFilestreamID/1c1ced2e8b2131bb
    To re-run:
    go test -run=FuzzFilestreamID/1c1ced2e8b2131bb
=== NAME  
FAIL
exit status 1
FAIL    github.com/elastic/beats/v7/filebeat/input/filestream   95.419s

I'm not quite sure I'm experiencing OOM, I run go test -fuzz while keeping an eye on htop and did not see a memory spike or the memory filling up.

AlekSi commented 8 months ago

Might be related to #56238

maxammann commented 7 months ago

@lmb I'm supposing the EOF is related to the process getting killed due to OOM.

At least I experienced an OOM when running the example you posted initially:

fuzz: elapsed: 50s, execs: 9495 (0/sec), new interesting: 1 (total: 14)
fuzz: elapsed: 1m8s, execs: 9495 (0/sec), new interesting: 1 (total: 14)
fuzz: elapsed: 1m8s, execs: 9495 (0/sec), new interesting: 1 (total: 14)
[LWP 14680 exited]
[LWP 14679 exited]
[LWP 14678 exited]
[LWP 14677 exited]
[LWP 14676 exited]
[LWP 14675 exited]
[LWP 14673 exited]
[LWP 14674 exited]
[New process 14673]

Program terminated with signal SIGKILL, Killed.
The program no longer exists.
(gdb) fuzz: elapsed: 1m9s, execs: 11424 (3286/sec), new interesting: 2 (total: 15)
fuzz: elapsed: 1m12s, execs: 18743 (2440/sec), new interesting: 3 (total: 16)
fuzz: elapsed: 1m15s, execs: 18743 (0/sec), new interesting: 3 (total: 16)
fuzz: elapsed: 1m23s, execs: 18743 (0/sec), new interesting: 3 (total: 16)
fuzz: elapsed: 1m23s, execs: 18743 (0/sec), new interesting: 3 (total: 16)
fuzz: elapsed: 1m23s, execs: 19649 (5249/sec), new interesting: 3 (total: 16)
--- FAIL: FuzzSpec (83.18s)
    fuzzing process hung or terminated unexpectedly while minimizing: EOF
    Failing input written to testdata/fuzz/FuzzSpec/4ac8ead72d16ddcc
    To re-run:
    go test -run=FuzzSpec/4ac8ead72d16ddcc
[ 2014.895523] Out of memory: Killed process 14690 (btf.test) total-vm:6535944kB, anon-rss:3566968kB, file-rss:0kB, shmem-rss:0kB, UID:0 pgtables:8672kB oom_score_adj:0