Skip to content

synctest.Wait instead of a sleep

Level: 201 · anyone who has put time.Sleep in a test to let a goroutine catch up

One line: synctest.Wait returns when every other goroutine in the bubble is durably blocked, so a check made after it sees what those goroutines did — the same on every run, with no sleep — and the race detector counts it as synchronization; leave it out and go test -race fails the test.

The question

A worker handles orders until its context is cancelled:

// worker handles orders until ctx is cancelled.
func worker(ctx context.Context, orders <-chan int) {
    for {
        select {
        case <-orders:
        case <-ctx.Done():
            return
        }
    }
}

A test wants to check two things: the worker is still running after it has taken an order, and it has stopped after cancel(). Neither is settled at the moment the test's goroutine reaches its next line. cancel() closes the context's Done channel and returns; the worker notices when it next runs, and nothing in the program says whether that happens before the test looks. A short time.Sleep before the check is a guess about the scheduler.

Inside a bubble (the previous lesson), synctest.Wait ↗ replaces the guess. It blocks until every goroutine in the bubble other than the caller is durably blocked — waiting on something only another goroutine in the same bubble can provide — or has ended. The script writes a test that calls it twice, and a second test that checks right after cancel() with no Wait, and runs them with and without the race detector:

Verified output of synctest_wait_sh.sh — regenerated by tools/run_examples.py, never hand-typed.

$ go mod init example
$ go test -v -count=1 -run 'TestWorkerStops$'
=== RUN   TestWorkerStops
    worker_test.go:32: after an order: stopped = false
    worker_test.go:39: after cancel:   stopped = true
--- PASS: TestWorkerStops
PASS
ok      example
exit status 0
$ go test -race -count=1 -run 'TestWorkerStops$'
PASS
ok      example
exit status 0
$ go test -race -count=1 -run TestWorkerStopsWithoutWait
race report: yes
--- FAIL: TestWorkerStopsWithoutWait
    testing.go: race detected during execution of test
FAIL
FAIL    example
exit status 1

Reading the output

after an order: stopped = false. The send on orders completed when the worker received. Wait then returned once the worker was back in its select, blocked on two channels of the bubble, so the test read stopped while the worker was known to be waiting — not in the middle of anything.

after cancel: stopped = true. cancel() closed Done. Wait returned only after the worker had seen it and returned, and the goroutine around it had set stopped and ended.

With -race, ok example. The race detector treats the read of stopped after Wait as ordered after the goroutine's write. The Go blog's synctest announcement ↗ says so directly — "The race detector understands Wait calls" — and this run shows it: no report, exit status 0.

Without the Wait: race report: yes, then --- FAIL. This version reads stopped right after cancel(). The worker's write and the test's read now have nothing between them that puts one first, which is a data race as the Go memory model ↗ defines it, and the testing package fails a test during which the race detector reported one: race detected during execution of test, exit status 1. The script leaves out one line of that run — the test's own the worker has not stopped yet. Whether it appears depends on whether the scheduler ran the worker between cancel() and the check, and nothing in the program decides that.

synctest_wait_sh.sh

synctest_wait_sh.sh in full — pasted here by tools/run_examples.py from the file CI runs.

#!/usr/bin/env bash
# synctest.Wait blocks until every other goroutine in the bubble is durably
# blocked, so a test can ask "has the worker reacted yet?" and get the same
# answer on every run, with no sleep. The same test without the Wait is a data
# race, and go test -race fails it. Whether that version's own check fires
# depends on the scheduler, so this script does not print that line, and it
# drops the durations go test prints.
set -u

dir=$(mktemp -d)
trap 'rm -rf "$dir"' EXIT
cd "$dir" || exit 1
export GOTOOLCHAIN=local

cat >worker_test.go <<'GO'
package example

import (
    "context"
    "testing"
    "testing/synctest"
)

// worker handles orders until ctx is cancelled.
func worker(ctx context.Context, orders <-chan int) {
    for {
        select {
        case <-orders:
        case <-ctx.Done():
            return
        }
    }
}

func TestWorkerStops(t *testing.T) {
    synctest.Test(t, func(t *testing.T) {
        ctx, cancel := context.WithCancel(t.Context())
        orders := make(chan int)
        stopped := false
        go func() {
            worker(ctx, orders)
            stopped = true
        }()

        orders <- 1042
        synctest.Wait() // returns once the worker is blocked in its select again
        t.Log("after an order: stopped =", stopped)
        if stopped {
            t.Fatal("the worker stopped before it was cancelled")
        }

        cancel()
        synctest.Wait() // returns once the worker's goroutine has ended
        t.Log("after cancel:   stopped =", stopped)
        if !stopped {
            t.Fatal("cancel did not stop the worker")
        }
    })
}

func TestWorkerStopsWithoutWait(t *testing.T) {
    synctest.Test(t, func(t *testing.T) {
        ctx, cancel := context.WithCancel(t.Context())
        orders := make(chan int)
        stopped := false
        go func() {
            worker(ctx, orders)
            stopped = true
        }()

        orders <- 1042
        cancel()
        if !stopped { // races with the write above: nothing says which runs first
            t.Error("the worker has not stopped yet")
        }
    })
}
GO

say() { printf '$ %s\n' "$*"; }

# Print go test's output without what varies: "(0.00s)" after a test's name,
# the time after "ok  example" or "FAIL  example", and testing.go's line number.
tidy() {
    sed -E 's/ \([0-9.]+s\)$//; s/^(ok|FAIL)([[:space:]]+example)[[:space:]]+[0-9.]+s$/\1\2/; s/testing\.go:[0-9]+:/testing.go:/' test.txt
}

say 'go mod init example'
go mod init example 2>/dev/null || exit 1

# -race needs cgo, and on Linux a C compiler. Stop, rather than print a key
# in which go test failed to build.
if [ "$(go env CGO_ENABLED)" != 1 ]; then
    echo 'go test -race needs cgo (and on Linux a C compiler); CGO_ENABLED is not 1' >&2
    exit 1
fi

say "go test -v -count=1 -run 'TestWorkerStops\$'"
go test -v -count=1 -run 'TestWorkerStops$' >test.txt 2>&1
status=$?
tidy
echo "exit status $status"

say "go test -race -count=1 -run 'TestWorkerStops\$'"
go test -race -count=1 -run 'TestWorkerStops$' >test.txt 2>&1
status=$?
tidy
echo "exit status $status"

say 'go test -race -count=1 -run TestWorkerStopsWithoutWait'
go test -race -count=1 -run TestWorkerStopsWithoutWait >test.txt 2>&1
status=$?
if grep -q '^WARNING: DATA RACE$' test.txt; then
    echo 'race report: yes'
else
    echo 'race report: no'
fi
tidy | grep -E '^(--- |ok|FAIL|PASS)|race detected'
echo "exit status $status"

What Wait waits for

Wait finishes on the same condition that moves the fake clock: every other goroutine in the bubble durably blocked. A goroutine waiting to lock a sync.Mutex, reading from a network connection, or inside a system call is blocked, but not durably, because something outside the bubble could end the wait — so Wait keeps waiting for it. The package documentation ↗ adds two rules: Wait must be called from inside a bubble, and not by two goroutines of the same bubble at once.

Wait and the fake clock work together. The documentation's context.WithTimeout example sleeps until one nanosecond before the deadline, calls Wait, and checks that the context is not yet done; then it sleeps the last nanosecond, calls Wait again, and checks that it is. The sleep moves the clock; the Wait lets the goroutines that the clock woke finish reacting before the check.

What to do

  • Replace the sleep before a check with synctest.Wait, inside synctest.Test.
  • Put a Wait between every action that starts work in another goroutine and the check that looks for its effect — a send, a cancel(), a time.Sleep that fires a timer. What cancellation does outside a test is Cancel reaches every goroutine.
  • Run these tests with -race. A missing Wait shows up as a race report and a failed test, as in the last block above. The race detector shows what the report contains.
  • Keep what the goroutines wait on inside the bubble — channels created there, not a lock held from outside or a socket — or Wait waits for those goroutines too.

In other languages

  • Concurrency library — chapter 09, Testing and tools (ThreadSanitizer, Go's race detector, stress tests, deterministic schedulers), is planned; no page there asks this question yet.
  • Rust — the standard library has nothing that waits until every other thread is blocked. (Not machine-checked here.) A Rust test that needs another thread to have acted waits on something that thread does — a join, a receive on a channel — so the wait is written into the code under test, where synctest.Wait asks the Go runtime instead. The mistake in this page's second test — a variable written by one thread and read by another with nothing in between — is the kind safe Rust refuses to compile; the Rust library's Data races ↗ shows that refusal for a shared counter.

Sources