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: imperfection in gc trace lines #54649

Closed
go101 opened this issue Aug 24, 2022 · 3 comments
Closed

runtime: imperfection in gc trace lines #54649

go101 opened this issue Aug 24, 2022 · 3 comments
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

@go101
Copy link

go101 commented Aug 24, 2022

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

$ go version
go version go1.19 linux/amd64

Does this issue reproduce with the latest release?

Yes

What did you do?

package main

import (
	"math/rand"
	"time"
)

var x [512][]*int

func garbageProducer() {
	rand.Seed(time.Now().UnixNano())

	for i := 0; ; i++ {
		n := 6 + rand.Intn(6)
		for j := range x {
			x[j] = make([]*int, 1<<n)
			for k := range x[j] {
				x[j][k] = new(int)
			}
		}
		time.Sleep(time.Second / 1000)
	}
}

func bigStack(c chan int, v byte) byte {
	defer func() {
		c <- 1
	}()
	var s = []byte{33 << 20: 0} // on stack
	for i := range s { s[i] = v }
		
	return s[v]
}

func main() {
	go bigStack(nil, 123)
	go bigStack(nil, 123)
	garbageProducer()
}

It looks, unlike Go 1.18, Go 1.19 uses the real stack sizes in calculating target memory.
But the # MB stacks items in the gc trace lines still show the 2n stack memory block sizes.

BTW, in the runtime docs, https://pkg.go.dev/runtime, # MB stacks and # MB globals are listed but not shown in the format line.

What did you expect to see?

$ GODEBUG=gctrace=1  ./main
gc 1 @0.016s 19%: 0.053+36+0.016 ms clock, 0.21+36/4.9/39+0.066 ms cpu, 3->3->3 MB, 4 MB goal, 66 MB stacks, 0 MB globals, 4 P
gc 2 @0.184s 7%: 0.019+24+0.013 ms clock, 0.076+0.083/24/0.063+0.052 ms cpu, 70->74->16 MB, 73 MB goal, 66 MB stacks, 0 MB globals, 4 P
gc 3 @0.442s 4%: 0.036+9.3+0.029 ms clock, 0.14+0.17/9.1/6.2+0.11 ms cpu, 94->95->5 MB, 98 MB goal, 66 MB stacks, 0 MB globals, 4 P
gc 4 @0.678s 3%: 0.069+27+0.033 ms clock, 0.27+0.74/26/37+0.13 ms cpu, 56->57->12 MB, 77 MB goal, 66 MB stacks, 0 MB globals, 4 P
gc 5 @1.057s 3%: 0.061+54+0.053 ms clock, 0.24+0.17/54/4.0+0.21 ms cpu, 86->92->16 MB, 92 MB goal, 66 MB stacks, 0 MB globals, 4 P
...

What did you see instead?

$ GODEBUG=gctrace=1  ./main
gc 2 @0.184s 7%: 0.019+24+0.013 ms clock, 0.076+0.083/24/0.063+0.052 ms cpu, 70->74->16 MB, 73 MB goal, 128 MB stacks, 0 MB globals, 4 P
gc 3 @0.442s 4%: 0.036+9.3+0.029 ms clock, 0.14+0.17/9.1/6.2+0.11 ms cpu, 94->95->5 MB, 98 MB goal, 128 MB stacks, 0 MB globals, 4 P
gc 4 @0.678s 3%: 0.069+27+0.033 ms clock, 0.27+0.74/26/37+0.13 ms cpu, 56->57->12 MB, 77 MB goal, 128 MB stacks, 0 MB globals, 4 P
gc 5 @1.057s 3%: 0.061+54+0.053 ms clock, 0.24+0.17/54/4.0+0.21 ms cpu, 86->92->16 MB, 92 MB goal, 128 MB stacks, 0 MB globals, 4 P
...
@gopherbot gopherbot added the compiler/runtime Issues related to the Go compiler and/or runtime. label Aug 24, 2022
@dr2chase
Copy link
Contributor

dr2chase commented Aug 24, 2022

@mknyszek ptal?

@dr2chase dr2chase added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Aug 24, 2022
@mknyszek mknyszek self-assigned this Aug 24, 2022
@mknyszek mknyszek added this to the Go1.20 milestone Aug 24, 2022
@gopherbot
Copy link

gopherbot commented Aug 24, 2022

Change https://go.dev/cl/425366 mentions this issue: runtime: update gctrace docs and print lastStackScan instead of max

@mknyszek
Copy link
Contributor

mknyszek commented Aug 24, 2022

Thanks, sent a fix.

rajbarik pushed a commit to rajbarik/go that referenced this issue Sep 1, 2022
This change updates the gctrace docs to include stacks and globals in
the format line, and prints lastStackScan for "# MB stacks" instead of
maxStackScan, which is more accurate.

Fixes golang#54649.

Change-Id: Ibff2c390c9c9bf2b24b5b4e98ca346cc98d7cb2e
Reviewed-on: https://go-review.googlesource.com/c/go/+/425366
Run-TryBot: Michael Knyszek <mknyszek@google.com>
Auto-Submit: Michael Knyszek <mknyszek@google.com>
TryBot-Result: Gopher Robot <gobot@golang.org>
Reviewed-by: Michael Pratt <mpratt@google.com>
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
Status: Done
Development

No branches or pull requests

4 participants