errorreporting: Stack incompatible with pkg/errors

[odsod]

Client

Error Reporting

Describe Your Environment

Go 1.10.1 on Ubuntu 18.04 (local development machine)

Use Case

type StackTracer interface {
	StackTrace() errors.StackTrace
}

var (
	projectID       = flag.String("projectID", "", "")
	credentialsFile = flag.String("credentialsFile", "", "")
)

func main() {
        flag.Parse()

	client, err := errorreporting.NewClient(ctx, *projectID, errorreporting.Config{
		ServiceName:    "test",
		OnError: func(err error) {
			log.Printf("Failed to report error: %+v", err)
		},
	}, option.WithCredentialsFile(*credentialsFile))
	if err != nil {
		panic(errors.Wrap(err, "failed to initialize error reporting client"))
	}

        // given a pkg/errors error
	testErr := errors.New("hello there")

        // report error without stack trace
	err = errorReportingClient.ReportSync(ctx, errorreporting.Entry{
		Error: testErr,
	})
	if err != nil {
		panic(errors.Wrap(err, "failed to log error"))
	}

        // report error with stack trace
	err = client.ReportSync(ctx, errorreporting.Entry{
		Error: testErr,
		Stack: []byte(fmt.Sprintf("%v", testErr.(StackTracer).StackTrace())),
	})
	if err != nil {
		panic(errors.Wrap(err, "failed to log error with stack trace"))
	}
}

Expected Behavior

Error gets reported successfully.

Actual Behavior

panic: failed to log error with stack trace: rpc error: code = InvalidArgument desc = ReportedErrorEvent.context must contain a location unless `message` contain an exception or stacktrace.

[jeanbza]

Hello! The problem here is probably testErr.(StackTracer).StackTrace(). The function expects a stack that looks something like:

goroutine 39 [running]:
runtime/debug.Stack()
	/gopath/runtime/debug/stack.go:24 +0x79
cloud.google.com/go/errorreporting.(*Client).logInternal()
	/gopath/cloud.google.com/go/errorreporting/errors.go:259 +0x18b
cloud.google.com/go/errorreporting.(*Client).Report()
	/gopath/cloud.google.com/go/errorreporting/errors.go:248 +0x4ed
cloud.google.com/go/errorreporting.TestReport()
	/gopath/cloud.google.com/go/errorreporting/errors_test.go:137 +0x2a1
testing.tRunner()
	/gopath/testing/testing.go:610 +0x81
created by testing.(*T).Run
	/gopath/testing/testing.go:646 +0x2ec

Does your stack look something like that? Could you post what you're seeing?

[odsod]

Hi Jean!

Thanks for the quick reply!

When I run this small program:

package main

import (
	"fmt"

	"github.com/pkg/errors"
)

type StackTracer interface {
	StackTrace() errors.StackTrace
}

func main() {
	stackTrace := fmt.Sprintf("%+v", errors.New("hello there").(StackTracer).StackTrace())
	fmt.Print("Start ---> #####")
	fmt.Print(stackTrace)
	fmt.Print("##### <---- End")
}

I get the following output:

 $ go run cmd/hello/main.go
Start ---> #####
main.main
        /home/oscar/go/src/github.com/einride/zapextra/cmd/test/main.go:14
runtime.main
        /usr/lib/go-1.10/src/runtime/proc.go:198
runtime.goexit
        /usr/lib/go-1.10/src/runtime/asm_amd64.s:2361##### <---- End

[odsod]

I assume that the error I'm seeing is a validation error from the gRPC service called by the error reporting client.

The format of the https://github.com/pkg/errors stack trace is indeed slightly different than the default stack trace as formatted by runtime.Stack.

Would it be possible to document the expected format of the stack trace so that users of pkg/errors can mangle it before reporting?

Alternatively, if possible, it would of course be very convenient if the error reporting service understood stack traces on the format emitted by pkg/errors. 😉

[jeanbza]

Hi @odsod - I totally missed the title where it mentioned pkg/errors, my apologies. I'm of the opinion the error reporting service should understand these stacks, and that we should document stacks we can understand. Thanks again for reporting this. I'm going to now follow up with the error reporting team to see if we can make their parser understand these stacks.

[odsod]

Thank you @jadekler for looking into this!

[jba]

This is being tracked by internal bug 112529621.

[odsod]

Thanks for the update @jba!

[jacekjagiello]

@jadekler Any updates on this? I'm also facing the same issue

[jeanbza]

I've just followed up again on the bug. No status updates at the moment, unfortunately - apologies.

[cbandy]

There are (more than?) a handful of issues on the pkg/errors project asking for changes to the formatting of stacktraces printed by wrapped errors. In those that I've seen, the maintainer consistently recommends users do the formatting to fit their needs, e.g. pkg/errors#102 (comment) .

Checking for the stacktrace interface introduces a dependency, certainly, but if this package wants to integrate, perhaps that's one way to go.

[jeanbza]

You may be able to use something like that, yes. However, parts of the service are unfortunately pretty tied to the parser's logic, so you'd have to find a parser that fits what the expectation is. I've dug some this morning but didn't come up with anything great; I'll keep the conversation going with that team.

[cmoad]

We hacked together a formatter that Stackdriver seems happy with. Some frame parts (routine id, routine status, func args) are either hard-coded or omitted, but the important parts work. Note that var ErrorReportingClient *errorreporting.Client is initialized in another file in this package.

package microservice

import (
	"bytes"
	"fmt"
	"runtime"
	"strings"

	"cloud.google.com/go/errorreporting"
	"github.com/pkg/errors"
)

type causer interface {
	Cause() error
}

type stackTracer interface {
	StackTrace() errors.StackTrace
}

// ReportError logs the given errorreporting entry to Stackdriver
func ReportError(entry errorreporting.Entry) {
	if ErrorReportingClient != nil {
		if len(entry.Stack) == 0 {
			// attempt to add a formatted stack based on the error
			entry.Stack = FormatStack(entry.Error)
		}
		ErrorReportingClient.Report(entry)
	}
}

// FormatStack is a best attempt at recreating the output of runtime.Stack
// Stackdriver currently only supports the stack output from runtime.Stack
// Tracking this issue for pkg/errors support: https://github.com/googleapis/google-cloud-go/issues/1084
func FormatStack(err error) (buffer []byte) {
	if err == nil {
		return
	}

	// find the inner most error with a stack
	inner := err
	for inner != nil {
		if cause, ok := inner.(causer); ok {
			inner = cause.Cause()
			if _, ok := inner.(stackTracer); ok {
				err = inner
			}
		} else {
			break
		}
	}

	if stackTrace, ok := err.(stackTracer); ok {
		buf := bytes.Buffer{}
		// routine id and state aren't available in pure go, so we hard-coded these
		buf.WriteString(fmt.Sprintf("%s\ngoroutine 1 [running]:\n", err.Error()))

		// format each frame of the stack to match runtime.Stack's format
		var lines []string
		for _, frame := range stackTrace.StackTrace() {
			pc := uintptr(frame) - 1
			fn := runtime.FuncForPC(pc)
			if fn != nil {
				file, line := fn.FileLine(pc)
				lines = append(lines, fmt.Sprintf("%s()\n\t%s:%d +%#x", fn.Name(), file, line, fn.Entry()))
			}
		}
		buf.WriteString(strings.Join(lines, "\n"))

		buffer = buf.Bytes()
	}

	return
}

[kamronbatman]

I am getting the same error with go-errors, which claims to use the same format as runtime/debug.Stack()

[odeke-em]

Cool @cmoad! Wanna spin that code in #1084 (comment) into a package?

Kindly pinging the various parties to checkout and perhaps use @cmoad's work in #1084 (comment) but also to follow-up with the internal bug filing @jba as per #1084 (comment)

[kamronbatman]

I made a package that can be used to create and format stacktraces that work for gcp. We use it for our logger in all of our projects and it gets the job done.
https://github.com/vyng/gcp-stacktrace-errors

[sagikazarmark]

@odeke-em I released an error handler library for Stackdriver that supports pkg/errors stack traces (based on the above code to format the stack trace):

https://github.com/emperror/handler-stackdriver

[odeke-em]

Thanks everyone! Great to see your converters @kamronbatman @sagikazarmark -- so perhaps we can link folks to your packages.

I've spent sometime this evening examining this issue and also thinking
about alternatives such as providing an interface like

type StackSourceLocationer interface {
     Stack() []byte
     SourceLocation() (filepath string, lineno int32, functionName string)
}

that the various error packages and wrappers could use, but unfortunately that seems a little
hacky as a workaround for not being able to support something that is documented
by the product's expectations as per https://cloud.google.com/error-reporting/reference/rest/v1beta1/projects.events/report#ReportedErrorEvent.message

and which requests that Stack be of the format produced by https://golang.org/pkg/runtime/debug/#Stack at least for Go.

Thus, I have instead sent a CL which documents this expectation so the various
consumers can use the respective library of choice to format stacktraces.

If/when the product can consume pkg/errors then we'll update the respective document
and that can turn into a feature, or maybe we could re-explore the StackSourceLocationer interface, but for now I've mailed out CL https://code-review.googlesource.com/c/gocloud/+/43431 which will close this issue after the documentation is merged.

Sorry that we couldn't do more but really the product expectation is what defines what we can do.

[sagikazarmark]

@odeke-em what's the appropriate channel to communicate this to the stackdriver developers?

I understand that this is not the place where this problem can be solved, but closing the issue without somehow following up with the them sounds...wrong.

[odeke-em]

@odeke-em what's the appropriate channel to communicate this to the stackdriver developers?
I understand that this is not the place where this problem can be solved, but closing the issue without somehow following up with the them sounds...wrong.

@sagikazarmark in deed, and that's why this issue has been open for 364 days (~1 year), the bug was filed internally at Google as per #1084 (comment).

However, I've filed https://issuetracker.google.com/issues/138952283 which everyone can publicly track, please post up feedback and support on that issue.

With that I am going to merge in the CL that documents this problem and as we've seen there at least 2 packages to help with this reformatting to runtime.Stack.

Thank you all for the discourse and for using this package!