runtime: pointer assignment in tight loop cause long STW

[zhouguangyuan0718]

What version of Go are you using (go version)?

$ go version
go version go1.20.2 linux/amd64

Does this issue reproduce with the latest release?

Yes

What operating system and processor architecture are you using (go env)?

go env Output

$ go env
GO111MODULE=""
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/zgy/.cache/go-build"
GOENV="/home/zgy/.config/go/env"
GOEXE=""
GOEXPERIMENT=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/zgy/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/zgy/go"
GOPRIVATE=""
GOPROXY="https://goproxy.cn,direct"
GOROOT="/home/zgy/00.Tools/stablego/go"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/home/zgy/00.Tools/stablego/go/pkg/tool/linux_amd64"
GOVCS=""
GOVERSION="go1.20.2"
GCCGO="gccgo"
GOAMD64="v1"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD="/dev/null"
GOWORK=""
CGO_CFLAGS="-O2 -g"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-O2 -g"
CGO_FFLAGS="-O2 -g"
CGO_LDFLAGS="-O2 -g"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -Wl,--no-gc-sections -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build2002358002=/tmp/go-build -gno-record-gcc-switches"

What did you do?

package main

import (
	"runtime"
	"time"
)

var a = [1000]*int{}

func Func1() {
	var b [1000]*int
	for a[0] == nil {
		a = b
	}
}

func main() {
	go Func1()
	ticker := time.NewTicker(time.Second)
	for range ticker.C {
		runtime.GC()
	}
}

Use go build to build this single file program.
And use export GODEBUG=gctrace=1 to enable gctrace.
Then just excute it.

What did you expect to see?

The STW time of GC should in normal range. Maybe microseconds to milliseconds.

What did you see instead?

./main 
gc 1 @1.001s 24%: 328+4201+1363 ms clock, 5259+0/0.13/0+21812 ms cpu, 0->0->0 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 16 P (forced)
gc 2 @6.894s 39%: 48+3432+3799 ms clock, 768+0/0.10/0+60788 ms cpu, 0->0->0 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 16 P (forced)
gc 3 @14.173s 41%: 389+838+673 ms clock, 6231+0/0.13/0+10774 ms cpu, 0->0->0 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 16 P (forced)
gc 4 @16.075s 49%: 2399+319+544 ms clock, 38386+0/0.12/0+8716 ms cpu, 0->0->0 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 16 P (forced)
gc 5 @19.339s 38%: 413+7188+725 ms clock, 6621+0/0.10/0+11607 ms cpu, 0->0->0 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 16 P (forced)
gc 6 @27.667s 40%: 15+145+1200 ms clock, 243+0/0.091/0+19212 ms cpu, 0->0->0 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 16 P (forced)
gc 7 @29.028s 45%: 1281+450+1298 ms clock, 20501+0/0.11/0+20773 ms cpu, 0->0->0 MB, 4 MB goal, 0 MB stacks, 0 MB globals, 16 P (forced)

Actually, The second STW during GC is about one second. I have even observed it will be several minutes.

It seems that this may be related to #36365 . There is a task "Make large pointer-full memmoves/memclrs preemptible" in it. But it seems that it is no more update about it.

[mknyszek]

I think this is unfortunately just the way things are right now, because runtime all code (including the memmoves) is non-async-preemptible. These memmoves also don't have preemption points themselves. Maybe we could have versions of these memmoves that do have preemption points? That would at least fix this "called in a loop" case, but it wouldn't help with singular long memmoves.

Resolving the relevant task from #36365 would indeed also fix this, and it would be a more general fix.