Golang : How to profile or log time spend on execution?

Being able to calculate how long it takes to execute a routine or function is crucial in optimizing a program(this is also known as profiling a program). The time taken to execute a routine can help developers to determine where is the bottleneck and introduce better algorithm or use faster packages to achieve the desire result.

In this tutorial, we will explore how to calculate time spend on executing a routine or function in Golang.

The algorithm is simple :

First, take a snapshot of the time before execution and after execution. Then calculate the difference.

For example :

 package main

 import (
 "fmt"
 "log"
 "time"
 )

 func main() {
 t1 := time.Now()
 fmt.Println("Do something...")
 t2 := time.Now()
 log.Printf("[Do something] takes about %v\n", t2.Sub(t1))
 }

Sample output :

Do something...

2015/03/30 10:24:52 [Do something] takes about 36.466µs

Do something...

2015/03/30 10:24:54 [Do something] takes about 36.193µs

another example for web GET operation. This must take into account of your Internet connection speed as well.

 func indexHandler(w http.ResponseWriter, r *http.Request) {
 t1 := time.Now()
 fmt.Fprintf(w, "Hello World!")
 t2 := time.Now()
 log.Printf("[%s] %q %v\n", r.Method, r.URL.String(), t2.Sub(t1))
 }

 func main() {
 http.HandleFunc("/", indexHandler)
 http.ListenAndServe(":8080", nil)
 }

Sample output :

[GET] / 1.1ms

[GET] /contact 2.08ms

IF you need better and detailed analysis on your Golang program. Please read up the official Golang's blog on profiling http://blog.golang.org/profiling-go-programs

Reference :

Wikipedia : Profiling computer program.