runtime: GOTRACEBACK variant to print only the panicking goroutine

[idank]

GOTRACEBACK controls what gets printed on failure. By default "a failure prints a stack trace for every extant goroutine, eliding functions internal to the run-time system, and then exits with exit code 2."

It would be nice if we there was a variant that printed just the offending goroutine, which is usually what you care about during development.

[adg]

This needn't be a proposal IMO. It's an uncontroversial feature request.

[rsc]

Leaving in proposal process.

The offending goroutine is always printed first, because it's certainly the first thing you care about.

However, I think goroutines are central enough to Go and to understanding the overall state of the program that I'm a bit reluctant to have a mode that prints only one of them on a crash.

[davecheney]

I agree. When asking for more information on crash type bugs, one of the most frustrating issues is a desire by the op to truncate the crash to the "most important" information. I don't want to see a change that encourages this behaviour, however well intentioned.

On 24 Oct 2015, at 07:07, Russ Cox notifications@github.com wrote:

Leaving in proposal process.

The offending goroutine is always printed first, because it's certainly the first thing you care about.

However, I think goroutines are central enough to Go and to understanding the overall state of the program that I'm a bit reluctant to have a mode that prints only one of them on a crash.

—
Reply to this email directly or view it on GitHub.

[idank]

This isn't about changing the default.. rather merely adding the option for those who find this format more friendly, e.g. during development.

[davecheney]

I don't see why an option is needed, post processing the output, with
something like less or head will work just as well.

On Sat, Oct 24, 2015 at 10:40 AM, Idan Kamara notifications@github.com
wrote:

This isn't a about changing the default.. rather merely adding the option
for those who find this format more friendly, e.g. during development.

—
Reply to this email directly or view it on GitHub
#12366 (comment).

[rsc]

I thought more about this, and I discussed it with @aclements, who has a bit more of a "new Go programmer" perspective than I do, and he reminded me how noisy the extra goroutines are and how you have to learn that the current goroutine prints first and that you can usually ignore the rest of the output.

We've been through similar reductions before: we omit runtime stack frames when showing user goroutine stacks, and we omit internal runtime goroutines entirely, both in an attempt to boost the signal-to-noise ratio of crash dumps, even though occasionally those omissions do hurt debugging a complex problem.

For the vast majority of crash dumps one encounters in day-to-day work, it is true that only the current goroutine matters (panics due to nil pointer, index out of bounds, regexp.MustCompile, etc). It may be that, on balance, showing only the current goroutine by default would increase the signal-to-noise ratio of crash dumps enough to make up for the loss of information in more complex cases. Again, we already discard potentially useful information by default because it is too rarely useful. The question is whether all the extra goroutines are too rarely useful. I am coming around to the point that they might be.

I think if we did this we'd also want to add a runtime/debug.SetTraceback funtion to control GOTRACEBACK at run time. People with flaky programs might well want to call SetTraceback in main.

[rsc]

I'm going to watch my own programs for the next week or so and see how often I actually need more than just the current goroutine from a panic dump. I encourage others to do the same.

[davecheney]

@rsc rather than watching your own programs, I encourage you to look at the
samples posted in issues, the go forum, and the mailing list for counter
examples.

Obscuring the list of running goroutines makes it harder to spot problems
with leaking goroutines, oom errors caused by excessive concurrent cgo
calls, to name a few common requests for assistance.

I know I cannot be unbiased as an experienced go user, but "the important
information is at the top" has always been a simple rule for finding the
most pertinent information about a crash, and that doesn't mean we have to
hide the rest of the output.

On Sat, 24 Oct 2015, 15:29 Russ Cox notifications@github.com wrote:

I'm going to watch my own programs for the next week or so and see how
often I actually need more than just the current goroutine from a panic
dump. I encourage others to do the same.

—
Reply to this email directly or view it on GitHub
#12366 (comment).

[dominikh]

I have a feeling that changing the default to only showing one goroutine would benefit trivial errors only, and punish complex ones. One can argue that in a similar vein, this change would benefit newer Go programmers but punish more experienced ones.

One needs to keep in mind that crashes can happen unexpectedly and may be hard to reproduce, and little is more annoying than having insufficient debugging output when such a crash happens. Having to set an environment variable – that didn't need to be set for years – and wait for the crash to happen again is a terrible experience.

[aclements]

I worry about making this the default. As @dominikh said, it's incredibly frustrating to have insufficient debugging info because you forgot to turn on some option. I also worry that it will reduce the quality of bug reports, both by Go developers to Go and, especially, by end users to software written in Go.

I worry less about adding it as an option, but we have to ask if this is for experienced Go users or inexperienced ones? If it's for inexperienced ones, then it cannot be a non-default option because they won't find it. However, I think it's actually less important for inexperienced users because they tend not to have many goroutines. If it's for experienced ones, they can discover the option and weigh the costs and benefits of using it.

Here's an alternate proposal, though I'm not sure whether or not I like it. At the end of the traceback spew, re-print just the panic message and the file/line that it happened on (not the full traceback). If most of the time during development only the current goroutine matters, I posit that most of the time that only the current goroutine matters, only the line that failed matters. And if it turns out you need more than that, it's all there above.

[griesemer]

On Mon, Oct 26, 2015 at 7:51 AM, Austin Clements notifications@github.com
wrote:

At the end of the traceback spew, re-print just the panic message and the
file/line that it happened on (not the full traceback). If most of the
time during development only the current goroutine matters, I posit that
most of the time that only the current goroutine matters, only the line
that failed matters. And if it turns out you need more than that, it's all
there above.

I like this - especially if cleanly separated from the traceback. It will
improve the current situation (in most cases no need to scroll up to the
beginning of the traceback), and we won't lose any information by default.

-gri

[minux]

I was going to propose that we print the current goroutine last (perhaps duplicate the traceback if we afraid that existing traceback parsers might assume the order), but then I saw Austin's suggestion, and I like it very much. What could be an option is how many levels of stacktraces for the current goroutine to show at the end. I think something like 3 could be the default.

[rsc]

I'd like to try showing only one goroutine during the freeze. I am not sure it's the right thing to do, but it's at least plausible. I certainly understand the "but there's good information there!" counter-argument, but I thought the same thing abot eliding runtime frames, and I worry about being too conservative here ("it's always been that way") and thereby discounting what may be a good idea (as my initial reply did). We won't know unless we do the experiment, and the freeze seems as good a time as any to do it.

I will send a CL adding GOTRACEBACK=single and making it the default. I will file a separate issue to decide whether to restore the default for Go 1.6.

Thanks again for the proposal, @idank.

[rsc]

CL golang.org/cl/16512 is the CL adding the mode and making it the default, and #13107 is the issue about possibly rolling back the change in default.

[gopherbot]

CL https://golang.org/cl/16513 mentions this issue.

[gopherbot]

CL https://golang.org/cl/16512 mentions this issue.

[davecheney]

Yup, that's a fair position. Thanks Russ.

On Sat, Oct 31, 2015 at 5:44 AM, Russ Cox notifications@github.com wrote:

Closed #12366 #12366 via bf1de1b
bf1de1b
.

—
Reply to this email directly or view it on GitHub
#12366 (comment).