CC @mknyszek @aclements

That 10 GiB ballast is freed (notice that inuse is 0) because the compiler determines the ballast value is no longer live before the sleep. The scavenger is trying to reclaim the space, so that object is not actually a ballast because it gets garbage collected. This is all WAI.

It takes a while to return 10 GiB of memory back to the OS (pacing is 1 page per ms, in this case 4 KiB per ms => ~43 minutes) if the system doesn't support transparent huge pages, which darwin does not. I'm not sure why you're seeing 30% CPU utilization specifically, but when running any non-trivial application we haven't seen additional costs associated with the scavenger on that order of magnitude (in fact, it's paced to try to use about 1% of 1 CPU, which is consistent with performance regressions I've encountered). I suspect the increased CPU utilization is actually coming from the fact that scavenging prints very often in gctrace which is a known issue we need to fix (#32952).

If you modify the program to instead be:

package main

import "time"

var ballast []byte

func main() {
	ballast = make([]byte, 10<<30)
	time.Sleep(time.Hour)
}

you'll notice that with GODEBUG=gctrace=1 that the scavenger is no longer doing any work, since the ballast never dies. Alternatively, you could add a runtime.KeepAlive after the time.Sleep to achieve a similar effect.

@mknyszek ok thanks

As a side note I have to mention that running without GODEBUG=gctrace=1 consumes similar amount of cpu

@pmalekn Interesting. I notice that you're running this inside docker (and maybe a linux image?)? It may be that docker's indirection makes the syscalls to return memory to the OS much more expensive, since running a linux image in docker on darwin spins up a VM.

If I run it directly on darwin, I instead see utilization on the order of 6-7%. Still higher than expected but not as bad as 30%.

@pmalekn I forgot to finish my last comment.

On a separate note, in Go 1.14, the scavenger is now paced according to how long each scavenging operation actually took, so it's more likely to be close to 1%. Trying this out with Go 1.14 and the scavenger actually... halts. Sigh. This is related to #35788. But anyway the high utilization you're seeing is gone.

@mknyszek I can confirm that running on MacOS it seems to be fixed.

Without GODEBUG=gctrace=1.

USER               PID  %CPU %MEM      VSZ    RSS   TT  STAT STARTED      TIME COMMAND
pmalek           12496   5.8  2.0 15198892 340336 s007  S+    8:38PM   0:03.51 ./go1.13.5
pmalek           12529   0.0  2.0 15799180 340932 s006  S+    8:38PM   0:00.20 ./go1.14beta1
pmalek           12463   0.0  2.0 15197640 340324 s002  S+    8:38PM   0:00.15 ./go1.12.14

and with GODEBUG=gctrace=1

USER               PID  %CPU %MEM      VSZ    RSS   TT  STAT STARTED      TIME COMMAND
pmalek           12960   8.5  2.0 15199660 340348 s007  R+    8:41PM   0:01.34 ./go1.13.5
pmalek           12976   0.0  2.0 15799436 340856 s006  S+    8:41PM   0:00.20 ./go1.14beta1
pmalek           12944   0.0  2.0 15196616 340324 s002  S+    8:41PM   0:00.14 ./go1.12.14

Same inside the container:

CONTAINER ID        NAME                CPU %               MEM USAGE / LIMIT     MEM %               NET I/O             BLOCK I/O           PIDS
04645753d3a0        go1.12.14           0.00%               332.1MiB / 7.294GiB   4.45%               898B / 0B           0B / 0B             5
34a8ec402dd9        go1.13.5            30.47%              332.2MiB / 7.294GiB   4.45%               718B / 0B           0B / 0B             6
54ecde1bf6bd        go1.14beta1         0.00%               332.5MiB / 7.294GiB   4.45%               648B / 0B           0B / 0B             5

and inside the container with GODEBUG=gctrace=1

CONTAINER ID        NAME                CPU %               MEM USAGE / LIMIT     MEM %               NET I/O             BLOCK I/O           PIDS
8f9184764bf7        go1.13.5            27.75%              332.1MiB / 7.294GiB   4.45%               828B / 0B           0B / 0B             6
9ee0b6809517        go1.12.14           0.00%               332.1MiB / 7.294GiB   4.45%               738B / 0B           0B / 0B             5
e5eaa5bb2d88        go1.14beta1         0.00%               332.5MiB / 7.294GiB   4.45%               578B / 0B           0B / 0B             5