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 should reclaim off-heap memory #43402

Closed
zhuangel opened this issue Dec 28, 2020 · 2 comments
Closed

Runtime should reclaim off-heap memory #43402

zhuangel opened this issue Dec 28, 2020 · 2 comments
Labels
FrozenDueToAge

Comments

@zhuangel
Copy link

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

$ go version
go version go1.15.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/chenglang.hy/.cache/go-build"
GOENV="/home/chenglang.hy/.config/go/env"
GOEXE=""
GOFLAGS=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOINSECURE=""
GOMODCACHE="/home/chenglang.hy/go/pkg/mod"
GONOPROXY=""
GONOSUMDB=""
GOOS="linux"
GOPATH="/home/chenglang.hy/go"
GOPRIVATE=""
GOPROXY="https://proxy.golang.org,direct"
GOROOT="/opt/go1.15.2"
GOSUMDB="sum.golang.org"
GOTMPDIR=""
GOTOOLDIR="/opt/go1.15.2/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=/tmp/go-build028285215=/tmp/go-build -gno-record-gcc-switches"

What did you do?

The off heap memory will not reclaimed, even the program has free all used memory.
This is a simplify test case, the test case run as following steps

1 allocate lots memory, such as 4GB
check the runtime memory stats , the memory is used as expectd.
check /proc//numa_maps, the memory is used as expectd.

2 release all allocated memory
check the runtime memory stats, the heap memory has returned to OS.
check /proc//numa_maps, off-heap memory (anon-rss expect c000000000 vma) still consume lots memory, even I tried with runtime.GC, debug.FreeOSMemory, and sleep long time.

Test case source
package main

import (

"fmt"

"log"

"os/exec"

"runtime"

"runtime/debug"

"strconv"

"syscall"

"time"

"unsafe"

)


const (

// PageSize is the system page size.

PageSize = 1 << PageShift


// PageShift is the binary log of the system page size.
PageShift = 12

entriesPerPage = 512



)


type PTE uintptr

type PTEs [entriesPerPage]PTE

var used map[*PTEs]struct{}


// newAlignedPTEs returns a set of aligned PTEs.

func newAlignedPTEs() *PTEs {

temp := make([]byte, PageSize)

for idx:=0; idx < PageSize; idx++ {

temp[idx] = 'D'

}

return (*PTEs)(unsafe.Pointer(&temp[0]))

}


// Alloc 4GB memory.

func AllocStress() {

for idx:=0; idx < 1024*1024; idx++ {

ptes := newAlignedPTEs()

used[ptes] = struct{}{}

}

}


// Free all test memory.

func AllocCleanUp() {

for ptes, _ := range used {

delete(used, ptes)

}

used = nil

}


// Got runtime memory stats.

func GetMemStat(){

for idx:=0; idx < 3; idx++ {

var st runtime.MemStats

runtime.GC()

debug.FreeOSMemory()

runtime.ReadMemStats(&st)

fmt.Printf("        Runtime stats: HeapAlloc %v HeapInuse %v HeapIdle %v HeapReleased %v\n",

st.HeapAlloc, st.HeapInuse, st.HeapIdle, st.HeapReleased)

time.Sleep(time.Second)

}

}


// Got numa_maps under proc.

func GetProcStat(pid int, dump bool) {

file := "/proc/"+strconv.FormatInt(int64(pid), 10)+"/numa_maps"

heapcmd := "grep anon "+file+" | grep -v file | grep 'c......000' | awk '{print $3}' | awk -F= '{print $2}' | tr -d '\n'"

totalcmd := "grep anon "+file+" | grep -v file | awk '{print $3}' | awk -F= '{sum += $2}; END {print sum}' | tr -d '\n'"

offheapcmd := "grep anon "+file+" | grep -v file | grep -v 'c......000' | awk '{print $3}' | awk -F= '{sum += $2}; END {print sum}' | tr -d '\n'"

heap, err := exec.Command("sh", "-c", heapcmd).Output()

if err != nil {

log.Fatal(err)

}

total, err := exec.Command("sh", "-c", totalcmd).Output()

if err != nil {

log.Fatal(err)

}

offheap, err := exec.Command("sh", "-c", offheapcmd).Output()

if err != nil {

log.Fatal(err)

}

fmt.Printf("        The numa_maps is heap-rss: %s off-heap-rss %s total-rss %s\n", heap, offheap, total)

if dump {

dumpcmd := "cat "+file

filedump, err := exec.Command("sh", "-c", dumpcmd).Output()

if err != nil {

log.Fatal(err)

}

fmt.Printf("        The %s numa_maps:\n %s", file, filedump)


	file = "/proc/"+strconv.FormatInt(int64(pid), 10)+"/status"
	dumpcmd = "cat "+file
	filedump, err = exec.Command("sh", "-c", dumpcmd).Output()
	if err != nil {
		log.Fatal(err)
	}
	fmt.Printf("        The %s status:\n %s", file, filedump)
}



}


func main() {

pid := syscall.Getpid()

used = make(map[*PTEs]struct{})


fmt.Printf("Step 1: Start alloc stress test, then got stats\n")
AllocStress()
GetMemStat()
GetProcStat(pid, false)

fmt.Printf("Step 2: CleanUp Alloc stress test, then got stats\n")
AllocCleanUp()
GetMemStat()
GetProcStat(pid, false)

fmt.Printf("Step 3: Test finish, sleep 5 then got stats again\n")
time.Sleep(time.Second*5)
GetMemStat()
GetProcStat(pid, false)

fmt.Printf("Step 6: Test done, sleep 120 and wait quit\n")
time.Sleep(time.Second*120)
GetMemStat()
GetProcStat(pid, true)

runtime.KeepAlive(used)



}

Test case Output
$GODEBUG="madvdontneed=1" ./pagetable
Step 1: Start alloc stress test, then got stats
        Runtime stats: HeapAlloc 4317644192 HeapInuse 4317921280 HeapIdle 42942464 HeapReleased 42909696
        Runtime stats: HeapAlloc 4317644280 HeapInuse 4317921280 HeapIdle 42713088 HeapReleased 42647552
        Runtime stats: HeapAlloc 4317646080 HeapInuse 4317921280 HeapIdle 42942464 HeapReleased 42745856
        The numa_maps is heap-rss: 1054198 off-heap-rss 57844 total-rss 1112065
Step 2: CleanUp Alloc stress test, then got stats
        Runtime stats: HeapAlloc 402544 HeapInuse 679936 HeapIdle 4360347648 HeapReleased 4359995392
        Runtime stats: HeapAlloc 402552 HeapInuse 679936 HeapIdle 4360347648 HeapReleased 4360069120
        Runtime stats: HeapAlloc 402656 HeapInuse 679936 HeapIdle 4360314880 HeapReleased 4360077312
        The numa_maps is heap-rss: 388 off-heap-rss 57845 total-rss 58245
Step 3: Test finish, sleep 5 then got stats again
        Runtime stats: HeapAlloc 404200 HeapInuse 679936 HeapIdle 4360347648 HeapReleased 4360175616
        Runtime stats: HeapAlloc 404200 HeapInuse 679936 HeapIdle 4360347648 HeapReleased 4360241152
        Runtime stats: HeapAlloc 404200 HeapInuse 679936 HeapIdle 4360183808 HeapReleased 4360085504
        The numa_maps is heap-rss: 383 off-heap-rss 57848 total-rss 58241
Step 6: Test done, sleep 120 and wait quit
        Runtime stats: HeapAlloc 405736 HeapInuse 679936 HeapIdle 4360347648 HeapReleased 4360290304
        Runtime stats: HeapAlloc 405736 HeapInuse 679936 HeapIdle 4360314880 HeapReleased 4360224768
        Runtime stats: HeapAlloc 405744 HeapInuse 679936 HeapIdle 4360347648 HeapReleased 4360290304
        The numa_maps is heap-rss: 338 off-heap-rss 57849 total-rss 58199
        The /proc/5149/numa_maps numa_maps:
 00400000 default file=/opt/pagetable mapped=188 N0=188 kernelpagesize_kB=4
004bc000 default file=/opt/pagetable mapped=192 N0=192 kernelpagesize_kB=4
0057c000 default file=/opt/pagetable anon=9 dirty=9 mapped=24 N0=15 N1=9 kernelpagesize_kB=4
00594000 default anon=17 dirty=17 N0=1 N1=16 kernelpagesize_kB=4
c000000000 default anon=400 dirty=400 N0=142 N1=258 kernelpagesize_kB=4
7f12f72f2000 default anon=22219 dirty=22219 N0=640 N1=21579 kernelpagesize_kB=4
7f12fcd5d000 default anon=11802 dirty=11802 N0=6 N1=11796 kernelpagesize_kB=4
7f12ffc73000 default anon=7524 dirty=7524 N1=7524 kernelpagesize_kB=4
7f1301a16000 default anon=5263 dirty=5263 N0=3 N1=5260 kernelpagesize_kB=4
7f1302ece000 default anon=3499 dirty=3499 N0=3 N1=3496 kernelpagesize_kB=4
7f1303c99000 default anon=1984 dirty=1984 N1=1984 kernelpagesize_kB=4
7f1304475000 default anon=1815 dirty=1815 N0=1 N1=1814 kernelpagesize_kB=4
7f1304bb8000 default anon=956 dirty=956 N1=956 kernelpagesize_kB=4
7f1304f7f000 default anon=763 dirty=763 N1=763 kernelpagesize_kB=4
7f1305284000 default anon=242 dirty=242 N1=242 kernelpagesize_kB=4
7f13053bc000 default anon=1735 dirty=1735 N0=733 N1=1002 kernelpagesize_kB=4
7f1307d5e000 default
7f1317ede000 default anon=3 dirty=3 N1=3 kernelpagesize_kB=4
7f1317ee1000 default
7f1329d8e000 default anon=1 dirty=1 N1=1 kernelpagesize_kB=4
7f1329d8f000 default
7f132c164000 default anon=1 dirty=1 N1=1 kernelpagesize_kB=4
7f132c165000 default
7f132c5de000 default anon=1 dirty=1 N1=1 kernelpagesize_kB=4
7f132c5df000 default
7f132c65e000 default anon=24 dirty=24 N0=1 N1=23 kernelpagesize_kB=4
7ffc4f63d000 default stack anon=4 dirty=4 N1=4 kernelpagesize_kB=4
7ffc4f795000 default
7ffc4f797000 default
        The /proc/5149/status status:
 Name:	pagetable
Umask:	0022
State:	S (sleeping)
Tgid:	5149
Ngid:	0
Pid:	5149
PPid:	121852
TracerPid:	0
Uid:	1329078	1329078	1329078	1329078
Gid:	100	100	100	100
FDSize:	256
Groups:	100 19001
NStgid:	5149
NSpid:	5149
NSpgid:	5149
NSsid:	121852
VmPeak:	 5133780 kB
VmSize:	 5133780 kB
VmLck:	       0 kB
VmPin:	       0 kB
VmHWM:	 4460544 kB
VmRSS:	  233028 kB
RssAnon:	  231444 kB
RssFile:	    1584 kB
RssShmem:	       0 kB
VmData:	 4533096 kB
VmStk:	     132 kB
VmExe:	     752 kB
VmLib:	       8 kB
VmPTE:	    8780 kB
VmPMD:	      36 kB
VmSwap:	       0 kB
HugetlbPages:	       0 kB
Threads:	21
SigQ:	0/513333
SigPnd:	0000000000000000
ShdPnd:	0000000000000000
SigBlk:	0000000000000000
SigIgn:	0000000000000000
SigCgt:	fffffffe7fc1feff
CapInh:	0000000000000000
CapPrm:	0000000000000000
CapEff:	0000000000000000
CapBnd:	0000003fffffffff
CapAmb:	0000000000000000
Seccomp:	0
Speculation_Store_Bypass:	vulnerable
Cpus_allowed:	ffffffff
Cpus_allowed_list:	0-31
Mems_allowed:	00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000000,00000003
Mems_allowed_list:	0-1
voluntary_ctxt_switches:	175
nonvoluntary_ctxt_switches:	282

What did you expect to see?

Runtime should reclaim off-heap memory (anon-rss expect c000000000 vma), when the application has freed all memory.

What did you see instead?

The off-heap memory did not reclaimed.
@ianlancetaylor
Copy link
Contributor

The memory is released to the operating system over time. It is not released immediately, because there is a reasonable chance that a program that needs a lot of memory at one point will soon need a lot of memory again. The mechanism that releases unused heap memory to the OS is called the heap scavenger, and you can use GODEBUG=scavtrace=1 to see what it does.

@zhuangel
Copy link
Author

The memory is released to the operating system over time. It is not released immediately, because there is a reasonable chance that a program that needs a lot of memory at one point will soon need a lot of memory again. The mechanism that releases unused heap memory to the OS is called the heap scavenger, and you can use GODEBUG=scavtrace=1 to see what it does.

I am not mean heap memory, please see my test case, the heap memory has been released after I free the allocated memory, also I called runtime.GC and debug.FreeOSMemory in my test case, and I tried with about 120second wait.

From the numa_maps, you could easily find heap memory allocated and freed as expected.

Now I mean off-heap memory, which I this is used for heap memory management, maybe memory used by GCSys / MSpanInuse.

@golang golang locked and limited conversation to collaborators Dec 29, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Assignees
No one assigned
Labels
FrozenDueToAge
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@ianlancetaylor @gopherbot @zhuangel