pkg / errors

Simple error handling primitives
https://godoc.org/github.com/pkg/errors
BSD 2-Clause "Simplified" License
8.18k stars 691 forks source link

Stacktrace don't print all stack #227

Closed MAAARKIN closed 4 years ago

MAAARKIN commented 4 years ago

Current scenario.

AuthorizationService has a GetDetails function that call a CardService GetCard function.

func (a AuthorizationServiceImpl) GetDetails(ctx context.Context, model *authorization.Authorization) (*authorization.Detail, error) {
    ...
    cardDetail, err := a.cardService.GetCard(ctx, model.CardNumber)
    if err != nil {
//line 41       return nil, errors.Wrap(err, "service error during GetDetails")
    }

    ...
}

CardService has a GetCard function that call a CardDelivery CardDetails function

func (c CardServiceImpl) GetCard(ctx context.Context, cardNumber string) (*card.Card, error) {
    ...
    detailPan, err := c.cardDelivery.CardDetails(ctx, cardNumber)
    if err != nil {
//line 30       return nil, errors.Wrap(err, "service error during GetCard")
    }

    ...
}

CardDelivery has a CardDetails function that call a HttpClient Post

func (r *RestImpl) CardDetails(ctx context.Context, cardNumber string) (*DetailPan, error) {
    ...
    response, err := r.httpClient.Post(piercardsUrl + "/check-pan", body, headers, nil)

    if err != nil {
//line 45       return nil, errors.Wrap(err, "delivery error during CardDetails")
    }

my problem occuring this last function but when i print the stacktrace they are not show the last 2 functions:

Stack Trace:

dev.azure.com/conductortech/prepaid/_git/orchestrator.git/internal/service.AuthorizationServiceImpl.GetDetails
    C:/Workspace/prepaid/orchestrator/internal/service/authorization.go:41
dev.azure.com/conductortech/prepaid/_git/orchestrator.git/cmd/http/handlers.AuthorizationController.checkAuthorization
    C:/Workspace/prepaid/orchestrator/cmd/http/handlers/authorizations.go:48
net/http.HandlerFunc.ServeHTTP
    C:/Go/src/net/http/server.go:2007

the last two services are not printed in the stacktrace, but they are wrapped with errors.Wrap(err, msg)

My code to print the stacktrace:

                fmt.Println("Cause:")
        fmt.Println(errors.Cause(err))
        if err, ok := err.(stackTracer); ok {
            fmt.Println("Stack Trace:")
            result := fmt.Sprintf("%+v", err.StackTrace()[0:6])
            fmt.Println(result)
        }

i'm doing anything wrong ?

puellanivis commented 4 years ago

What version of pkg/errors are you using? Some earlier versions have different behavior.

Using errors.Wrap(…) at every layer is inefficient, because it tends to end up repeating a lot of the same stacktrace information all the way up the chain. Ideally, you should use errors.Wrap(…) only on the non-pkg/errors error at the very start of the chain, and then at each additional level use errors.WithMessage(…).

Finally, you do not have to extract the stacktrace yourself to print it out. It should be printed out just by using fmt.Printf("%+v\n", err)

MAAARKIN commented 4 years ago

@puellanivis i'm using "github.com/pkg/errors v0.9.1" version.

i will try to refactor my code to using like you said, i will change today and i go back to say if work. @puellanivis thx for your help.

MAAARKIN commented 4 years ago

@puellanivis i change the code... but not work exactly i want, i need to extract the stacktrace to report to the team, to be honest, i just use the pkg error to show the stacktrace, but the stracktrace just print the first 2 levels of my services, if i change wraps to WithMessage, the stacktrace dont show.

i tried to use WithStack(err) to chain and just when the cause started i use Wrap, but the stacktrace dont show the entire stacktrace.

MAAARKIN commented 4 years ago

Using code:

fmt.Printf("%+v", err.StackTrace()[0:6])

Print:

Stack Trace:

myrepos/conductortech/prepaid/_git/orchestrator.git/internal/service.AuthorizationServiceImpl.GetDetails
    C:/Workspace/prepaid/orchestrator/internal/service/authorization.go:42
myrepos/conductortech/prepaid/_git/orchestrator.git/cmd/http/handlers.AuthorizationController.checkAuthorization
    C:/Workspace/prepaid/orchestrator/cmd/http/handlers/authorizations.go:48
net/http.HandlerFunc.ServeHTTP
    C:/Go/src/net/http/server.go:2007
github.com/go-chi/chi.(*Mux).routeHTTP
    C:/Users/marcos.filho/go/pkg/mod/github.com/go-chi/chi@v4.0.3+incompatible/mux.go:425
net/http.HandlerFunc.ServeHTTP

Using the second code:

fmt.Printf("%+v\n", err)

print:

myrepos/conductortech/prepaid/_git/orchestrator.git/internal/delivery/cards.(*RestImpl).CardDetails
    C:/Workspace/prepaid/orchestrator/internal/delivery/cards/rest.go:45
myrepos/conductortech/prepaid/_git/orchestrator.git/internal/service.CardServiceImpl.GetCard
    C:/Workspace/prepaid/orchestrator/internal/service/card.go:28
myrepos/conductortech/prepaid/_git/orchestrator.git/internal/service.AuthorizationServiceImpl.GetDetails
    C:/Workspace/prepaid/orchestrator/internal/service/authorization.go:39
myrepos/conductortech/prepaid/_git/orchestrator.git/cmd/http/handlers.AuthorizationController.checkAuthorization
    C:/Workspace/prepaid/orchestrator/cmd/http/handlers/authorizations.go:48
net/http.HandlerFunc.ServeHTTP
    C:/Go/src/net/http/server.go:2007
github.com/go-chi/chi.(*Mux).routeHTTP
    C:/Users/marcos.filho/go/pkg/mod/github.com/go-chi/chi@v4.0.3+incompatible/mux.go:425
net/http.HandlerFunc.ServeHTTP

The problem it's happen only if i limit the stack, the correct stack is the second code, But is too Huge, i want to limit the print. But if i limit the code don't print first two lines (in bold), this lines are most important for the stacktrace.

it's a bug ?

puellanivis commented 4 years ago

if i change wraps to WithMessage, the stacktrace dont show.

Yes, WithMessage does not attach stack traces, at all, so you will get no stack traces. But you should still use it instead of errors.Wrap() or errors.WithStack() at each level after the first wrap, otherwise you keep overwriting stacks with a newer stack. Notice:

    C:/Workspace/prepaid/orchestrator/internal/service/authorization.go:42
vs
    C:/Workspace/prepaid/orchestrator/internal/service/authorization.go:39

The authorization.go:42 is where you’re calling the errors.Wrap, or errors.WithStack, not where you are calling the function that produced the error. This is why you are missing the top two layers of your stacktrace, because you’re overriding them with a new stacktrace at each layer.

You need to only attach the stack trace at the very first level. if you do not actually care about the messages, then just use errors.WithStack(err), at rest.go:45. And just return that error at each level, without doing anything to it.

If you still actually do want the messages, then at rest.go:45 use errors.Wrap(err, …), then at each other level use errors.WithMessage(err, …) then, when you go to print the stack, you need to unwrap each layer until you find a stackTracer which is easy given the new errors.As from go1.13:

Do:

                fmt.Println("Cause:")
        fmt.Println(errors.Cause(err))
        var st stackTracer
        if errors.As(err, &st) {
            fmt.Println("Stack Trace:")
            result := fmt.Sprintf("%+v", st.StackTrace()[0:6])
            fmt.Println(result)
        }

If you’re not using go1.13 then use xerrors.As(…).

MAAARKIN commented 4 years ago

thx u so much @puellanivis it worked very well. As you said, i was doing wrong, now at the first level i'm using WithStack and after that i'm just return the error, not wrap anymore. And now when i limit the message work very well.