runtime: Channel benchmark causes extremely high idle wake ups on macOS Sequoia

[chrisprobst]

Go version

go version go1.24.1 darwin/arm64

Output of go env in your module/workspace:

AR='ar'
CC='cc'
CGO_CFLAGS='-O2 -g'
CGO_CPPFLAGS=''
CGO_CXXFLAGS='-O2 -g'
CGO_ENABLED='1'
CGO_FFLAGS='-O2 -g'
CGO_LDFLAGS='-O2 -g'
CXX='c++'
GCCGO='gccgo'
GO111MODULE=''
GOARCH='arm64'
GOARM64='v8.0'
GOAUTH='netrc'
GOBIN=''
GOCACHE='/Users/chrisprobst/Library/Caches/go-build'
GOCACHEPROG=''
GODEBUG=''
GOENV='/Users/chrisprobst/Library/Application Support/go/env'
GOEXE=''
GOEXPERIMENT=''
GOFIPS140='off'
GOFLAGS=''
GOGCCFLAGS='-fPIC -arch arm64 -pthread -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -ffile-prefix-map=/var/folders/fd/pttbx7q55wv1r5x5qtw7h2gc0000gn/T/go-build2030550518=/tmp/go-build -gno-record-gcc-switches -fno-common'
GOHOSTARCH='arm64'
GOHOSTOS='darwin'
GOINSECURE=''
GOMOD='/Users/chrisprobst/repos/goperfchan/go.mod'
GOMODCACHE='/Users/chrisprobst/go/pkg/mod'
GONOPROXY='buf.build/gen/go'
GONOSUMDB='buf.build/gen/go'
GOOS='darwin'
GOPATH='/Users/chrisprobst/go'
GOPRIVATE='buf.build/gen/go'
GOPROXY='https://proxy.golang.org,direct'
GOROOT='/opt/homebrew/Cellar/go/1.24.1/libexec'
GOSUMDB='sum.golang.org'
GOTELEMETRY='local'
GOTELEMETRYDIR='/Users/chrisprobst/Library/Application Support/go/telemetry'
GOTMPDIR=''
GOTOOLCHAIN='auto'
GOTOOLDIR='/opt/homebrew/Cellar/go/1.24.1/libexec/pkg/tool/darwin_arm64'
GOVCS=''
GOVERSION='go1.24.1'
GOWORK=''
PKG_CONFIG='pkg-config'

What did you do?

Running the following program on a recent macOS version with M3/M4 (Pro/Max):

package main

import (
	"log"
)

func main() {
	N := 10_000_000
	chans := make([]chan int, N)
	log.Print("Creating channels")
	for i := range chans {
		chans[i] = make(chan int)
	}
	log.Print("Created channels")

	log.Print("Creating tasks")
	for i := range chans[:len(chans)-1] {
		a, b := chans[i+1], chans[i]
		go func() {
			for {
				a <- <-b + 1
			}
		}()
	}
	log.Print("Created tasks")

	for {
		log.Print("Sending first item")
		chans[0] <- 0
		log.Print("Reading last item: ", <-chans[len(chans)-1])
	}
}

What did you see happen?

The program itself behaves as expected. However, the macOS system monitor shows very high idle wake ups, like extremely high:

It's German language but the column "Reaktivierungen" is referring to the idle wake up count.

Dothing a similar program in Rust using tokio and async_channel behaves similar in runtime performance (a bit faster of course) but does not show similar idle wake ups.

This problem ALSO happens with a simple HTTP server and wrk as a load generator. The issue is described at the end of this issue: #49679

This points to a more general Go scheduler issue on macOS because it happens even without network.

What did you expect to see?

I would expect the idle wake up count to be low as there should not be a reason for wake ups.

[prattmic]

My initial assumption would be each channel send doing a wakep to wake a thread. But with 10M goroutines, we should really have all threads awake and wakep should do nothing.

Needs investigation.

[gabyhelp]

Related Issues

• runtime: time.Sleep() wakes up too early #48214 (closed)
• runtime: sysmon looping when idle #6673 (closed)
• cmd/trace: give more context to "Scheduler wait" table column on /goroutine page #63430
• runtime/pprof: GOOS=darwin over-reports CPU usage in mutex-heavy workload #68477
• runtime: scheduler sometimes starves a runnable goroutine on wasm platforms #65178 (closed)

Related Discussions

• High Idle wakeups
• Strange behaviour of Goroutine with time.Sleep on macOS 10.12

_{(Emoji vote if this was helpful or unhelpful; more detailed feedback welcome in this discussion.)}

[prattmic]

For reference of anyone looking into this, see my notes at #49679 (comment). powermetrics can report wake ups on the CLI.

[rhysh]

But with 10M goroutines, we should really have all threads awake and wakep should do nothing.

Those 10M goroutines are each blocked on their own channel. They wake up one at a time when they receive the single int value, increment it, and pass it along to the next goroutine in the chain.

I'd expect the following dynamic to often take place: Goroutine N-1 has marked goroutine N as runnable, attempts to receive from its inbound channel, and blocks. The P begins running goroutine N. Goroutine N sends on its outbound channel, leading to a goready call for goroutine N+1, leading to a ready call with next=true, leading to a runqput call with next=true plus a wakep. Now goroutine N+1 is in the runnext field of the current P. Within wakep, we see that there's a need for a "spinning" M. We obtain an idle P and pass it to startm with spinning=true. That M+P wakes up and looks for work. It doesn't find any in the first few places it looks, and ends up in runqgrab, in the portion that attempts to take other Ps' runnext work (after a usleep call to see whether the other P picks up the job itself).

I'm not surprised that such small grains of work, plus underutilization relative to GOMAXPROCS, lead to a large number of wakeups.