Measure elapsed time with a defer statement in Go

I thought of using the defer statement to measure the elapsed time of a program in Go:

func main() {
	start := time.Now()
	defer fmt.Println(fmt.Sprintf("The process took %s", time.Now().Sub(start)))
    ...
}

I thought this would produce the correct result but it didn't:

[09:36:55]pc@work:~/test$ go run ./main.go
Processed 209806/209806 TUF files
All records are inserted in the database.
Verifying records are inserted correctly...
Verified 209806/209806 TUF files
All records have been inserted and verified successfully.
The process took 600ns
[14:24:06]pc@work:~/test$

Even though the process took 5 hours, which is visible from the timestamps on the left, the deferred fmt.Println() statement showed 600 nanoseconds. What am I doing wrong?

Defered function arguments are evaluated immediately. You can wrap their evaluation into an anonymous function to delay their evaluation until the defer actually gets triggered:

defer func() {
    fmt.Println(fmt.Sprintf("The process took %s", time.Now().Sub(start)))
}()

Read more about the defer statement in A Tour of Go and the language specification.

The arguments to the deferred function are evaluated right away, meaning the time.Now().Sub(start) part is computed right after the start.

If you want to time the function, say:

defer func() {
    time.Now().Sub(start) // ...
}()

Alternatively, I have written a package for it: https://github.com/gonutz/tic so you can say:

func main() {
    defer tic.Toc()()
}

and note the two ()() which are there for the exact same reason, the first function call starts the timing and returns a function to be deferred which stops the timing.