Tag Archives: Go

Investigating Memory Leaks in Go with pprof

Memory leaks are among the toughest problems a software engineer may need to deal with. A program consumes huge amounts of memory, possibly crashes as a result, and it’s not immediately apparent why. Different languages have different tools to deal with resource problems. In Go, we can use the built-in profiler called pprof.

To see it in action, we’ll consider a simple program that allocates some memory. It’s not the best example, but real situations with memory leaks are both hard to troubleshoot and to make up. So instead of trying to come up with a really good example, I’ll show you how to use the tooling on a simple one, and then you can apply the same steps when you encounter a real problem situation.

package main

import (
	"fmt"
)

func main() {
	const size = 1000000
	waste := make([]int, size)
	for i := 0; i < size; i++ {
		waste[i] = i
	}

	fmt.Println("Done.")
}

The above code is nothing special, right? It’s clear where we’re allocating memory. However, real situations aren’t always so simple, and so we’ll use pprof to help us understand what’s going on under the hood. We do this by adding a couple of imports and setting up an endpoint as follows:

package main

import (
	"fmt"
	"net/http"
	_ "net/http/pprof"
)

func main() {
	const size = 1000000
	waste := make([]int, size)
	for i := 0; i < size; i++ {
		waste[i] = i
	}

	http.ListenAndServe("localhost:8090", nil)

	fmt.Println("Done.")
}

Before we go on, there are a few things to note at this point:

  • The port is arbitrary. You can use any you want, as long as it doesn’t conflict with something else.
  • If you want to access the endpoint from another machine, use 0.0.0.0 instead of localhost.
  • It’s generally not a good idea to include profiling code with a program by default, because its operation can cause nontrivial resource consumption, and can also expose internal details about the code that can have security and intellectual property implications. So, do this only in case of necessity and in a controlled environment.
  • The ListenAndServe() is blocking, so in this case you won’t see “Done.” printed afterwards. If you need code to resume afterwards (e.g. you’re using a web framework such as Gin), run ListenAndServe() at the beginning in a goroutine like:
	go func() {
		err := http.ListenAndServe("localhost:8090", nil)
		if err != nil {
			fmt.Println(err)
		}
	}()

So, once you’ve got pprof set up, you can run the program and, from a separate terminal, access /debug/pprof relative to the endpoint you specified:

Accessing the pprof endpoint

From here, if we click on “heap”, we get a dump of heap (memory) information:

The program’s heap info from pprof

Because this output is rather cryptic, our problem now shifts from obtaining memory data to interpreting it. Grab a copy of this heap dump either by saving directly from the browser, or using the following command. If it’s on a server, copy it over to your local system using scp or similar. We’ll inspect the memory using this dump, but hang onto it so that you can compare the state before and after a possible fix later.

curl http://localhost:8090/debug/pprof/heap > heap.dump

Once you have the heap dump on your local system, there are different ways to inspect it. The easiest way I found is to use pprof’s -http switch to run a local web server that gives you a few different views. Let’s try that:

go tool pprof -http=localhost:8091 heap.dump

Again, the port here is arbitrary but it needs to be different from the one you specified in the code. That was for the pprof endpoint, whereas this one is for pprof’s analysis tool. Once this is running, we can open localhost:8091 to understand a little more:

The graph view and menu of viewing options
The flame graph view
The source view
The top view

This tool has a few different ways you can use to inspect memory allocation in the program’s heap. I find the graph, flame graph, top and source views most useful, but there are others. Because a program’s memory structures can be very complex, it often helps to use several of these views to look at it from different angles. For instance, the graph view gives us an idea of the extent of memory allocation as functions call each other, but the source view actually tells us the exact line that is allocating memory.

Keep in mind that the fact that memory is being allocated does not necessarily imply that there is a problem. So, in practice you’ll need to diligently spend time inspecting several heap dumps of the same program at different times or with different changes. Every program is different, so there’s no general-purpose advice that can be offered to solve memory leaks. pprof can help you gather and view data about the program’s memory, but it’s up to you to understand the nature of how your program behaves and be able to spot bad behaviour in the heap dumps.

While I prefer the above approach, some people like inspecting heap dumps directly in the terminal using pprof. For instance, you can run pprof without the -http switch to enter interactive mode and then use the svg command to generate the graph view as an image:

$ go tool pprof heap.dump
File: __debug_bin2191375990
Type: inuse_space
Time: Jun 16, 2024 at 12:36pm (CEST)
Entering interactive mode (type "help" for commands, "o" for options)
(pprof) svg
Generating report in profile001.svg
(pprof) 

Personally, I think this is a little more cumbersome because you have to learn pprof’s specific commands, it requires graphviz to be installed in some situations (for the image generation), and it takes more effort to see the different views that the web-based approach offers trivially. But, if you prefer it this way, the option is there.

So, hopefully the steps above should make pprof really easy for you to use. I’d like to express my gratitude to the following sources that helped me figure out how to use it originally, and contain some more detail if you need it:

Go: Gin Returns Misleading Response When JSON Fails

There’s a thing with Go where a float containing special values such as NaN, +Inf or -Inf will fail to serialize, as is documented in several GitHub issues (e.g. this one and this other one). We can see this easily as follows.

First, create a module:

go mod init main

Then, try serialising a special float value:

package main

import (
	"encoding/json"
	"fmt"
	"math"
)

func main() {
	if _, err := json.Marshal(math.NaN()); err != nil {
		fmt.Println(err)
	}
}

The output then shows:

json: unsupported value: NaN

Okay, so the serialiser doesn’t play well with special float values. Now, let’s talk about what happens when you do this in the Gin Web Framework.

We’ll get right to the point if we copy Gin’s “Getting Started” sample:

package main

import (
  "net/http"

  "github.com/gin-gonic/gin"
)

func main() {
  r := gin.Default()
  r.GET("/ping", func(c *gin.Context) {
    c.JSON(http.StatusOK, gin.H{
      "message": "pong",
    })
  })
  r.Run() // listen and serve on 0.0.0.0:8080 (for windows "localhost:8080")
}

Then, we tweak the struct to contain a special float value:

package main

import (
	"math"
	"net/http"

	"github.com/gin-gonic/gin"
)

func main() {
  r := gin.Default()
  r.GET("/ping", func(c *gin.Context) {
    c.JSON(http.StatusOK, gin.H{
      "message": math.Inf(1),
    })
  })
  r.Run() // listen and serve on 0.0.0.0:8080 (for windows "localhost:8080")
}

After running a go mod tidy (or the go get command per Gin’s setup instructions) to retrieve the Gin dependency, we can run the program. This results in some pretty odd behaviour:

There’s an error in the output, but Gin returns a 200 response with no data in it.

By hitting the http://localhost:8080/ping endpoint (e.g. in a web browser), we get back a 200 OK response, with Content-Length: 0 and an empty body. Gin’s output clearly shows an error:

Error #01: json: unsupported value: +Inf

The same behaviour occurs with any JSON that can’t be parsed, not just floats. For instance, we could also put a function value into the JSON and Gin will half-fail the same way:

		c.JSON(http.StatusOK, gin.H{
			"message": func() {},
		})

It’s pretty misleading for the API to return a 200 OK as if everything’s fine, but with no data. We had this problem at my work, earlier this week, and in that case we didn’t even get the error in the output, so it was a tricky data issue to troubleshoot. It would be a lot better if Gin returned a response with an appropriate status code and body so that the API’s client could at least get an idea of what went wrong.

Filling Go Structs in VS Code

If you program in Go, then you work with structs all the time. There’s a handy little tool in VS Code that you can use to quickly populate an empty struct with all its fields instead of writing them by hand. With your cursor over the name of the struct, bring up the context menu by doing one of the following:

  • Clicking on the light bulb to the left
  • Pressing Ctrl+. (Windows/Linux)
  • Pressing Cmd+. (Max)
This context menu lets you fill a struct’s fields.

Then, click on the “Fill” option or press ENTER to accept it, and the struct’s fields will be added along with default values for each according to their type:

The struct’s fields have been added with default values.

This little productivity tool is great, especially when you’re mapping data across structs in different parts of your application.

Working with Maps in Go

In Go, a map is a data structure allowing you to store pairs of keys and values, while using the key to look up more complex data.

A few examples of maps, and a comparison to arrays/slices.

In other languages, you’ll find similar data structures called dictionary, hashtable, hashmap or even object. the ability to associate keys and values and the ability to perform this lookup very quickly makes maps extremely useful for many different applications, such as those in the image above and the list below.

  • Storing/retrieving customer data based on a government-issued ID number.
  • Translating English text to Morse code
  • Actual dictionaries, mapping words to a description, or words in one language to the equivalent in another
  • A telephone directory, associating names with telephone numbers
  • Storing product prices based on their barcodes
  • Grouping properties for a specific object (this can also be done with structs in Go, but only when all the properties are well-defined in advance)

The careful reader will note that arrays and slices have a similar capability of associating an index (key) with a value. However, there are two important differences:

  • Arrays and slices can only take zero or positive integer keys. Maps can use a wider variety of data types as keys, with strings being a popular choice.
  • Map keys have no particular order. Although they can be integers (similar to arrays and slices), they can be negative or have gaps (such as the “square roots” example in the image above).

Initialising Maps

A map is a generic data type so you need to decide the data type of the keys and values. (Interestingly, although general-purpose support for generics was added to the language as recently as 2022, built-in data structures such as arrays, slices and maps have been generic all along.) For instance, you can declare a map of string to string this way:

domainToCountry := map[string]string{}

Alternatively, you can use the built-in make() function. There’s no real difference between the two approaches if you’re declaring an empty map.

domainToCountry := make(map[string]string)

The map data type takes the form map[key]value. So if you want to declare a map of string to float32 instead, you do:

nameToPrice := map[string]float32{}

(Note that the use of float32 to represent money values isn’t a great idea due to floating-point error. This is just an example.)

If you want to initialise a map with data from the get-go, you initialise it with the curly brackets and add literal data between them:

	domainToCountry := map[string]string{
		"es": "Spain",
		"it": "Italy",
	}

Note that the comma is required even after the last item.

Outputting a Map

If you want to display the contents of a map for debugging or other purposes, simply dropping it into a fmt.Println() does the trick. If you want to display it as part of a format string, use the %v placeholder for the map.

package main

import "fmt"

func main() {
	domainToCountry := map[string]string{
		"es": "Spain",
		"it": "Italy",
	}
	fmt.Println(domainToCountry)
	fmt.Printf("My map: %v", domainToCountry)
}
The output displaying the map using fmt.Println() and fmt.Printf() can be seen in the Debug Console near the bottom of the window.

Getting Data from a Map

Use indexing syntax to get a value from a map by its key:

	country1, exists1 := domainToCountry["es"]
	country2, exists2 := domainToCountry["cat"]

	fmt.Printf("es: %s, %t\n", country1, exists1) // outputs: "es: Spain, true"
	fmt.Printf("es: %s, %t\n", country2, exists2) // outputs: "es: , false"

Doing this returns 2 values: the corresponding value of the key, and whether the key exists in the map. It’s a safe operation, so if the key doesn’t exist, the value returned will be the default value of the type (e.g. 0 for ints, "" for strings, etc), and the second return value will come back as false.

The second return value is in fact optional; you can omit it entirely if you just want the value back. But, it’s useful to check whether the key exists in the map, as a default value can otherwise be confused with a legit value (e.g. 0 could mean that the key isn’t in the map, or it could really be a value in the map).

country1 := domainToCountry["es"]

The first return value is also optional, so if you only care to check whether the key exists in the map, you can replace it with an underscore:

_, exists1 := domainToCountry["es"]

The existence check can also be done inline within an if statement. This has the advantage of limiting the scope of the key/value variables to the scope of the if statement, limiting the potential for accidental and erroneous usage in longer functions:

	if country1, exists1 := domainToCountry["es"]; exists1 {
		fmt.Printf("The entry for %s exists. Let's do something with it!\n", country1)
	}

Inserting/Updating Data in a Map

After a map has been initialised, you can add key-value pairs to it using indexing syntax:

domainToCountry["be"] = "Belgium"

If the key wasn’t present in the map, it gets added. If it was, then the value gets overwritten.

	domainToCountry["be"] = "Belgium"
	domainToCountry["be"] = "Belgium2"
	fmt.Println(domainToCountry) // outputs "map[be:Belgium2 es:Spain it:Italy]"

Removing Data from a Map

Use the built-in delete() function to remove a key and its corresponding value from the map. This function is safe and will do nothing if the key is not in the map.

	delete(domainToCountry, "be") // removed
	delete(domainToCountry, "aaa") // wasn't there, so no-op

Length of a Map

Use the built-in len() function to check how many keys are present in the map.

	length := len(domainToCountry)
	fmt.Println(length) // outputs 2

Iterating over a Map

Use a for ... range loop to iterate over the keys and/or values of a map:

	for domain, country := range domainToCountry {
		fmt.Printf("Extension %s belongs to %s\n", domain, country)
	}

The output of the above snippet would be:

Extension es belongs to Spain
Extension it belongs to Italy

Both the key and value are optional. If you want just the key, simply omit the value:

	for domain := range domainToCountry {
		fmt.Println(domain)
	}

Whereas if you just want the value, replace the key with an underscore:

	for _, country := range domainToCountry {
		fmt.Println(country)
	}

You could also omit both, but that’s not usually very useful:

	for range domainToCountry {
		fmt.Println("I don't know why I'm iterating over a map if I don't use its data")
	}

It’s important to note that when iterating over a map, there’s no clearly-defined order as there is in arrays and slices. If you iterate over the same map multiple times, don’t expect to see the data come out in the same order each time.

Iterating over the same map multiple times produces differently ordered results.

Clearing a Map

To delete all items from a map, all you need to do is re-initialise it. The memory used by the old keys and values will be freed when the garbage collector kicks in.

package main

import "fmt"

func main() {
	domainToCountry := map[string]string{
		"es": "Spain",
		"it": "Italy",
	}

	domainToCountry = map[string]string{} // clear map

	fmt.Println(domainToCountry) // outputs "map[]"
}

A Map of Slices

Now that we’ve covered basic usage of maps, let’s consider a few more elaborate scenarios. For starters, how do we store multiple values for each key? For instance, we want to create a telephone directory (name to telephone number) and each person can have multiple numbers. For that, we can use a map of string to slice of string ([]string):

telephoneDirectory := map[string][]string{}

Note that, as I wrote in “From .NET to GoLang: Where Did Everything Go?“, the map syntax starts to be very confusing when you go beyond maps of simple types, due to overuse of square brackets. Note also that I’m opting to use strings to represent telephone numbers because the latter sometimes have length or characters that integer data types can’t handle.

When we add entries to our directory, we have to be careful to check whether a list of numbers already exists for that particular name. If it does, we add to it; otherwise we initialise a new one.

package main

import "fmt"

func addToDirectory(telephoneDirectory map[string][]string, name, telephoneNumber string) {
	if _, exists := telephoneDirectory[name]; !exists {
		telephoneDirectory[name] = []string{}
	}

	telephoneDirectory[name] = append(telephoneDirectory[name], telephoneNumber)
}

func main() {
	telephoneDirectory := map[string][]string{}

	addToDirectory(telephoneDirectory, "Bob", "12345678")
	addToDirectory(telephoneDirectory, "Bob", "87654321")
	addToDirectory(telephoneDirectory, "Charlie", "20202020")

	fmt.Println(telephoneDirectory) // outputs "map[Bob:[12345678 87654321] Charlie:[20202020]]"
}

This could have been written in a few different ways, but the one I chose in this example is to use the inline existence check to initialise an empty slice of strings for the name if it isn’t found in the directory. The subsequent addition of the number to the corresponding slice thus works the same way whether the name was previously in the directory or not.

A Map of Maps

Sometimes you need multiple dimensions in a map. I don’t have a really good example for this as it’s not a very common use case unless you’re grouping a lot of data for batch processing. So I’ll just show how it’s done:

package main

import "fmt"

func main() {
	myMap := map[string]map[string]int{} // map of string -> (map of string -> int)

	myMap["John"] = map[string]int{} // initialise inner map for key "John"
	myMap["John"]["age"] = 12
	myMap["John"]["height"] = 76

	fmt.Println(myMap) // outputs "map[John:map[age:12 height:76]]"
}

This is quite similar to what we saw in the previous section: the map syntax is rather confusing, and you have to make sure to initialise the inner map properly before using it. Otherwise it starts off as nil and if you try to use it, your program will panic.

Maps of Structs

Instead of maps of maps, it’s more common to have maps of structs. That allows us to look up data records based on some kind of identifier. For instance:

package main

import "fmt"

type Product struct {
	Name  string
	Price float32
}

func main() {

	products := map[string]Product{}

	products["pen"] = Product{
		Name:  "A fine blue pen",
		Price: 12.0,
	}

	fmt.Println(products) // outputs: "map[pen:{A fine blue pen 12}]"
}

However, as I showed in “From .NET to GoLang: Here We Go Again“, there’s a nasty surprise to be seen if you try to update a struct’s field when it’s in a map:

products["pen"].Price = 15.0
Attempting to update a property in a struct in a map causes a compiler error.

This is an unfortunate peculiarity in Go resulting from the concept of addressable values. In short, because values in a map are stored by value (rather than by reference), they can’t be manipulated directly. So there are 2 ways we can carry out this update.

The first is to replace the entire struct. So:

package main

import "fmt"

type Product struct {
	Name  string
	Price float32
}

func main() {

	products := map[string]Product{}

	products["pen"] = Product{
		Name:  "A fine blue pen",
		Price: 12.0,
	}

	products["pen"] = Product{
		Name:  products["pen"].Name,
		Price: 15.0,
	}

	fmt.Println(products) // outputs "map[pen:{A fine blue pen 15}]"
}

The second is to store pointers to products, instead of products by value.

package main

import "fmt"

type Product struct {
	Name  string
	Price float32
}

func main() {

	products := map[string]*Product{}

	products["pen"] = &Product{
		Name:  "A fine blue pen",
		Price: 12.0,
	}

	products["pen"].Price = 15.0

	fmt.Println(products) // outputs "map[pen:0xc000010030]"
}

Note however that this messes up the output when we print the map, because the map is no longer storing products directly. So the value that gets printed out is the address of the Product that the pointer is pointing to.

A Set Data Structure

Go doesn’t have a set data structure (you know, the mathematical kind in which values are unique and unordered). For simple use cases like eliminating duplicates, we can emulate the behaviour of a set using a map:

package main

import "fmt"

func main() {

	numbers := []int{1, 5, 8, 1, 3, 2, 4, 5}

	deduplicated := map[int]struct{}{}

	for _, number := range numbers {
		deduplicated[number] = struct{}{}
	}

	fmt.Println(deduplicated) // outputs "map[1:{} 2:{} 3:{} 4:{} 5:{} 8:{}]"
}

What we’re doing here is creating a map where we only care about the key (and not the value). The use of an empty struct{} is a tip I picked up on Stack Overflow because it doesn’t allocate any memory (as opposed to, for example, a bool). The syntax may appear a little confusing, but when you see two pairs of curly brackets next to each other, think of struct{} as the data type and the second {} as the initialisation syntax.

So then, all we do is feed each number from the slice into the map. As we’ve seen before, assigning another value to a key that already exists will simply overwrite it, leaving a single value for the key. That’s pretty much the same functionality we need for a set.

However, a set can do much more than just deduplicate items. If you need typical set operations such as intersection, union or difference, then check out my article “GoLang Set Data Structure” which shows how to use the third-party golang-set library which should have all the features you need.

Maps and Concurrency

The 2013 official blog post about maps states clearly that maps are not thread-safe, and suggests the use of locks to prevent data races arising from concurrent access to maps.

However, a concurrent version of the map data structure was released in 2017 with Go 1.9, i.e. sync.Map. While I haven’t had the chance to explore it in detail and it’s outside the scope of this article anyway, those looking for such a thing will be pleased to note that it exists and can do the necessary research to learn how to use it.

Summary and Further Reading

The map data structure will be familiar to anyone who has used something similar in other languages. It is easy enough to work with, but does have some quirks of its own that are unique to Go.

Read more about Go maps at the following locations:

GoLang: Using defer for Scope Bound Resource Management

Most programming languages today provide some way to bind the lifetime of a resource (for instance, a file handle) to a scope within a program, and implicitly clean it up when that scope ends. We can use destructors in C++, using blocks in C#, or with statements in Python. In Go, we use defer. As far as I can tell, this pattern originates in C++ and is called either Resource Acquisition Is Initialization (RAII), or Scope-Bound Resource Management (SBRM). It has various applications that range from resource deallocation (such as file handling, smart pointers, or locks) to scoped utility functions, as I’ve shown in my 2016 article, “Scope Bound Resource Management in C#“.

To understand what we’re talking about and why it’s useful, we first need to start with life without SBRM. Consider a simple program where we read the contents of a file:

package main

import (
	"fmt"
	"os"
	"time"
)

func main() {
	file, err := os.Open("example.txt") // open the file
	if err != nil {
		fmt.Println("Failed to open file!")
		return
	}

	data := make([]byte, 4)
	_, err = file.Read(data) // read 4 bytes from the file
	if err != nil {
		fmt.Println("Failed to read the file!")
		return
	}

	fmt.Println(string(data)) // print the data from the file

	file.Close() // close the file

	time.Sleep(time.Second) // pretend to do other work afterwards
}

Here, we’re opening a file, doing something with it, and then (like good citizens) closing it. We’re also doing something afterwards. However, this is in itself quite error-prone. Here are a few things that could happen which would jeopardise that Close() call:

  • We might forget to call Close() entirely.
  • An early return (e.g. due to an error) might skip the call to Close().
  • A more complex function with multiple branching might not reach Close() due to a mistake in the logic.

We can improve the situation by using defer. Putting the Close() call in a defer statement makes it run at the end of the function, whether there was an error or not. To illustrate, we’ll try to open a file that doesn’t exist, and use a Println() instead of the actual Close() to be able to see some output:

package main

import (
	"fmt"
	"os"
)

func main() {
	_, err := os.Open("nonexistent.txt") // open the file
	defer fmt.Println("Closing")
	if err != nil {
		fmt.Println("Failed to open file!")
		return
	}
}

Because the deferred statement runs at the end of the function in any case, we see “Closing” in the output:

Failed to open file!
Closing

defer is useful to ensure resources are cleaned up, but it’s not as good as SBRM constructs from other languages. One drawback is that there’s no actual requirement to use defer when allocating a resource, whereas something like C#’s using block ensures that anything allocated with it gets disposed at the end of its scope.

Another disadvantage is that it is function-scope only. Let’s imagine we have this program where we do a series of time-consuming tasks:

package main

import (
	"fmt"
	"time"
)

func main() {
	fmt.Println("Doing hard work...")

	time.Sleep(time.Second)

	fmt.Println("Doing harder work...")

	time.Sleep(2 * time.Second)

	fmt.Println("Doing even harder work...")

	time.Sleep(3 * time.Second)

	fmt.Println("Finished!")
}

We’d like to benchmark each step. In “Scope Bound Resource Management in C#“, I was able to wrap statements in a using block with a utility ScopedTimer that I created. Like C#, Go has blocks based on curly brackets, so let’s try and (ab)use them to measure the time taken by one of the tasks:

package main

import (
	"fmt"
	"time"
)

func main() {
	fmt.Println("Doing hard work...")

	{
		startTime := time.Now()
		defer fmt.Printf("Hard work took %s", time.Since(startTime))
		time.Sleep(time.Second)
	}

	fmt.Println("Doing harder work...")

	time.Sleep(2 * time.Second)

	fmt.Println("Doing even harder work...")

	time.Sleep(3 * time.Second)

	fmt.Println("Finished!")
}

The output is:

Doing hard work...
Doing harder work...
Doing even harder work...
Finished!
Hard work took 148ns

Two things went wrong here:

  • The benchmark measured 148 nanoseconds for a task that took one second! That’s because the time.Since(startTime) got evaluated right away rather than when defer started executing its statement.
  • The benchmark for the first task only got printed at the end of the entire function. That’s because defer runs at the end of the function, not at the end of the current scope.

We can fix the first problem by wrapping the deferred statement in an anonymous function that executes itself (which in the JavaScript world would be called an Immediately Invoked Function Expression or IIFE):

// ...

	{
		startTime := time.Now()
		defer func() {
			fmt.Printf("Hard work took %s", time.Since(startTime))
		}()
		time.Sleep(time.Second)
	}

// ...

We now get a benchmark of about 6 seconds, simply because defer is still running at the end of the function:

Doing hard work...
Doing harder work...
Doing even harder work...
Finished!
Hard work took 6.002184229s

To fix this benchmark, we have to fix the second problem, which is that defer runs at the end of the function. What we want is to use defer to measure the duration of each task inside the function. We have a number of ways to do this, but since defer is function scoped, they all involve the use of functions.

The first option is to break up main() into separate functions for each task:

package main

import (
	"fmt"
	"time"
)

func runTask1() {
	startTime := time.Now()
	defer func() {
		fmt.Printf("Hard work took %s\n", time.Since(startTime))
	}()
	time.Sleep(time.Second)
}

func runTask2() {
	startTime := time.Now()
	defer func() {
		fmt.Printf("Harder work took %s\n", time.Since(startTime))
	}()
	time.Sleep(2 * time.Second)
}

func runTask3() {
	startTime := time.Now()
	defer func() {
		fmt.Printf("Even harder work took %s\n", time.Since(startTime))
	}()
	time.Sleep(3 * time.Second)
}

func main() {
	fmt.Println("Doing hard work...")

	runTask1()

	fmt.Println("Doing harder work...")

	runTask2()

	fmt.Println("Doing even harder work...")

	runTask3()

	fmt.Println("Finished!")
}

This does produce correct results:

Doing hard work...
Hard work took 1.000149001s
Doing harder work...
Harder work took 2.001123261s
Doing even harder work...
Even harder work took 3.000039148s
Finished!

However:

  • It is quite verbose.
  • It duplicates all the benchmarking logic.
  • Although many people advocate for smaller functions, I find it easier to read longer functions if the operations are sequential and there’s no duplication, rather than hopping across several functions to understand the logic.

Another way we could do this is by retaining the original structure of main(), but using IIFEs instead of curly brackets to delineate the scope of each task:

package main

import (
	"fmt"
	"time"
)

func main() {
	fmt.Println("Doing hard work...")

	func() {
		startTime := time.Now()
		defer func() {
			fmt.Printf("Hard work took %s\n", time.Since(startTime))
		}()
		time.Sleep(time.Second)
	}()

	fmt.Println("Doing harder work...")

	func() {
		startTime := time.Now()
		defer func() {
			fmt.Printf("Harder work took %s\n", time.Since(startTime))
		}()
		time.Sleep(2 * time.Second)
	}()

	fmt.Println("Doing even harder work...")

	func() {
		startTime := time.Now()
		defer func() {
			fmt.Printf("Even harder work took %s\n", time.Since(startTime))
		}()
		time.Sleep(3 * time.Second)
	}()

	fmt.Println("Finished!")
}

It works just as well:

Doing hard work...
Hard work took 1.000069185s
Doing harder work...
Harder work took 2.001031904s
Doing even harder work...
Even harder work took 3.001086566s
Finished!

This approach is interesting because we actually managed to create scopes inside a function where defer could operate. All we did was put each task and its respective benchmarking logic inside an anonymous function and execute it right away. So the sequential code works just the same whether this anonymous function is there or not; it only makes a difference for defer.

Of course, we are still duplicating code in a very uncivilised way here, so we’ll move onto the third approach, which is simply to implement the benchmarking logic in a helper function and use it to execute the task itself:

package main

import (
	"fmt"
	"time"
)

func runBenchmarked(actionName string, doAction func()) {
	fmt.Printf("Doing %s...\n", actionName)
	startTime := time.Now()
	defer func() {
		fmt.Printf("%s took %s\n", actionName, time.Since(startTime))
	}()
	doAction()
}

func main() {
	runBenchmarked("hard work", func() {
		time.Sleep(time.Second)
	})

	runBenchmarked("harder work", func() {
		time.Sleep(2 * time.Second)
	})

	runBenchmarked("even harder work", func() {
		time.Sleep(3 * time.Second)
	})

	fmt.Println("Finished!")
}

The runBenchmarked() function takes care of everything about each task: it prints a message when it’s about to start, executes the task itself, and prints the time it took using the same defer statement we’ve been using for benchmarking. To do this, it takes the name of the task (as a string) as well as the task itself (as a callback function).

Then, in main(), all we need to do is call runBenchmarked() and pass the name of the task and the task itself. This results in the code being brief, free of duplication, and nicely scoped, which I believe is the closest we can get in Go to the SBRM constructs of other languages. The output shows that this works just as well:

Doing hard work...
hard work took 1.000901126s
Doing harder work...
harder work took 2.001077689s
Doing even harder work...
even harder work took 3.001477287s
Finished!

Conclusion

defer in Go provides some degree of SBRM support for scoped cleanup or utility purposes. However, it suffers from the following drawbacks:

  • It does not enforce implicit cleanup of allocated resources as similar constructs in other languages do.
  • Any parameters that need to be evaluated at the end of the scope should be wrapped in an IIFE.
  • It is function-scoped, therefore using defer for a limited/block scope inside a function requires it to be wrapped in another function.