x/mobile: when a panic happens, a long enough traceback deadlocks the runtime on Android

[gawen]

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

$ go version
go version go1.13.1 linux/amd64

Does this issue reproduce with the latest release?

Yes.

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

go env Output

$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/home//.cache/go-build"
GOENV="/home//.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/opt/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/lib/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/usr/lib/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD=""
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-build557544076=/tmp/go-build -gno-record-gcc-switches"

What did you do?

I have an Go application compiled for Android with gomobile. When a panic happens, the runtime prints a traceback and quits. However, when this traceback is long enough, the application freezes and never quits.

Gomobile redirects stderr to Android (Android log tag being "GoLog"). When a panic happens, the world is frozen, so:

• the goroutine lineLog does not consume anymore the pipe dup-ed to stderr;
• at some point the pipe becomes full;
• the runtime continues to write the long traceback in stderr and blocks until stderr is writable;
• deadlock.

Disabling the gomobile's redirection from stderr makes the application crashes "properly".

Note that the runtime already redirect logs to Android (with the tag "Go"), so the redirection of stderr by gomobile seems redundant to me?

To reproduce, you can modify the runtime to println lot of lines when a panic is caught, until the runtime freezes.

What did you expect to see?

When a panic happens, and the resulting traceback is long enough, I expect the runtime to print the full traceback and quit.

What did you see instead?

When a panic happens, and the resulting traceback is long enough, I see the runtime prints a truncated traceback and freezes.

[steeve]

cc @eliasnaur, I know you don't maintain it anymore but it would be nice to know if the now built-in support in Go itself would enable to remove this bit in gomobile, or there were some other reason for it to exist?

[eliasnaur]

AFAICT, the runtime only redirects its own printing (of crashes) to stderr. The gomobile redirect is for all writes to stderr (and stdout), not just the runtime's.

One fix is to rewrite the gomobile redirect in C(go).

[steeve]

Sample found at https://codelab.wordpress.com/2014/11/03/how-to-use-standard-output-streams-for-logging-in-android-apps/

[steeve]

Another idea would be to implement a buffered writer and only replace os.Stdout/Stderr. That won't redirect all stdout/stderr logging, but Go code would be fine, and stderr wouldn't be duped, so the dump would work.

[hyangah]

Wonder if it's possible to let the gomobile directly send all logs to logd using the code similar to runtime/write_err_android.go. More desirably, would be nice if it allows users to turn it on and off - I found logging from some libraries is too chatty for mobile application use cases.

[gawen]

Proposal patch for this issue: golang/mobile#40

[gopherbot]

Change https://golang.org/cl/212839 mentions this issue: internal/mobileinit: redirect std{out,err} without using Go