Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

runtime: pointer assignment in tight loop cause long STW #59902

Open
zhouguangyuan0718 opened this issue Apr 30, 2023 · 1 comment
Open

runtime: pointer assignment in tight loop cause long STW #59902

zhouguangyuan0718 opened this issue Apr 30, 2023 · 1 comment
Assignees
Labels
compiler/runtime Issues related to the Go compiler and/or runtime. NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Milestone

Comments

@zhouguangyuan0718
Copy link
Contributor

zhouguangyuan0718 commented Apr 30, 2023

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.

@gopherbot gopherbot added the compiler/runtime Issues related to the Go compiler and/or runtime. label Apr 30, 2023
@cagedmantis cagedmantis added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label May 1, 2023
@cagedmantis cagedmantis added this to the Backlog milestone May 1, 2023
@mknyszek
Copy link
Contributor

mknyszek commented May 3, 2023

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.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
compiler/runtime Issues related to the Go compiler and/or runtime. NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one.
Projects
Development

No branches or pull requests

4 participants