I once worked on a codebase where every method was supposed to log when it was entered and when it returned. With a few hundred methods, that meant the same two lines everywhere.

The problem

Every method started like this:

logs.Trace("Entry: <method name>")
defer logs.Trace("Exit: <method name>")

Two lines, duplicated everywhere, with the method name written out by hand in both. Renaming a method meant remembering to update two string literals, and copy-pasting the pair into a new method meant remembering to change them at all. Most of the stale log lines I found came from exactly that.

What I wanted was one line, with the name written once.

Functions that return functions

A higher-order function either takes a function as a parameter or returns one. The second kind solves this neatly: have trace log the entry immediately and hand back a function that logs the exit.

trace.go
package main
 
import (
	"fmt"
)
 
func trace(functionName string) func() {
	fmt.Printf("Entering '%s'\n", functionName)
 
	return func() {
		fmt.Printf("Leaving '%s'\n", functionName)
	}
}
 
func foo() {
	defer trace("foo")()
	fmt.Println("Executing foo")
}
 
func main() {
	foo()
}
Entering 'foo'
Executing foo
Leaving 'foo'

The closure returned by trace captures functionName, so the exit message knows which function it belongs to without being told a second time.

The two sets of parentheses

The highlighted line is doing something more subtle than it looks, and it is worth being precise about it. defer trace("foo")() contains two calls:

  • trace("foo") runs immediately, printing Entering 'foo' and returning a function.
  • That returned function is what gets deferred, so it runs when foo returns, printing Leaving 'foo'.

The rule behind this is that defer evaluates everything except the final call straight away. It needs to know which function to defer and with what arguments, so it evaluates the expression that produces them at the point the defer statement executes — and only postpones the outermost call.

WARNING

Drop the second () and the code still compiles, still passes go vet, and is wrong. With defer trace("foo") it is trace itself that gets deferred, so the output becomes:

Executing foo
Entering 'foo'

The entry message now prints on the way out, and the exit message never prints at all — the returned closure is discarded unused. Nothing warns you. If your entry logs look strangely late and your exit logs have vanished, this is why.

Was it worth it

Per method, two lines became one, and the method name is written once instead of twice. The whole entry/exit convention now lives in a single function, so changing the format, adding a timestamp, or routing it to a different logger is one edit rather than a few hundred.

The pattern generalises well beyond logging. Anything with a symmetric setup and teardown — opening and closing a span, acquiring and releasing a lock, starting and stopping a timer — fits the same shape: do the setup, return the teardown, and let defer handle the rest.