Background

When we add business logs to our application code, regardless of the level of logging, in addition to the information that we actively pass to Logger for it to log, it is also very important to know which function printed the line and where it is located, otherwise it is likely to be like looking for a needle in a haystack when troubleshooting.

For logging, it is important to record the function name and line number of the caller of the Logger method. Some logging libraries support this, such as Zap.

1
2
3
4
5
6
7


func main() {
  logger, _ := zap.NewProduction(zap.AddCaller())
  defer logger.Sync()

  logger.Info("hello world")
}

Output:

1

{"level":"info","ts":1587740198.9508286,"caller":"caller/main.go:9","msg":"hello world"}

But if you want a robust development framework, you should not let yourself be strongly bound to a logging library, a better approach is to develop a logging facade, the program directly use the logging facade, and then the facade calls the logging library to complete the logging. A typical Java slf4j is this idea, where the program uses the slf4j directly, followed by a Logger that can be either logback or log4j or even any logging library implementation that satisfies the slf4j convention.

If we were to design a Log Facade with Go, we would need to get the caller’s function name and file location in the facade itself, so how do we achieve this inside Go? This requires the Caller function provided by the runtime standard library.

runtime.Caller

The function signature of runtime.Caller is as follows.

1

func Caller(skip int) (pc uintptr, file string, line int, ok bool)

The Caller function reports information about the file and line number of the function executed by the current Go program call stack. The parameter skip is the number of stack frames to go up, 0 is the caller of Caller (the call stack where Caller is located), 1 is the caller of the caller who called Caller, and so on. Isn’t it a bit dizzying, here’s an example.

1
2
3
4
5
6

func CallerA() {
  //The call stack of the function CallerA is obtained
  pc, file, lineNo, ok := runtime.Caller(0)
  //The call stack of the caller of the CallerA function is obtained
  pc1, file1, lineNo1, ok1 := runtime.Caller(1)
}

The return value of the function is the call stack identifier, the full filename with path, and the line number of the call in the file. If the information is not available, the return value ok will be set to false.

Get the function name of the caller

The first return value of runtime.Caller is a call stack identifier, through which we can get the function information of the call stack *runtime.Func, and then further get the function name of the caller, which will be used in the following functions and methods.

1
2
3

func FuncForPC(pc uintptr) *Func

func (*Func) Name

runtime.FuncForPC function returns a *Func indicating the call stack corresponding to the call stack identifier pc; if the call stack identifier does not have a corresponding call stack, the function returns nil.

The Name method returns the name of the function called by the call stack. As mentioned above, runtime.FuncForPC may return nil, but the Name method is implemented in such a way to avoid the possibility of panic, so we can use it with confidence.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11

func (f *Func) Name() string {
 if f == nil {
  return ""
 }
 fn := f.raw()
 if fn.isInlined() { // inlined version
  fi := (*funcinl)(unsafe.Pointer(fn))
  return fi.name
 }
 return funcname(f.funcInfo())
}

Usage examples

Here’s a simple example of using runtime.Caller and runtime.FuncForPC together to get caller information.

 1
 2
 3
 4
 5
 6
 7
 8
 9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28

package main

import (
 "fmt"
 "path"
 "runtime"
)

func getCallerInfo(skip int) (info string) {

 pc, file, lineNo, ok := runtime.Caller(skip)
 if !ok {

  info = "runtime.Caller() failed"
  return
 }
 funcName := runtime.FuncForPC(pc).Name()
 fileName := path.Base(file) // The Base function returns the last element of the path
 return fmt.Sprintf("FuncName:%s, file:%s, line:%d ", funcName, fileName, lineNo)
}

func main() {

 // Print out information about the getCallerInfo function itself
 fmt.Println(getCallerInfo(0))
 // Print out information about the caller of the getCallerInfo function
 fmt.Println(getCallerInfo(1))
}

Note: Here we demonstrate that it is relatively simple to trace up a call stack to get the caller’s information. When you really want to implement a class library like log facade, there may be several layers of encapsulation, and the caller information you want to record in the log should be the location where the business code hits the log, then the number of layers to go back up is definitely not as simple as 1. The specific number of layers to skip depends on the specific encapsulation of the implemented log facade.

Summary

Caller` back through the call stack to get information about the caller, although powerful, but frequent access to this information can also have an impact on program performance. Our business code shouldn’t depend on it for implementation, it’s more useful for some libraries that are transparent to the business and only used when logging information.