How to use pkg/errors to annotate error & pretty print stack trace in golang?

Consider the following code (https://go.dev/play/p/hDOyP3W_lqW)

package main

import (
	"log"

	"github.com/pkg/errors"
)

func myError() error {
	return errors.New("failing unconditionally")
}

func myError1() error {
	return errors.Errorf("annotate with additional debug info: %+v", myError())
}

func myError2() error {
	return errors.Errorf("extra debug info: %+v", myError1())
}

func main() {
	if err := myError2(); err != nil {
		log.Printf("%+v", err)
	}
}

I originate the error with errors.New and annotate it with additional info using errors.Errorf.

It does what I want--record and print the stack trace & line number. However, the problem is that the output of log.Printf("%+v", err) is verbose and repetitive:

2009/11/10 23:00:00 extra debug info: annotate with additional debug info: failing unconditionally
main.myError
	/tmp/sandbox3329712514/prog.go:10
main.myError1
	/tmp/sandbox3329712514/prog.go:14
main.myError2
	/tmp/sandbox3329712514/prog.go:18
main.main
	/tmp/sandbox3329712514/prog.go:22
runtime.main
	/usr/local/go-faketime/src/runtime/proc.go:250
runtime.goexit
	/usr/local/go-faketime/src/runtime/asm_amd64.s:1571
main.myError1
	/tmp/sandbox3329712514/prog.go:14
main.myError2
	/tmp/sandbox3329712514/prog.go:18
main.main
	/tmp/sandbox3329712514/prog.go:22
runtime.main
	/usr/local/go-faketime/src/runtime/proc.go:250
runtime.goexit
	/usr/local/go-faketime/src/runtime/asm_amd64.s:1571
main.myError2
	/tmp/sandbox3329712514/prog.go:18
main.main
	/tmp/sandbox3329712514/prog.go:22
runtime.main
	/usr/local/go-faketime/src/runtime/proc.go:250
runtime.goexit
	/usr/local/go-faketime/src/runtime/asm_amd64.s:1571

iiuc, errors package appends an additional copy of stack trace to the error every time of annotating the error, as can be seen in the below snippet

// repetitive (thrice) error stack
main.myError
	/tmp/sandbox3329712514/prog.go:10
main.myError1
	/tmp/sandbox3329712514/prog.go:14
main.myError2
	/tmp/sandbox3329712514/prog.go:18
main.main
	/tmp/sandbox3329712514/prog.go:22
runtime.main
	/usr/local/go-faketime/src/runtime/proc.go:250
runtime.goexit
	/usr/local/go-faketime/src/runtime/asm_amd64.s:1571
main.myError1
	/tmp/sandbox3329712514/prog.go:14
main.myError2
	/tmp/sandbox3329712514/prog.go:18
main.main
	/tmp/sandbox3329712514/prog.go:22
runtime.main
	/usr/local/go-faketime/src/runtime/proc.go:250
runtime.goexit
	/usr/local/go-faketime/src/runtime/asm_amd64.s:1571
main.myError2
	/tmp/sandbox3329712514/prog.go:18
main.main
	/tmp/sandbox3329712514/prog.go:22
runtime.main
	/usr/local/go-faketime/src/runtime/proc.go:250
runtime.goexit
	/usr/local/go-faketime/src/runtime/asm_amd64.s:1571

My desired output is

// Desired output
2009/11/10 23:00:00 extra debug info: annotate with additional debug info: failing unconditionally
main.myError
	/tmp/sandbox3329712514/prog.go:10
main.myError1
	/tmp/sandbox3329712514/prog.go:14
main.myError2
	/tmp/sandbox3329712514/prog.go:18
main.main
	/tmp/sandbox3329712514/prog.go:22
runtime.main
	/usr/local/go-faketime/src/runtime/proc.go:250
runtime.goexit
	/usr/local/go-faketime/src/runtime/asm_amd64.s:1571

One way to achieve that is to only use the errors package to originate the error and then use fmt.Errorf with %+v to add additional info in the call stack (like this https://go.dev/play/p/OrWe6KUIL_m). However, it's error-prone and hard to enforce every developer to use this pattern in a large code base. Developers have to remember to use the errors package to originate the error and use fmt properly with %+v %s to print out the stack trace.

I'm wondering if this is the desired behavior (verbose and repetitive). And is it possible to consistently use the errors package to annotate errors along the call stack without worrying about appending repetitive stack trace copies (e.g., the errors magically knows the error already has a stack trace)?

there are v format specifiers for printing an error.

%s - print the error. If the error has a Cause it will be
printed recursively.

%v – It will print only values. The field name will not be printed. This is the default way of printing a struct when using Println
(print the error 👉🏻 If the error has a Cause it will be printed recursively.)

%+v – It will print both field and value.
(extended format. Each Frame of the error's StackTrace will be printed in detail.)

In your case:

func myerror() error {
    return errors.New("failing unconditionally") // 1️⃣
}

func myerror1() error {
    return errors.Errorf("annotate with additional debug info: %+v", myerror()) // 2️⃣
}

func myerror2() error {
    return errors.WithStack(myerror1()) // 3️⃣
}

1️⃣ create new error with stack file (errors.New)

2️⃣ create new error with "formatted" message and this error stack (errors.Errorf)

3️⃣ create new error with this error stack (errors.WithStack)

2022/07/13 11:42:03 annotate with additional debug info: failing unconditionally
github.com/kozmod/idea-tests/core/errors.myerror
	/Users/19798572/GolandProjects/idea-tests/core/errors/stack_test.go:10 // 1️⃣
github.com/kozmod/idea-tests/core/errors.myerror1
	/Users/19798572/GolandProjects/idea-tests/core/errors/stack_test.go:14
github.com/kozmod/idea-tests/core/errors.myerror2
	/Users/19798572/GolandProjects/idea-tests/core/errors/stack_test.go:18
github.com/kozmod/idea-tests/core/errors.TestStack.func1
	/Users/19798572/GolandProjects/idea-tests/core/errors/stack_test.go:35
testing.tRunner
	/Library/GoLang/go1.18.2.darwin-amd64/src/testing/testing.go:1439
runtime.goexit
	/Library/GoLang/go1.18.2.darwin-amd64/src/runtime/asm_amd64.s:1571
github.com/kozmod/idea-tests/core/errors.myerror1
	/Users/19798572/GolandProjects/idea-tests/core/errors/stack_test.go:14 // 2️⃣
github.com/kozmod/idea-tests/core/errors.myerror2
	/Users/19798572/GolandProjects/idea-tests/core/errors/stack_test.go:18
github.com/kozmod/idea-tests/core/errors.TestStack.func1
	/Users/19798572/GolandProjects/idea-tests/core/errors/stack_test.go:35
testing.tRunner
	/Library/GoLang/go1.18.2.darwin-amd64/src/testing/testing.go:1439
runtime.goexit
	/Library/GoLang/go1.18.2.darwin-amd64/src/runtime/asm_amd64.s:1571
github.com/kozmod/idea-tests/core/errors.myerror2
	/Users/19798572/GolandProjects/idea-tests/core/errors/stack_test.go:18 // 3️⃣
github.com/kozmod/idea-tests/core/errors.TestStack.func1
	/Users/19798572/GolandProjects/idea-tests/core/errors/stack_test.go:35
testing.tRunner
	/Library/GoLang/go1.18.2.darwin-amd64/src/testing/testing.go:1439
runtime.goexit
	/Library/GoLang/go1.18.2.darwin-amd64/src/runtime/asm_amd64.s:1571

1️⃣ start of the first error stack

2️⃣ start of the second error stack

3️⃣ start of the third error stack

You can simply create the "root" error with stack and then add message (wrap) "root" error

func myerror3() error {
	return errors.New("failing unconditionally")
}

func myerror4() error {
	return errors.WithMessage(myerror3(), "annotate with additional debug info")
}

func myerror5() error {
	return errors.WithMessage(myerror4(), "myerror5")
}

func main() {
    if err := myerror5(); err != nil {
        log.Printf("%+v", err)
    }
}

<kbd>PLAYGROUND</kbd>

or

func myError() error {
    // create error (github.com/pkg/errors + fmt) with stack (message)
	return fmt.Errorf("%+v", errors.New("failing unconditionally"))
}

func myError1() error {
	return fmt.Errorf("annotate with additional debug info: %v", myError())
}

func myError2() error {
	return fmt.Errorf("extra debug info: %v", myError1())
}

func main() {
	if err := myError2(); err != nil {
		log.Printf("%v", err)
	}
}

<kbd>PLAYGROUND</kbd>

I don't particularly like github.com/pkg/errors, so I wrote my own package with similar behavior where I can control the format of my stack.

You can find my package in github.com/go-msvc/errors and copy or change it as you like.

It does not have a errors.New(), only errors.Error() which does the same. You can change that in your copy to be consistent with the standard one (I will too).

I also wrap errors with errors.Wrapf(err, "...xxx failed..."). If you just append inside a string like you did, the formatter cannot traverse the layers.

So, when I take your main.go and change:

• New() to Error(),
• Errorf("....: %+v", err) to Wrapf(err, "..."), and
• import github.com/go-msvc/errors,
  Then it outputs this:

2022/07/14 13:35:33 main.go(18):extra debug info because main.go(14):annotate with additional debug info because main.go(10):failing unconditionally

That works for me and avoids lots of clutter in the stack.

If you want newlines, you can add that too, but I prefer my error messages in my log files not to have newlines.

Code:

package main

import (
    "log"

    "github.com/go-msvc/errors"
)

func myError() error {
    return errors.Error("failing unconditionally")
}

func myError1() error {
    return errors.Wrapf(myError(), "annotate with additional debug info")
}

func myError2() error {
    return errors.Wrapf(myError1(),"extra debug info")
}

func main() {
    if err := myError2(); err != nil {
        log.Printf("%+v", err)
    }
}