Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

cmd/go: shutdown crash output is unreadable #46631

Closed
klauspost opened this issue Jun 7, 2021 · 6 comments
Closed

cmd/go: shutdown crash output is unreadable #46631

klauspost opened this issue Jun 7, 2021 · 6 comments
Labels
FrozenDueToAge fuzz Issues related to native fuzzing support NeedsFix The path to resolution is known, but the work has not been done. release-blocker
Milestone
Go1.18

Comments

@klauspost
Copy link
Contributor

klauspost commented Jun 7, 2021 •
edited

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

λ gotip version
go version devel go1.17-5542c10fbf Fri Jun 4 03:07:33 2021 +0000 windows/amd64

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

go env Output
λ gotip env
set GO111MODULE=
set GOARCH=amd64
set GOBIN=
set GOCACHE=d:\temp\gocache
set GOENV=C:\Users\klaus\AppData\Roaming\go\env
set GOEXE=.exe
set GOFLAGS=
set GOHOSTARCH=amd64
set GOHOSTOS=windows
set GOINSECURE=
set GOMODCACHE=e:\gopath\pkg\mod
set GONOPROXY=
set GONOSUMDB=
set GOOS=windows
set GOPATH=e:\gopath
set GOPRIVATE=
set GOPROXY=https://goproxy.io
set GOROOT=C:\Users\klaus\sdk\gotip
set GOSUMDB=sum.golang.org
set GOTMPDIR=
set GOTOOLDIR=C:\Users\klaus\sdk\gotip\pkg\tool\windows_amd64
set GOVCS=
set GOVERSION=devel go1.17-5542c10fbf Fri Jun 4 03:07:33 2021 +0000
set GCCGO=gccgo
set AR=ar
set CC=gcc
set CXX=g++
set CGO_ENABLED=1
set GOMOD=NUL
set CGO_CFLAGS=-g -O2
set CGO_CPPFLAGS=
set CGO_CXXFLAGS=-g -O2
set CGO_FFLAGS=-g -O2
set CGO_LDFLAGS=-g -O2
set PKG_CONFIG=pkg-config
set GOGCCFLAGS=-m64 -mthreads -fmessage-length=0 -fdebug-prefix-map=d:\temp\wintemp\go-build102784969=/tmp/go-build -gno-record-gcc-switches

What did you do?

Simple fuzz test:

func FuzzCrash(f *testing.F) {
	f.Cleanup(func() {
		panic("error")
	})
	f.Fuzz(func(t *testing.T, data []byte) {
		time.Sleep(time.Second)
	})
}

Run gotip test -fuzz=FuzzCrash -test.run=None -parallel=16. Press ctrl+c which caused a crash.

What did you expect to see?

Readable output.

What did you see instead?

Copy of output: https://gist.github.com/klauspost/a03eaeda5aa172c0a5990f91c6e7b4a9

(Also we obviously didn't call "f.Fail", the CleanUp function probably did).
@katiehockman katiehockman changed the title [dev.fuzz] Shutdown crash output is unreadable. [dev.fuzz] cmd/go: shutdown crash output is unreadable. Jun 7, 2021
@katiehockman katiehockman added fuzz Issues related to native fuzzing support NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Jun 7, 2021
@katiehockman katiehockman added this to the Unreleased milestone Jun 7, 2021
@katiehockman
Copy link
Contributor

katiehockman commented Jun 7, 2021 •
edited

/cc @golang/fuzzing

@katiehockman katiehockman changed the title [dev.fuzz] cmd/go: shutdown crash output is unreadable. [dev.fuzz] cmd/go: shutdown crash output is unreadable Jun 29, 2021
@katiehockman
Copy link
Contributor

I just repro'd this locally and can confirm that something is going wrong here. Will look into it further.

@katiehockman katiehockman added the NeedsFix The path to resolution is known, but the work has not been done. label Jun 29, 2021
@gopherbot gopherbot removed the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Jun 29, 2021
@katiehockman
Copy link
Contributor

katiehockman commented Jun 29, 2021 •
edited

It looks like every worker is calling the Cleanup method, and panicking in a way that isn't being caught/logged properly. That very large block of text appears to be a set of stack traces that came from each worker panicking during Cleanup (in your example, you had 16 workers, so that's going to be a lot of output). All of the workers are trying to write to stdout at the same time, to report that there was an issue while running Cleanup, which is why everything is so jumbled.

@katiehockman katiehockman self-assigned this Jun 29, 2021
@katiehockman katiehockman mentioned this issue Jun 30, 2021
Closed
@jayconrod
Copy link
Contributor

I looked into this a bit today. Can confirm, the output is garbled because the worker processes share stdout and stderr. I set it up that way initially to help with debugging, but we should fix it and do it right.

testing uses stdout for test control messages (--- PASS and so on with -v) and logging (via TB.Log). The coordinator process should probably capture stdout, then only forward log lines onto its own stdout.

testing doesn't usually write to stderr (except when parsing its own flags), so anything written there should come from the fuzz target or an unrecovered panic (which is the case here). The coordinator should capture stderr from each worker, then print that or return an error when a worker terminates unexpectedly.

If all the workers panic, the output is going to be overwhelming, even if the coordinator prints each worker's output separately. We may just want to just print output from the first failing worker.

@katiehockman
Copy link
Contributor

This is likely going to be a release blocker for Go 1.18

@katiehockman katiehockman modified the milestones: Unreleased, Go1.18 Sep 14, 2021
@rsc rsc changed the title [dev.fuzz] cmd/go: shutdown crash output is unreadable cmd/go: shutdown crash output is unreadable Sep 21, 2021
@gopherbot
Copy link

Change https://golang.org/cl/352892 mentions this issue: internal/fuzz: disconnect stdout and stderr from the worker

@golang golang locked and limited conversation to collaborators Jun 23, 2023
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge fuzz Issues related to native fuzzing support NeedsFix The path to resolution is known, but the work has not been done. release-blocker
Projects
Go Security
Status: No status
Milestone
Go1.18
Development

No branches or pull requests
4 participants
@jayconrod @klauspost @gopherbot @katiehockman