twitchtv / twirp

A simple RPC framework with protobuf service definitions
https://twitchtv.github.io/twirp/docs/intro.html
Apache License 2.0
7.19k stars 326 forks source link

Log stack trace from recovered panic #325

Closed titpetric closed 3 years ago

titpetric commented 3 years ago

When recovering a panic, an internalWithCause error is created. When recover is being invoked, it should be possible to invoke runtime/debug.Stack or PrintStack to log the stack trace where the error is coming from. I'd like to print the stack trace from a ServerHooks error handler, but it's unreachable at that point. I'd even prefer if the server crashed, so I could inspect the stdout/stderr logs.

I had to add a debug.PrintStack() into the recover() scope to figure out what particularly the source of the panic was.

It could be possible to create the error that conforms to pkg/errors stack tracer interface:

type stackTracer interface {
        StackTrace() errors.StackTrace
}
titpetric commented 3 years ago

It often happens, for whatever reason, that I keep adding this into the twirp generated code:

--- a/service/bots/src/rpc/points/points.twirp.go
+++ b/service/bots/src/rpc/points/points.twirp.go
@@ -17,6 +17,7 @@ import ioutil "io/ioutil"
 import json "encoding/json"
 import strconv "strconv"
 import strings "strings"
+import "runtime/debug"

 import protojson "google.golang.org/protobuf/encoding/protojson"
 import proto "google.golang.org/protobuf/proto"
@@ -1095,6 +1096,7 @@ func (e *wrappedError) Cause() error  { return e.cause } // for github.com/pkg/e
 // The panic is re-raised so it can be handled normally with middleware.
 func ensurePanicResponses(ctx context.Context, resp http.ResponseWriter, hooks *twirp.ServerHooks) {
        if r := recover(); r != nil {
+               debug.PrintStack()
                // Wrap the panic as an error so it can be passed to error hooks.
                // The original error is accessible from error hooks, but not visible in the response.
                err := errFromPanic(r)

If I understand correctly, if I could define a panic handler I could put debug.PrintStack there, it would just need to be invoked around the vicinity of this code (errFromPanic maybe). /I'm also unsure the panic should be re-thrown, since the stack information from the recovered panic is lost./

Would you consider extending ServerHooks with a panic handler? Even invoking the Error func already defined would mean that I can print the stack here.

titpetric commented 3 years ago

I'll close this one as invalid, I see now that the Error() function in hooks is invoked, so there is a way to log the stack without changes. I'm not sure if the docs need improvement, or I just need to read code better. Best regards.