Skip to content
New issue

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

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

Already on GitHub? # to your account

Log panic stack traces #278

Merged

Conversation

RichVanderwal
Copy link
Contributor

The Go Agent is able to record errors in the case of panics. This functionality is normally turned off, see the comments here in the source.

A larger customer of ours noticed that when cfg.ErrorCollector.RecordPanics turned on (that is, set to true), the Go Agent "swallows" any stack trace that would normally be displayed by the Go runtime during a panic. This means the customer simply doesn't see stack traces anymore after panics. See issue #275.

When a reproduction of the problem is run with this PR in place, it logs the stack trace very similarly to the original Go runtime version, but with extra frames at the top of the trace that show the Go Agent is doing its job.

Here's the output from the Go runtime when cfg.ErrorCollector.RecordPanics is turned off:

panic: runtime error: index out of range [5] with length 0

goroutine 1 [running]:
main.doit(0xc0000b8690)
	/Users/rvanderwal/delete_me/main.go:18 +0x92
main.main()
	/Users/rvanderwal/delete_me/main.go:35 +0x1b2
exit status 2

Here's the output from the Go Agent with this PR applied when cfg.ErrorCollector.RecordPanics is turned on:

2021/03/17 00:11:47 goroutine 1 [running]:
runtime/debug.Stack(0xc000782d70, 0xc00c88ccd4b1a738, 0x1880b301eb)
	/usr/local/go/src/runtime/debug/stack.go:24 +0x9f
github.com/newrelic/go-agent/v3/newrelic.(*thread).End(0xc000782d70, 0x151ab20, 0xc0001fc0d8, 0x0, 0x0)
	/Users/rvanderwal/newrelic/go-agent/v3/newrelic/internal_txn.go:384 +0x15c5
github.com/newrelic/go-agent/v3/newrelic.(*Transaction).End(0xc0003c8318)
	/Users/rvanderwal/newrelic/go-agent/v3/newrelic/transaction.go:41 +0x67
panic(0x151ab20, 0xc0001fc0d8)
	/usr/local/go/src/runtime/panic.go:965 +0x1b9
main.doit(0xc000120690)
	/Users/rvanderwal/delete_me/main.go:19 +0xa8
main.main()
	/Users/rvanderwal/delete_me/main.go:42 +0x1b1

Here's the small program I used to reproduce the issue.

package main

import (
	"fmt"
	"os"
	"time"

	"github.com/newrelic/go-agent/v3/newrelic"
)

func doit(app *newrelic.Application) {
	defer itsOK()
	txn := app.StartTransaction("panic test 01")
	defer txn.End()

	var mySlice []int

	time.Sleep(time.Duration(time.Second * 1))
	fmt.Println(mySlice[5])
	time.Sleep(time.Duration(time.Second * 1))

}
func itsOK() {
	recover()
}

func main() {
	app, err := newrelic.NewApplication(
		newrelic.ConfigAppName("Example App"),
		newrelic.ConfigLicense(os.Getenv("NEW_RELIC_LICENSE_KEY")),
		newrelic.ConfigDebugLogger(os.Stdout),
		func(cfg *newrelic.Config) {
			cfg.ErrorCollector.RecordPanics = true
		},
	)
	if nil != err {
		fmt.Println(err)
		os.Exit(1)
	}
	time.Sleep(time.Duration(time.Second * 5))
	for i := 0; i < 100; i++ {
		doit(app)
	}

	app.Shutdown(time.Duration(time.Second * 60))
}

@RichVanderwal RichVanderwal added this to the Mar Go agent release milestone Mar 17, 2021
@RichVanderwal RichVanderwal linked an issue Mar 17, 2021 that may be closed by this pull request
@RichVanderwal RichVanderwal merged commit 1d27985 into newrelic:develop Mar 17, 2021
@RichVanderwal RichVanderwal deleted the log-stack-trace-on-panic branch March 17, 2021 20:42
# for free to join this conversation on GitHub. Already have an account? # to comment
Labels
Projects
None yet
Development

Successfully merging this pull request may close these issues.

Swallowed Panic Traces
2 participants