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.

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

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

Closed
mitar opened this issue Jul 16, 2020 · 20 comments

Comments

@mitar
Copy link
Contributor

mitar commented Jul 16, 2020

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
Copy link
Contributor

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:

Thanks

@mitar
Copy link
Contributor Author

mitar commented Jul 16, 2020

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
Copy link
Contributor Author

mitar commented Jul 16, 2020

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.

@mitar mitar changed the title A way to format unhandled panic Proposal: A way to configure format unhandled panic are written out Jul 16, 2020
@mitar mitar changed the title Proposal: A way to configure format unhandled panic are written out Proposal: A way to configure format unhandled panics are written out Jul 16, 2020
@ianlancetaylor
Copy link
Contributor

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
Copy link
Contributor Author

mitar commented Jul 16, 2020

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
Copy link
Contributor

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
Copy link
Contributor Author

mitar commented Jul 16, 2020

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.

@gopherbot gopherbot added this to the Proposal milestone Jul 16, 2020
@ianlancetaylor ianlancetaylor changed the title Proposal: A way to configure format unhandled panics are written out proposal: runtime: add mechanism to configure format used to write out unhandled panics Jul 16, 2020
@ianlancetaylor ianlancetaylor added this to Incoming in Proposals (old) Jul 16, 2020
@mitar
Copy link
Contributor Author

mitar commented Jul 17, 2020

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
Copy link
Contributor

rsc commented Jul 22, 2020

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
Copy link
Contributor Author

mitar commented Jul 22, 2020

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
Copy link
Contributor

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
Copy link
Contributor

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

@mitar
Copy link
Contributor Author

mitar commented Jul 23, 2020

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
Copy link
Contributor

maruel commented Aug 31, 2020

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 rsc moved this from Incoming to Active in Proposals (old) Sep 18, 2020
@rsc
Copy link
Contributor

rsc commented Sep 23, 2020

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

@rsc
Copy link
Contributor

rsc commented Sep 30, 2020

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

@rsc rsc moved this from Active to Likely Decline in Proposals (old) Sep 30, 2020
@creker
Copy link

creker commented Sep 30, 2020

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
Copy link
Contributor Author

mitar commented Sep 30, 2020

@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
Copy link
Contributor

@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
Copy link
Contributor

rsc commented Oct 7, 2020

No change in consensus, so declined.

@rsc rsc closed this as completed Oct 7, 2020
@rsc rsc moved this from Likely Decline to Declined in Proposals (old) Oct 7, 2020
@golang golang locked and limited conversation to collaborators Oct 8, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
No open projects
Development

No branches or pull requests

8 participants