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

Jump to bottom

runtime: Running two go program with 1GB mem GC not releases free package variable mem #42780

Open
wasmup opened this issue Nov 23, 2020 · 1 comment
Open

runtime: Running two go program with 1GB mem GC not releases free package variable mem #42780

wasmup opened this issue Nov 23, 2020 · 1 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.
Milestone
Backlog

Comments

@wasmup
Copy link

wasmup commented Nov 23, 2020

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

$ go version
go version go1.15.5 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="auto"
GOARCH="amd64"
GOBIN="/home/user1/go/bin"
GOCACHE="/home/user1/.cache/go-build"
GOENV="/home/user1/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/user1/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/user1/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/usr/local/go"
GOSUMDB="sum.golang.org"
GOTMPDIR="/dev/shm"
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
AR="ar"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
GOMOD=""
CGO_CFLAGS="-g -O2"
CGO_CPPFLAGS=""
CGO_CXXFLAGS="-g -O2"
CGO_FFLAGS="-g -O2"
CGO_LDFLAGS="-g -O2"
PKG_CONFIG="pkg-config"
GOGCCFLAGS="-fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/dev/shm/go-build790679581=/tmp/go-build -gno-record-gcc-switches"

What did you do?

Run this code twice on a system with 8GB RAM:

package main

import (
	"fmt"
	"os"
	"runtime"
	"time"
)

func main() {
	for i := 0; i < 10; i++ {
		a = make([]byte, 1024*meg)
		var m runtime.MemStats
		runtime.ReadMemStats(&m)
		fmt.Printf("env: %v, sys: %4d MB, alloc: %4d MB, idel: %4d MB, released: %4d MB, inuse: %4d MB\n",
			os.Getenv("GODEBUG"), m.HeapSys/meg, m.HeapAlloc/meg, m.HeapIdle/meg, m.HeapReleased/meg, m.HeapInuse/meg)
		time.Sleep(1 * time.Second)
	}
}

var a []byte

const meg = 1024 * 1024

e.g.:

go build
./main
# on a second terminal again:
./main

What did you expect to see?

It should work without problem.

What did you see instead?

one program killed:

./hello 
env: , sys: 1087 MB, alloc: 1024 MB, idel:   63 MB, released:   63 MB, inuse: 1024 MB
env: , sys: 2111 MB, alloc: 2048 MB, idel:   63 MB, released:   63 MB, inuse: 2048 MB
env: , sys: 3135 MB, alloc: 3072 MB, idel:   63 MB, released:   63 MB, inuse: 3072 MB
env: , sys: 4159 MB, alloc: 4096 MB, idel:   63 MB, released:   63 MB, inuse: 4096 MB
env: , sys: 4159 MB, alloc: 3072 MB, idel: 1087 MB, released:   63 MB, inuse: 3072 MB
env: , sys: 4159 MB, alloc: 4096 MB, idel:   63 MB, released:   63 MB, inuse: 4096 MB
env: , sys: 4159 MB, alloc: 3072 MB, idel: 1087 MB, released:   63 MB, inuse: 3072 MB
Killed

second is ok:

./hello 
env: , sys: 1087 MB, alloc: 1024 MB, idel:   63 MB, released:   63 MB, inuse: 1024 MB
env: , sys: 2111 MB, alloc: 2048 MB, idel:   63 MB, released:   63 MB, inuse: 2048 MB
env: , sys: 3135 MB, alloc: 3072 MB, idel:   63 MB, released:   63 MB, inuse: 3072 MB
env: , sys: 4159 MB, alloc: 4096 MB, idel:   63 MB, released:   63 MB, inuse: 4096 MB
env: , sys: 4159 MB, alloc: 3072 MB, idel: 1087 MB, released:   63 MB, inuse: 3072 MB
env: , sys: 4159 MB, alloc: 4096 MB, idel:   63 MB, released:   63 MB, inuse: 4096 MB
env: , sys: 4159 MB, alloc: 3072 MB, idel: 1087 MB, released:   63 MB, inuse: 3072 MB
env: , sys: 4159 MB, alloc: 4096 MB, idel:   63 MB, released:   63 MB, inuse: 4096 MB
env: , sys: 4159 MB, alloc: 3072 MB, idel: 1087 MB, released:   63 MB, inuse: 3072 MB
env: , sys: 4159 MB, alloc: 4096 MB, idel:   63 MB, released:   63 MB, inuse: 4096 MB

Command:

vmstat 1 -S MB

Output:

procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 1  0   1066   6138     71    721    0    0   695   482  305  612  6  3 90  1  0
 1  0   1065   6104     71    721    0    0   160     0 1531 4596  7  2 91  0  0
 0  0   1065   6037     71    721    0    0   240     0 1557 4083  7  2 91  0  0
 0  0   1065   5970     71    721    0    0     4   192  937 2217  3  1 96  0  0
 0  0   1065   5905     71    721    0    0    24     0 1034 2301  4  1 95  0  0
 1  0   1065   4892     71    721    0    0     8     0  859 1899  3  3 94  0  0
 1  0   1065   3820     71    721    0    0    20     0 1049 2427  4  3 93  0  0
 0  0   1065   1768     71    721    0    0   680    56 2089 4458  5  7 88  0  0
 1  0   1065    709     71    721    0    0     4     8  874 1644  4  4 93  0  0
 1  6   1097    100      0    133    0   32 21856 35908 10957 8837  3 20 76  2  0
 2  9   1266    101      0    153    0  169 60980 173888 45459 48146  1 16 65 18  0
 0  6   1461    100      0    154    3  204 41340 209088 63567 58552  1 17 66 16  0
 1 19   1693     99      0    161    1  233 29264 239488 66461 67954  0 17 46 37  0
 1 16   1881    122      0    189    5  195 48992 200360 52910 61015  1 17  4 78  0
 4  1   2047    100      1    174   10  188 48572 192868 54604 61304  1 20 33 46  0
 2  1   1402   2837      0    180   25   19 141128 19628 16023 29175  4 21 69  6  0
 1  0   1382   2793      1    203   19    0 44548     0 6728 17851  6  3 87  4  0

Happens for this code too:

package main

import (
	"fmt"
	"time"
)

func main() {
	for i := 0; i < 10; i++ {
		a = make([]byte, 1024*meg)
		a[0] = 1
		fmt.Println(a[0], len(a))
		time.Sleep(1 * time.Second)
	}
}

var a []byte

const meg = 1024 * 1024

Run :

go build
./hello
./hello
vmstat 1 -S MB

one:

1 1073741824
1 1073741824
1 1073741824
1 1073741824
1 1073741824
1 1073741824
1 1073741824
1 1073741824
Killed
@wasmup wasmup changed the title Running two go program with 1GB mem GC not releases free mem and kills one program Running two go program with 1GB mem GC not releases free mem Nov 23, 2020
@toothrot toothrot changed the title Running two go program with 1GB mem GC not releases free mem runtime: Running two go program with 1GB mem GC not releases free mem Dec 8, 2020
@toothrot toothrot changed the title runtime: Running two go program with 1GB mem GC not releases free mem runtime: Running two go program with 1GB mem GC not releases free package variable mem Dec 8, 2020
@toothrot
Copy link
Contributor

toothrot commented Dec 8, 2020 •
edited

I am no GC expert, so I am cc'ing runtime owners here: @aclements @randall77 @mknyszek @prattmic

I believe the releasing is based on what objects are determined to be reachable. In this case, you're using a package variable, so it's handled differently than if a were declared inside of main. Declaring it in main behaves as you would expect, rather than growing the heap to ~3-4GB.

If your program weren't actively allocating close to its max heap, the unused memory would be released when another memory-hogging program started. See also #29844 (comment)

Adding similar code to your program:

func main() {
// ...
	for {
		rssAfter := getRss()
		fmt.Printf("RSS before: %d, after: %d, delta: %d\n", rssBefore, rssAfter, rssBefore-rssAfter)
		time.Sleep(3 * time.Second)
	}
}

func getRss() int {
	output, err := exec.Command("ps", "-p", strconv.Itoa(os.Getpid()), "-o", "rss=").Output()
	if err != nil {
		panic(err)
	}

	rss, err := strconv.Atoi(strings.TrimSpace(string(output)))
	if err != nil {
		panic(err)
	}

	return rss
}

The memory remains unreleased, until the other memory hogging programs are started, during which it gets released:

RSS before: 4924, after: 3355644, delta: -3350720
RSS before: 4924, after: 3355644, delta: -3350720
RSS before: 4924, after: 1363620, delta: -1358696

See #42430 as an aggregate of GC pacing issues.

@toothrot toothrot added this to the Backlog milestone Dec 8, 2020
@toothrot toothrot added the NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. label Dec 8, 2020
@gopherbot gopherbot added the compiler/runtime Issues related to the Go compiler and/or runtime. label Jul 7, 2022
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
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
Go Compiler / Runtime
Status: Triage Backlog
Milestone
Backlog
Development

No branches or pull requests
3 participants
@toothrot @gopherbot @wasmup