Imre Nagi

Better Error Wrapping

I received feedbacks about the first writeup from my colleagues when I posted it on my company’s slack channel. Apart from the approach that is being quite controversial because I add behavior to the errors to determine what http status it should return, at least I know something that I have been missing or ignoring for so long.

On the previous article, I mentioned that we can wrap the error by using fmt.Errorf and %w.

func main() {
	innerErr := fmt.Errorf("internal")
	outerErr := fmt.Errorf("up: %w", innerErr)
	log.Error().Err(outerErr).Msg("just a long message")
}

The output when running this snippet will be:

{"level":"error","error":"up: internal","time":"2023-05-13T06:53:29-04:00","message":"just a long message"}

I knew that github.com/pkg/errors has utility method errors.Wrap() to wrap the error. I knew that the error message returned by fmt.Errorf("%w") and errors.Wrap() could be similar with the same format. If we try to use error.Wrap(), the result is pretty much similar.

outerErr := errors.Wrap(innerErr, "up")

// {"level":"error","error":"up: internal","time":"2023-05-13T07:02:10-04:00","message":"just a long message"}

However, I didn’t realize that errors.Wrap() is more useful in debugging purpose.

At least when I’m asking ChatGPT, here it is the reason why errors.Wrap() is useful:

Here are some reasons why errors.Wrap() is considered special:

Stack trace: When errors.Wrap() is used, it captures a stack trace at the point where the error is wrapped. This means that the stack trace will contain information about the sequence of function calls leading to the error. Having a stack trace helps in identifying the sequence of events that led to the error, enabling faster debugging and issue resolution.

The the initial idea of using error wrap is to know the origin of the error. Stack trace most of the time can give us detail information that is probably helpful in finding the root cause of the issue during debugging. This is something that fmt.Errorf can’t do much.

But how to get those information out? In rs/zerolog, we can utilize Stack() and set zerolog.ErrorStackMarshaler with format we want to get that information out.

package main

import (
	"fmt"

	"github.com/pkg/errors"
	"github.com/rs/zerolog"
	"github.com/rs/zerolog/log"
	"github.com/rs/zerolog/pkgerrors"
)

func main() {
	zerolog.ErrorStackMarshaler = pkgerrors.MarshalStack
	outerErr := outer()
	log.Error().Stack().Err(outerErr).Msg("just a long message")
}

func inner() error {
	return fmt.Errorf("internal")
}

func outer() error {
	return errors.Wrap(inner(), "outer")
}

The log generated by the error now (after being prettified) is similar to this:

{
    "level": "error",
    "stack": [
        {
            "func": "outer",
            "line": "23",
            "source": "main.go"
        },
        {
            "func": "main",
            "line": "14",
            "source": "main.go"
        },
        {
            "func": "main",
            "line": "250",
            "source": "proc.go"
        },
        {
            "func": "goexit",
            "line": "1594",
            "source": "asm_amd64.s"
        }
    ],
    "error": "outer: internal",
    "time": "2023-05-13T07:11:57-04:00",
    "message": "just a long message"
}

When looking at the stack trace, now we should be able to tell that where the error is originating from, that is from outer function on line 23.

References

Follow me

Follow my social media accounts!