Finding Goroutine Leaks in Tests
Finding Goroutine Leaks in Tests
A leaked goroutine at the end of a test can indicate several problems. Let's first, take a look at the most common ones before tackling an approach to finding them.
Problem: Deadlock
First, we can have a goroutine that is blocked. As an example:
func LeakySumSquares(ctx context.Context, data []int) (
聽total int, err error) {
聽results := make(chan int)
聽for _, v := range data {
聽 聽v := v
聽 聽go func() {
聽 聽 聽result := v * v
聽 聽 聽results <- result
聽 聽}()
聽}
聽for {
聽 聽select {
聽 聽case value := <-results:
聽 聽 聽total += value
聽 聽case <-ctx.Done():
聽 聽 聽return ctx.Err()
聽 聽}
聽}
聽return total, nil
}
In this case, when the context is canceled, the goroutines might end up leaking.
Problem: Leaked Resource
Many times different services, connections, or databases have an internal goroutine used for async processing. A leaked goroutine can show such leaks.
type Conn struct {
聽messages chan Message
聽close context.CancelFunc
聽done 聽chan struct{}
}
func Dial(ctx context.Context) *Conn {
聽ctx, cancel := context.WithCancel(ctx)
聽conn := &Conn{
聽 聽close: 聽 聽cancel,
聽 聽messages: make(chan Message)
聽 聽done: 聽 聽 make(chan struct{}),
聽}
聽go conn.monitor(ctx)
聽return conn
}
func (conn *Conn) monitor(ctx context.Context) {
聽defer close(conn.done)
聽for {
聽 聽select {
聽 聽case msg := <-conn.messages:
聽 聽 聽conn.handle(msg)
聽 聽case <-ctx.Done():
聽 聽 聽return
聽 聽}
聽}
}
func (conn *Conn) Close() {
聽conn.close()
聽<-conn.done
}
Even if the main loop is properly handled, the conn.handle(msg) could become deadlocked in other ways.
Problem: Lazy Closing Order
Even if all the goroutines terminate, there can still be order problems with regard to resource usage. For example, you could end up depending on a database, connection, file, or any other resource, that gets closed before the goroutine finishes.
Let's take a common case of the problem:
type Server struct {
聽log Logger
聽db 聽*sql.DB
}
func NewServer(log Logger, dburi string) (*Server, error) {
聽db, err := sql.Open("postgres", dburi)
聽if err != nil {
聽 聽return nil, fmt.Errorf("opening database failed: %w", err)
聽}
聽return &Server{log: log, db: db}, nil
}
func (server *Server) ServeHTTP(w http.ResponseWriter, r *http.Request) {
聽tag := r.FormValue("tag")
聽if tag == "" {
聽 聽return
聽}
聽// update the database in the background
聽go func() {
聽 聽err := server.db.Exec("...", tag)
聽 聽if err != nil {
聽 聽 聽server.log.Errorf("failed to update tags: %w", err)
聽 聽}
聽}()
}
func (server *Server) Close() {
聽_ = server.db.Close()
}
In this case, when the Server is closed, there still could be goroutines updating the database in the background. Similarly, even the Logger could be closed before the goroutine finishes, causing some other problems.
The severity of such close ordering depends on the context. Sometimes it's a simple extra error in the log; in other cases, it can be a data-race or a panic taking the whole process down.
Rule of Thumb
Hopefully, it's clear that such goroutines can be problematic.
One of the best rules in terms of preventing these issues is:
The location that starts the goroutine must wait for the goroutine to complete even in the presence of context cancellation. Or, it must explicitly transfer that responsibility to some other service.
As long as you close the top-level service responsible for everything, it'll become visible in tests because if there's a leak, then the test cannot finish.
Unfortunately, this rule cannot be applied to third-party libraries and it's easy to forget to add tracking to a goroutine.
Finding Leaks
We could use the total number of goroutines, to find leaks at the end of a test, however that wouldn't work with parallel tests.
One helpful feature in Go is , which can make profiling and stack traces more readable. One interesting feature they have is that they are propagated automatically to child goroutines.
This means if we attach a unique label to a goroutine, we should be able to find all the child goroutines. However, code for finding such goroutines is not trivial.
To attach the label:
func Track(ctx context.Context, t *testing.T, fn func(context.Context)) {
聽label := t.Name()
聽pprof.Do(ctx, pprof.Labels("test", label), fn)
聽if err := CheckNoGoroutines("test", label); err != nil {
聽 聽t.Fatal("Leaked goroutines\n", err)
聽}
}
Unfortunately, currently, there's not an easy way to get the goroutines with a given label. But, we can use some of the profiling endpoints to extract the necessary information. Clearly, this is not very efficient.
import "github.com/google/pprof/profile"
func CheckNoGoroutines(key, value string) error {
聽var pb bytes.Buffer
聽profiler := pprof.Lookup("goroutine")
聽if profiler == nil {
聽 聽return fmt.Errorf("unable to find profile")
聽}
聽err := profiler.WriteTo(&pb, 0)
聽if err != nil {
聽 聽return fmt.Errorf("unable to read profile: %w", err)
聽}
聽p, err := profile.ParseData(pb.Bytes())
聽if err != nil {
聽 聽return fmt.Errorf("unable to parse profile: %w", err)
聽}
聽return summarizeGoroutines(p, key, value)
}
func summarizeGoroutines(p *profile.Profile, key, expectedValue string) (
聽err error) {
聽var b strings.Builder
聽for _, sample := range p.Sample {
聽 聽if !matchesLabel(sample, key, expectedValue) {
聽 聽 聽continue
聽 聽}
聽 聽fmt.Fprintf(&b, "count %d @", sample.Value[0])
聽 聽// format the stack trace for each goroutine
聽 聽for _, loc := range sample.Location {
聽 聽 聽for i, ln := range loc.Line {
聽 聽 聽 聽if i == 0 {
聽 聽 聽 聽 聽fmt.Fprintf(&b, "# 聽 %#8x", loc.Address)
聽 聽 聽 聽 聽if loc.IsFolded {
聽 聽 聽 聽 聽 聽fmt.Fprint(&b, " [F]")
聽 聽 聽 聽 聽}
聽 聽 聽 聽} else {
聽 聽 聽 聽 聽fmt.Fprint(&b, "# 聽 聽 聽 聽 聽 ")
聽 聽 聽 聽}
聽 聽 聽 聽if fn := ln.Function; fn != nil {
聽 聽 聽 聽 聽fmt.Fprintf(&b, " %-50s %s:%d", fn.Name, fn.Filename, ln.Line)
聽 聽 聽 聽} else {
聽 聽 聽 聽 聽fmt.Fprintf(&b, " ???")
聽 聽 聽 聽}
聽 聽 聽 聽fmt.Fprintf(&b, "\n")
聽 聽 聽}
聽 聽}
聽 聽fmt.Fprintf(&b, "\n")
聽}
聽if b.Len() == 0 {
聽 聽return nil
聽}
聽return errors.New(b.String())
}
func matchesLabel(sample *profile.Sample, key, expectedValue string) bool {
聽values, hasLabel := sample.Label[key]
聽if !hasLabel {
聽 聽return false
聽}
聽for _, value := range values {
聽 聽if value == expectedValue {
聽 聽 聽return true
聽 聽}
聽}
聽return false
}
And a failing test might look like this:
func TestLeaking(t *testing.T) {
聽t.Parallel()
聽ctx, cancel := context.WithCancel(context.Background())
聽defer cancel()
聽Track(ctx, t, func(ctx context.Context) {
聽 聽LeakyThing(ctx)
聽})
}
func LeakyThing(ctx context.Context) {
聽done := make(chan struct{})
聽go func() {
聽 聽go func() {
聽 聽 聽done <- struct{}{}
聽 聽}()
聽 聽done <- struct{}{}
聽}()
}
The full example can be found here .
Depending on your use case, you may want to adjust to your needs. For example, you may want to skip some goroutines or maybe print some extra information, or have a grace period for transient goroutines to shut down.
Such an approach can be hooked into your tests or existing system in a multitude of ways.