proposal: runtime: add mechanism to configure format used to write out unhandled panics

[mitar]

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

go version go1.14.4 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

GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/mitar/.cache/go-build"
GOENV="/home/mitar/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/mitar/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"
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-build926066688=/tmp/go-build -gno-record-gcc-switches"

What did you do?

I am using logrus to log messages encoded as JSON objects to stderr.

What did you expect to see?

When unhanded panic happens, anywhere in the program, 3rd party libraries, and goroutines, I would like that panic is logged as JSON object as well, so that JSON parsing does not fail on that output from the program.

What did you see instead?

Panic message is not JSON so parsing of it fails when storing logs into storage expecting JSON. Moreover, one cannot then search over stored messages to obtain information about a particular panic: because it has not been stored.

[agnivade]

Panics are supposed to be exceptional cases in your program. It seems to me like you want panics to be logged normally. You can choose to do that using a recover block, and then let the panic continue.

I don't see a bug here. We do not use the issue tracker for questions such as these. It is only used for bugs and feature proposals. I will close this issue, but please feel free to ask it in any of these forums below:

• Stack Overflow with questions tagged "go"

• The Go Forum, a web-based forum

• Gophers Slack, use the invite app for access. The #general channel is a good starting point.

• Go Community on Hashnode with questions and posts tagged with "go"

• The golang-nuts mailing list

• IRC channel #go-nuts on Freenode

Thanks

[mitar]

Panics are supposed to be exceptional cases in your program.

Yes they are.

It seems to me like you want panics to be logged normally.

Yes, so that I can log it centrally.

You can choose to do that using a recover block, and then let the panic continue.

No, I cannot. Because in 3rd party libraries which use go routines I cannot use the recover block to capture and format and log the panic.

So I would propose that there is a way to configure how panics are formatted.

[mitar]

It is only used for bugs and feature proposals

And yes, this is a feature proposal. That go should provide a way to format how unhandled panic is being written out. How is that not a feature proposal? There is no way for one to currently do that.

[ianlancetaylor]

Programs can fail in various ways. A panic is just one of them. For example, there are also various unrecoverable runtime errors. And of course a third party library could call os.Exit.

I think that if you want to make this reliable, you will need to wrap the program with a small helper that can collect the output and format it as you like. That could handle all cases and will work today.

If you want to continue this proposal, please make specific suggestions for how the ABI should be changed. However, personally I think it is unlikely that such a proposal would be accepted.

Thanks.

[mitar]

I am not sure if perfect should be the enemy of good. Panic is a common pattern which go programs use and I would like to handle that. There are of course other issues which one cannot handle anyway, because maybe it will not even be written to stdout. I am aware of those. But I have not seen yet those in my container, while I have seen panics.

If you want to continue this proposal, please make specific suggestions for how the ABI should be changed.

I will think about it. Are compile time options acceptable?

[ianlancetaylor]

I don't see how to make this a compile time option. I can't think of any other comparable compile time options. But it's not necessarily unacceptable if it can fit into an existing approach.

More likely would be a GODEBUG environment variable setting.

[mitar]

So GODEBUG environment variable with panicformat=json, panicformat=oneline (for panic messages in one text line, not multi-line) or panicformat=plain for default behavior. I like this.

[mitar]

OK, so my proposal would then be to add to GODEBUG environment variable with panicformat variable with the following options:

• plain (current default), with unhandled panic output similar to:

panic: runtime error: last name cannot be nil

goroutine 1 [running]:  
main.fullName(0xc00006af28, 0x0)  
    /tmp/sandbox451943841/prog.go:13 +0x23f
main.main()  
    /tmp/sandbox451943841/prog.go:22 +0xc6

• oneline, where output is always just one line (unless the panic error string contains newlines, but this is not something this format should try to fix):

panic: runtime error: last name cannot be nil {while} goroutine 1 [running] {at} main.fullName(0xc00006af28, 0x0) /tmp/sandbox451943841/prog.go:13 +0x23f {at} main.main() /tmp/sandbox451943841/prog.go:22 +0xc6

• json, where output is made to be JSON encoded, encoded always in one line, without extra whitespace, with a fixed structure:

{"panic":"runtime error","error":"last name cannot be nil","while":[{"goroutine":1,"state":"running","stack":[{"func":"main.fullName","args":["0xc00006af28","0x0"],"file":"/tmp/sandbox451943841/prog.go","line":13,"offset":"+0x23f"},{"func":"main.main","args":[],"file":"/tmp/sandbox451943841/prog.go","line":22,"offset":"+0xc6"}]}]}

If there is also a signal information provided, like;

[signal SIGSEGV: segmentation violation code=0x1 addr=0x40 pc=0x2293]

Then oneline should have the following clause before {while}: {signal} SIGSEGV: segmentation violation code=0x1 addr=0x40 pc=0x2293. And json can have extra field "signal":{"name":"SIGSEGV","desc":"segmentation violation","code":"0x1","addr":"0x40","pc":"0x2293"}.

I am open to changes to any of those formats if people would prefer some other names in JSON or anything else. Also tell me if I forgot to handle anything which can get printed out during unhandled panic.

[rsc]

Multiple formats seems like a mistake - why put that code into every single Go binary in the world?
It's better to have the binaries produce one format and then let tools that need other formats wrap the program in a converter. Then if you need to change a detail of the new format, you only need to change the converter, not every Go binary in the world.

An analogy would be how go test -json does not actually put JSON-generating code in the test binary. It pipes the test output through a converter program (go tool test2json).

[mitar]

I think perfect should not be an enemy of the good. Nothing prevents you from also using the tool around the program to further process things to whichever format you want. But current stack output is very tricky to parse and process, because:

• It targets humans, not machine readability.
• It is multi-line, without clear separation of start and end of the output.
• It gets mixed with the rest of the program's output, which then makes the upper two points even more problematic.

So I would say that I am OK with any machine readable one-line format. I just think JSON is easy to use and pretty standard. But because people will not like that JSON or machine readability is a default, I think we need a switch here, which I am proposing above.

[ianlancetaylor]

The argument that the perfect should not be an enemy of the good is sound, but it applies equally well to saying that we shouldn't change anything. After all, the stack backtrace format is quite regular, and there is already existing code that parses it successfully.

[davecheney]

Supporting evidence for Ian's comment, https://github.com/maruel/panicparse

[mitar]

O, thank you for linking that project. Because it was one of motivations for this issue for me. Have you checked the code? This is what motivates me to say: hey, there must be a better way. The problem is also that stack trace format is not formally standardized/documented, so the author has to chase custom exceptions and fix them as they are reported.

We could just have a JSON and all that would be trivial.

[maruel]

Hi! Panicparse's author here.

I'm strongly agreeing with Russ and Ian. Please do not add any flag to customize the output. I'm in favor to closing this request as wontfix:

• panicparse's library can now extract snapshots from a stream (e.g. from a server's stderr), which should solve your problem at hand.
• panics can come from C or assembly. Snapshots can be partially corrupted. There's no guaranteed that the process' state is good enough to output strictly valid JSON output. Thus the parser would have to optimize partially corrupted JSON, since they are the hardest kind of crashes to diagnose! This makes the whole point about structured output moot.

Foot note: Dave feel free to page me next time. I just happen to have found this issue because I was searching for something unrelated.

[rsc]

Adding to minutes, but the discussion seems to be trending toward decline.

[rsc]

Based on the discussion above, this seems like a likely decline.

[creker]

In case you're using fluentd to collect logs you can use https://github.com/GoogleCloudPlatform/fluent-plugin-detect-exceptions to detect stack traces of various languages including Go.

[mitar]

@rsc Thanks for updates. Is disagree with points above, but I am willing to accept view from the community on this. I just think it is sad that all output from the program cannot be controlled to be machine readable, but runtime adds its own output.

Is there anything more for me to do here or just wait for issue to be closed?

[ianlancetaylor]

@mitar Unless something leads to a change in consensus, this issue will be closed automatically, and there is nothing you need to do. Thanks for the suggestion.

[rsc]

No change in consensus, so declined.