Go prints different function name from program counters returned from runtime.Callers() if I use errors package

Question

code1:

package main

import (
    "fmt"
    "github.com/pkg/errors"
    "runtime"
)

func main() {
    ptrs, _ := Test1("arg1", "arg2")
    for _, pc := range *ptrs {
        f := runtime.FuncForPC(pc)
        if f == nil {
            continue
        }
        filename, line := f.FileLine(pc)
        fmt.Printf("func name: %s, entry: %x, filename: %s, line: %d\n", f.Name(), f.Entry(), filename, line)
    }
}

func Test0(args ...interface{}) *[]uintptr {
    const depth = 32
    var pcs [depth]uintptr
    n := runtime.Callers(0, pcs[:])
    st := pcs[0:n]
    return &st
}

func Test1(args ...interface{}) (*[]uintptr, error) {
    return Test0(args...), errors.New("Test")
}

code2:

package main

import (
    "fmt"
    "runtime"
)

func main() {
    ptrs, _ := Test1("arg1", "arg2")
    for _, pc := range *ptrs {
        f := runtime.FuncForPC(pc)
        if f == nil {
            continue
        }
        filename, line := f.FileLine(pc)
        fmt.Printf("func name: %s, entry: %x, filename: %s, line: %d\n", f.Name(), f.Entry(), filename, line)
    }
}

func Test0(args ...interface{}) *[]uintptr {
    const depth = 32
    var pcs [depth]uintptr
    n := runtime.Callers(0, pcs[:])
    st := pcs[0:n]
    return &st
}

func Test1(args ...interface{}) (*[]uintptr, error) {
    return Test0(args...), nil//, errors.New("Test")
}

The only different part is returning error value of Test1(). In the code1 it returns erors.New("Test"), in the code2 it returns nil. In the FOR loop of main function, the program prints function name, the results are different:

result of code1:

func name: runtime.Callers, entry: 6a20c0, filename: C:/Program Files/Go/src/runtime/extern.go, line: 247
func name: runtime.Callers, entry: 6a20c0, filename: C:/Program Files/Go/src/runtime/extern.go, line: 247
func name: main.Test1, entry: 6a2180, filename: D:/develop/go-testbed/cmd/slicetest/slicetest.go, line: 30
func name: main.main, entry: 6a1ea0, filename: D:/develop/go-testbed/cmd/slicetest/slicetest.go, line: 11
func name: runtime.main, entry: 6476a0, filename: C:/Program Files/Go/src/runtime/proc.go, line: 259
func name: runtime.goexit, entry: 66eee0, filename: C:/Program Files/Go/src/runtime/asm_amd64.s, line: 1595

result of code2

func name: runtime.Callers, entry: b30020, filename: C:/Program Files/Go/src/runtime/extern.go, line: 247
func name: runtime.Callers, entry: b30020, filename: C:/Program Files/Go/src/runtime/extern.go, line: 247
func name: main.main, entry: b2fe00, filename: D:/develop/go-testbed/cmd/slicetest/slicetest.go, line: 10
func name: main.main, entry: b2fe00, filename: D:/develop/go-testbed/cmd/slicetest/slicetest.go, line: 9
func name: runtime.main, entry: ad6fc0, filename: C:/Program Files/Go/src/runtime/proc.go, line: 259
func name: runtime.goexit, entry: afe580, filename: C:/Program Files/Go/src/runtime/asm_amd64.s, line: 1595

As you see, code1 printed the correct function name, main.Test1 but code2 didn't. I read runtime.Callers print different program counters depending on where its run from which recommands to use runtime.CallersFrames() but I thinks it's not the problem because both code1 and code2 do not use it. I also see the errors.New() function but I didn't find something special. It creates callstack by caller() function which is almost same as Test0() in my code -- actually, I copied the contents of Test0() from caller().

Can someone tell me which causes the difference?

Go version: go1.19 windows/amd64

OS: windonws 11

version of github.com/pkg/errors: v0.9.1

Both of codes print the same result with main.Test1 if I run them in debug mode of Goland IDE.

Thank you!

score 2 · Accepted Answer · answered May 06 '23 at 12:30

2

From the documentation of runtime.Callers

To translate these PCs into symbolic information such as function names and line numbers, use CallersFrames. CallersFrames accounts for inlined functions and adjusts the return program counters into call program counters. Iterating over the returned slice of PCs directly is discouraged, as is using FuncForPC on any of the returned PCs, since these cannot account for inlining or return program counter adjustment.

(emph mine) You must not try to interpret the result of runtime.Callers yourself as you cannot do it properly. Your flawed attempt clearly demonsrates that the documentation is right.

This has literally nothing to do with github.com/pkg/errors (which is unmaintained and superseeded by new stuff in package errors anyway). It is a result of the compiler optimizing your code (differently while debugging).

Rule of thumb: Read the documentation of the functions you use and do what the documentation tells you. This is an instance of "Sometimes 3 month in the lab can spare you 6 hours in the library".

answered May 06 '23 at 12:30

Volker

40,468
7
81
87

Thank you. As I mentioned, I knew the `CallersFrames()` would solve my problem. What I really want to know is, WHY the results are different. I expected the same result, because the call chain, `errors.New(...) -> errors.callers() -> runtime.Callers()` does not include `CallersFrames()`, and my codes do nothing with the error. Reading document is important but... it is also important that the programs show same result for the same code in most cases. In my question, two codes are SAME except the part returning error so they should print same logs for function name. – Hodol May 06 '23 at 20:02
@Hodol Your code gets rewritten differently depending on the code (presence of errors.New) and whether it's being debuged or not. There is nothing to see here. The compiler is free to do so. There is no hidden why, just one function gets optimised differently than a different one. – Volker May 06 '23 at 20:42
O.K. I understand that the `errors` package can affect on the behavior of compiler. Thanks. – Hodol May 07 '23 at 06:54

Go prints different function name from program counters returned from runtime.Callers() if I use errors package

1 Answers1