Is there an efficient way to calculate execution time in golang?
If you are timing an entire function, then you can use defer
to eliminate some of the repetitive code.
// timer returns a function that prints the name argument and
// the elapsed time between the call to timer and the call to
// the returned function. The returned function is intended to
// be used in a defer statement:
//
// defer timer("sum")()
func timer(name string) func() {
start := time.Now()
return func() {
fmt.Printf("%s took %v\n", name, time.Since(start))
}
}
func main() {
defer timer("main")() // <-- The trailing () is the deferred call
time.Sleep(time.Second * 2)
} // prints: main took 2s
Run the example on the playground.
The specification says this about deferred calls:
Each time a "defer" statement executes, the function value and parameters to the call are evaluated as usual and saved anew but the actual function is not invoked. Instead, deferred functions are invoked immediately before the surrounding function returns,
The function value timer("main")
is evaluated at the defer statement. The timer
function records the current time and returns an anonymous function. The returned anonymous function is invoked immediately before the surrounding function returns. The anonymous function computes and prints the elapsed time.
Use runtime.Callers and runtime.CallersFrames to automatically get the name of the calling function.
// callerName returns the name of the function skip frames up the call stack.
func callerName(skip int) string {
const unknown = "unknown"
pcs := make([]uintptr, 1)
n := runtime.Callers(skip+2, pcs)
if n < 1 {
return unknown
}
frame, _ := runtime.CallersFrames(pcs).Next()
if frame.Function == "" {
return unknown
}
return frame.Function
}
// timer returns a function that prints the name of the calling
// function and the elapsed time between the call to timer and
// the call to the returned function. The returned function is
// intended to be used in a defer statement:
//
// defer timer()()
func timer() func() {
name := callerName(1)
start := time.Now()
return func() {
fmt.Printf("%s took %v\n", name, time.Since(start))
}
}
func main() {
defer timer()()
time.Sleep(time.Second * 2)
} // prints: main.main took 2s
Note that there is a runtime cost for getting the function name compared to using a string literal as in the first part of this answer. To avoid measuring the cost of getting the function name, timer
gets the name before recording the start time.
Run the example on the playground.
The solution provided by Bayta Darell is perfect.
In addition, if you don't want to pass function name explicitly, you could accomplish it like this:
func SomeFunction(list *[]string) {
defer TimeTrack(time.Now())
// Do whatever you want.
}
func TimeTrack(start time.Time) {
elapsed := time.Since(start)
// Skip this function, and fetch the PC and file for its parent.
pc, _, _, _ := runtime.Caller(1)
// Retrieve a function object this functions parent.
funcObj := runtime.FuncForPC(pc)
// Regex to extract just the function name (and not the module path).
runtimeFunc := regexp.MustCompile(`^.*\.(.*)$`)
name := runtimeFunc.ReplaceAllString(funcObj.Name(), "$1")
log.Println(fmt.Sprintf("%s took %s", name, elapsed))
}
As a result, you would get:
SomeFunction took 15.483µs
For more information, Refer this article: Go Function Tracing
Share the knowledge. :)