Memory is not even getting freed (back to OS)

Question

I'm running a server written in Go and the RSS is very high and the memory is not even getting freed (back to OS).

I used pprof to check but it seems that there is no memory leak.

I also tried:

GODEBUG=madvdontneed=1 ./memorytest

Please tell me how to use madvdontneed.

OS: CentOS 7 (Linux)
Arch: amd64
Go version: 1.14.2

Code:

package main

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

var garr []string

var chn chan int

func main() {
    chn = make(chan int, 1)

    go Alloc()

    <-chn
}

func Alloc() {
    for {
        arr := make([]string, 100000000)
        //copy(garr,arr)
        garr = arr
        print_heap_info()
        time.Sleep(5 * time.Second)
    }
}

func print_heap_info() {
    var m runtime.MemStats
    runtime.ReadMemStats(&m)
    fmt.Printf("env:%v, heapsys:%d,heapalloc:%d,heapidel:%d,heapreleased:%d,heapinuse:%d\n",
        os.Getenv("GODEBUG"), m.HeapSys, m.HeapAlloc, m.HeapIdle, m.HeapReleased, m.HeapInuse)
}

Output：

env:madvdontneed=1, heapsys:1677262848,heapalloc:1600074304,heapidel:76955648,heapreleased:76914688,heapinuse:1600307200
env:madvdontneed=1, heapsys:3287875584,heapalloc:3200081392,heapidel:87556096,heapreleased:87506944,heapinuse:3200319488
env:madvdontneed=1, heapsys:4898619392,heapalloc:4800086512,heapidel:98295808,heapreleased:98115584,heapinuse:4800323584
env:madvdontneed=1, heapsys:6509101056,heapalloc:6400090640,heapidel:108773376,heapreleased:108724224,heapinuse:6400327680
env:madvdontneed=1, heapsys:6509232128,heapalloc:4800086176,heapidel:1708908544,heapreleased:108724224,heapinuse:4800323584
env:madvdontneed=1, heapsys:6509002752,heapalloc:6400090304,heapidel:108675072,heapreleased:108560384,heapinuse:6400327680
env:madvdontneed=1, heapsys:6509199360,heapalloc:4800086712,heapidel:1708875776,heapreleased:108560384,heapinuse:4800323584
env:madvdontneed=1, heapsys:6509068288,heapalloc:6400090744,heapidel:108740608,heapreleased:108560384,heapinuse:6400327680
env:madvdontneed=1, heapsys:6509199360,heapalloc:4800086712,heapidel:1708875776,heapreleased:108560384,heapinuse:4800323584
env:madvdontneed=1, heapsys:6509068288,heapalloc:6400090840,heapidel:108740608,heapreleased:108462080,heapinuse:6400327680

enter image description here

"the RSS is very high and the memory is not even getting freed (back to OS)" both are normal. What is the actual problem? — Volker, Nov 23 '20 at 08:35
Your output shows the allocated memory has stabilized. Using a lot of memory is not a memory leak. — JimB, Nov 23 '20 at 12:09
But it's not the server code. Try `runtime.GC()` at the end of your program and let GC clean the garbage from the heap (It'll immediately release memory back to OS, if there's some unused memory). Go's runtime doesn't immediately release but keeps it to itself for it's future use but after some time if it's still not getting used then it releases back to the OS. — shmsr, Nov 23 '20 at 14:27
Even when go releases memory back to the OS, it will remain in Go's memory footprint until there is enough system-wide memory pressure to cause the OS to reclaim that memory. — Adrian, Nov 23 '20 at 14:38
Nov 23 16:51:52 localhost kernel: Out of memory: Kill process 29184 (memorytest) score 391 or sacrifice child — user10044988, Nov 24 '20 at 01:16

wasmup · Answer 1 · 2020-11-27T21:54:29.300

Optimize your memory allocations to lower the peak.

See also: debug.FreeOSMemory()

FreeOSMemory forces a garbage collection followed by an attempt to return as much memory to the operating system as possible. (Even if this is not called, the runtime gradually returns memory to the operating system in a background task.)

Your formatted output is:

sys: 1599 MB alloc: 1525 MB idel:   73 MB released:   73 MB inuse: 1526 MB 
sys: 3135 MB alloc: 3051 MB idel:   83 MB released:   83 MB inuse: 3052 MB 
sys: 4671 MB alloc: 4577 MB idel:   93 MB released:   93 MB inuse: 4577 MB 
sys: 6207 MB alloc: 6103 MB idel:  103 MB released:  103 MB inuse: 6103 MB 
sys: 6207 MB alloc: 4577 MB idel: 1629 MB released:  103 MB inuse: 4577 MB 
sys: 6207 MB alloc: 6103 MB idel:  103 MB released:  103 MB inuse: 6103 MB 
sys: 6207 MB alloc: 4577 MB idel: 1629 MB released:  103 MB inuse: 4577 MB 
sys: 6207 MB alloc: 6103 MB idel:  103 MB released:  103 MB inuse: 6103 MB 
sys: 6207 MB alloc: 4577 MB idel: 1629 MB released:  103 MB inuse: 4577 MB 
sys: 6207 MB alloc: 6103 MB idel:  103 MB released:  103 MB inuse: 6103 MB

Which is (for the last line):
sys: bytes of heap memory obtained from the OS: 6207 MB
alloc: bytes of allocated heap objects: 6103 MB
idel: bytes in idle (unused) spans: 103 MB
released: bytes of physical memory returned to the OS: 103 MB
inuse: bytes in in-use spans: 6103 MB

It is not a memory leak. Output for a system with total 8GB RAM (system memory monitor):

command:

GODEBUG=madvdontneed=1  go run .

Output:

env: madvdontneed=1, sys: 1087 MB, alloc: 1024 MB, idel:   63 MB, released:   63 MB, inuse: 1024 MB
env: madvdontneed=1, sys: 2111 MB, alloc: 2048 MB, idel:   63 MB, released:   63 MB, inuse: 2048 MB
env: madvdontneed=1, sys: 3135 MB, alloc: 3072 MB, idel:   63 MB, released:   63 MB, inuse: 3072 MB
env: madvdontneed=1, sys: 4159 MB, alloc: 4096 MB, idel:   63 MB, released:   63 MB, inuse: 4096 MB
env: madvdontneed=1, sys: 4159 MB, alloc: 3072 MB, idel: 1087 MB, released:   63 MB, inuse: 3072 MB
env: madvdontneed=1, sys: 4159 MB, alloc: 4096 MB, idel:   63 MB, released:   63 MB, inuse: 4096 MB
env: madvdontneed=1, sys: 4159 MB, alloc: 3072 MB, idel: 1087 MB, released:   63 MB, inuse: 3072 MB
env: madvdontneed=1, sys: 4159 MB, alloc: 4096 MB, idel:   63 MB, released:   63 MB, inuse: 4096 MB
env: madvdontneed=1, sys: 4159 MB, alloc: 3072 MB, idel: 1087 MB, released:   63 MB, inuse: 3072 MB
env: madvdontneed=1, sys: 4159 MB, alloc: 4096 MB, idel:   63 MB, released:   63 MB, inuse: 4096 MB

Code:

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

htop:

Output for vmstat 1 -S MB command, running two terminals:

procs -----------memory---------- ---swap-- -----io---- -system-- ------cpu-----
 r  b   swpd   free   buff  cache   si   so    bi    bo   in   cs us sy id wa st
 0  0   1161   6369     25    595    0    0   702   452  276  567  6  3 91  1  0
 3  0   1160   6300     28    632    0    0 43432     0 6288 14013 13  5 82  1  0
 1  0   1160   6243     28    634    0    0   528     0 6342 13008 11  3 85  0  0
 1  0   1160   6177     28    634    0    0    56    56  979 2090  4  1 95  0  0
 2  0   1160   6110     28    634    0    0     0     0 1061 2664  5  2 94  0  0
 0  0   1160   6044     28    634    0    0    12    36  994 2233  4  1 94  0  0
 0  0   1160   3991     28    634    0    0    32   188 1074 1787  5  6 89  0  0
 2  0   1160   2120     28    634    0    0     0   136 1016 1634  4  5 90  0  0
 1  0   1160    973     28    633    0    0     0     4 1077 1660  4  5 92  0  0
 2  0   1160    143     25    390    0    0  1780   356 1849 2341  4  9 87  0  0
 0  9   1323    102      0    108    0  165 51964 169652 20277 21017  1 20 53 25  0
 1  5   1510     99      0    129    2  189 54376 193996 57829 52152  1 16 56 27  0
 1  5   1794     99      0    129    1  286 10068 293856 81160 59511  0 16 77  6  0
 4  5   2047    101      0     98    5  257 21236 263292 69923 65485  0 23 54 23  0
 1  2   1479   2867      0    217   43   23 233508 24380 24023 48536  4 27 47 22  0
 2  0   1452   2824      0    232   27    0 43960     0 8168 21085  4  5 90  1  0
 0  1   1443   2814      0    233    9    0 10956     0 3341 8468  5  2 93  0  0
 3  0   1425   2796      0    231   18    0 19688     0 5780 15490  4  3 92  1  0
 1  1   1420   2672     10    337    3    0 121628  1920 3292 7934  5  7 81  7  0
 0  0   1394   2646     10    338   25    0 27360     0 7975 21555  3  5 92  0  0
 0  1   1359   6856     10    339    1    0  2416     0 1035 2108  3  2 95  0  0
 0  0   1353   6847     10    348    4    0 13660     0 1696 3471  4  1 95  0  0

Output for first GODEBUG=madvdontneed=1 go run . command (auto killed):

env: madvdontneed=1, sys: 1087 MB, alloc: 1024 MB, idel:   63 MB, released:   63 MB, inuse: 1024 MB
env: madvdontneed=1, sys: 2111 MB, alloc: 2048 MB, idel:   63 MB, released:   63 MB, inuse: 2048 MB
env: madvdontneed=1, sys: 3135 MB, alloc: 3072 MB, idel:   63 MB, released:   63 MB, inuse: 3072 MB
env: madvdontneed=1, sys: 4159 MB, alloc: 4096 MB, idel:   63 MB, released:   63 MB, inuse: 4096 MB
env: madvdontneed=1, sys: 4159 MB, alloc: 3072 MB, idel: 1087 MB, released:   63 MB, inuse: 3072 MB
env: madvdontneed=1, sys: 4159 MB, alloc: 4096 MB, idel:   63 MB, released:   63 MB, inuse: 4096 MB
env: madvdontneed=1, sys: 4159 MB, alloc: 3072 MB, idel: 1087 MB, released:   63 MB, inuse: 3072 MB
signal: killed

Output for second GODEBUG=madvdontneed=1 go run . command:

env: madvdontneed=1, sys: 1087 MB, alloc: 1024 MB, idel:   63 MB, released:   63 MB, inuse: 1024 MB
env: madvdontneed=1, sys: 2111 MB, alloc: 2048 MB, idel:   63 MB, released:   63 MB, inuse: 2048 MB
env: madvdontneed=1, sys: 3135 MB, alloc: 3072 MB, idel:   63 MB, released:   63 MB, inuse: 3072 MB
env: madvdontneed=1, sys: 4159 MB, alloc: 4096 MB, idel:   63 MB, released:   63 MB, inuse: 4096 MB
env: madvdontneed=1, sys: 4159 MB, alloc: 3072 MB, idel: 1087 MB, released:   63 MB, inuse: 3072 MB
env: madvdontneed=1, sys: 4159 MB, alloc: 4096 MB, idel:   63 MB, released:   63 MB, inuse: 4096 MB
env: madvdontneed=1, sys: 4159 MB, alloc: 3072 MB, idel: 1087 MB, released:   63 MB, inuse: 3072 MB
env: madvdontneed=1, sys: 4159 MB, alloc: 4096 MB, idel:   63 MB, released:   62 MB, inuse: 4096 MB
env: madvdontneed=1, sys: 4159 MB, alloc: 3072 MB, idel: 1087 MB, released:   62 MB, inuse: 3072 MB
env: madvdontneed=1, sys: 4159 MB, alloc: 4096 MB, idel:   63 MB, released:   62 MB, inuse: 4096 MB

Code:

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\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

Command:

GODEBUG=gctrace=1 go run .

Output:

gc 1 @0.008s 2%: 0.071+0.67+0.034 ms clock, 0.57+0.88/0.76/0.041+0.27 ms cpu, 4->4->0 MB, 5 MB goal, 8 P
gc 2 @0.014s 3%: 0.069+1.3+0.027 ms clock, 0.55+0.48/0.80/0.73+0.21 ms cpu, 4->4->0 MB, 5 MB goal, 8 P
gc 3 @0.029s 2%: 0.056+0.62+0.040 ms clock, 0.45+0.39/0.75/0.67+0.32 ms cpu, 4->4->0 MB, 5 MB goal, 8 P
gc 4 @0.045s 3%: 0.31+0.97+0.12 ms clock, 2.5+0.91/1.2/0.92+1.0 ms cpu, 4->4->0 MB, 5 MB goal, 8 P
gc 5 @0.060s 2%: 0.056+0.60+0.019 ms clock, 0.45+0.44/0.70/1.1+0.15 ms cpu, 4->4->0 MB, 5 MB goal, 8 P
gc 6 @0.071s 2%: 0.025+1.0+0.018 ms clock, 0.20+0.47/1.1/3.5+0.15 ms cpu, 4->4->0 MB, 5 MB goal, 8 P
gc 7 @0.084s 2%: 0.12+0.88+0.042 ms clock, 0.97+0.77/1.2/0.88+0.33 ms cpu, 4->4->1 MB, 5 MB goal, 8 P
gc 8 @0.093s 2%: 0.039+0.83+0.028 ms clock, 0.31+0.38/0.66/1.2+0.22 ms cpu, 4->4->0 MB, 5 MB goal, 8 P

gc 1 @0.007s 3%: 0.013+1.7+0.005 ms clock, 0.11+0.86/2.0/1.2+0.042 ms cpu, 4->5->4 MB, 5 MB goal, 8 P

gc 1 @0.002s 5%: 0.024+2.0+0.042 ms clock, 0.19+0.25/1.5/1.3+0.34 ms cpu, 4->6->5 MB, 5 MB goal, 8 P
gc 2 @0.017s 3%: 0.014+4.6+0.044 ms clock, 0.11+0.13/3.3/1.9+0.35 ms cpu, 9->10->7 MB, 10 MB goal, 8 P
gc 3 @0.058s 2%: 0.030+6.7+0.036 ms clock, 0.24+0.12/5.3/1.8+0.29 ms cpu, 13->15->10 MB, 15 MB goal, 8 P
gc 4 @0.100s 2%: 0.034+5.6+0.015 ms clock, 0.27+0/7.2/0.65+0.12 ms cpu, 18->18->12 MB, 21 MB goal, 8 P
gc env: gctrace=1, sys: 1087 MB, alloc: 1024 MB, idel:   63 MB, released:   63 MB, inuse: 1024 MB

1 @0.024s 0%: 0.028+0.41+0.016 ms clock, 0.22+0.11/0.14/0.093+0.13 ms cpu, 1024->1024->1024 MB, 1025 MB goal, 8 P
env: gctrace=1, sys: 2111 MB, alloc: 2048 MB, idel:   63 MB, released:   63 MB, inuse: 2048 MB

gc 2 @1.049s 0%: 0.021+0.44+0.005 ms clock, 0.16+0.12/0.15/0.12+0.045 ms cpu, 2048->2048->2048 MB, 2049 MB goal, 8 P
env: gctrace=1, sys: 3135 MB, alloc: 3072 MB, idel:   63 MB, released:   63 MB, inuse: 3072 MB

env: gctrace=1, sys: 4159 MB, alloc: 4096 MB, idel:   63 MB, released:   63 MB, inuse: 4096 MB

gc 3 @3.096s 0%: 0.023+0.56+0.017 ms clock, 0.18+0.13/0.20/0.17+0.13 ms cpu, 4096->4096->2048 MB, 4097 MB goal, 8 P
env: gctrace=1, sys: 4159 MB, alloc: 3072 MB, idel: 1087 MB, released:   63 MB, inuse: 3072 MB

env: gctrace=1, sys: 4159 MB, alloc: 4096 MB, idel:   63 MB, released:   63 MB, inuse: 4096 MB

gc 4 @5.619s 0%: 0.023+0.31+0.018 ms clock, 0.18+0.18/0.18/0.22+0.15 ms cpu, 4096->4096->2048 MB, 4097 MB goal, 8 P
env: gctrace=1, sys: 4159 MB, alloc: 3072 MB, idel: 1087 MB, released:   63 MB, inuse: 3072 MB

env: gctrace=1, sys: 4159 MB, alloc: 4096 MB, idel:   63 MB, released:   63 MB, inuse: 4096 MB

gc 5 @8.141s 0%: 0.025+0.26+0.004 ms clock, 0.20+0.16/0.15/0.15+0.033 ms cpu, 4096->4096->2048 MB, 4097 MB goal, 8 P
env: gctrace=1, sys: 4159 MB, alloc: 3072 MB, idel: 1087 MB, released:   63 MB, inuse: 3072 MB

gc 6 @10.413s 0%: 0.028+0.51+0.013 ms clock, 0.22+0.23/0.28/0.29+0.11 ms cpu, 4096->4096->2048 MB, 4097 MB goal, 8 P
env: gctrace=1, sys: 4159 MB, alloc: 4096 MB, idel:   63 MB, released:   63 MB, inuse: 4096 MB

The format of this line is subject to change. Currently, it is:

    gc # @#s #%: #+#+# ms clock, #+#/#/#+# ms cpu, #->#-># MB, # MB goal, # P
where the fields are as follows:
    gc #        the GC number, incremented at each GC
    @#s         time in seconds since program start
    #%          percentage of time spent in GC since program start
    #+...+#     wall-clock/CPU times for the phases of the GC
    #->#-># MB  heap size at GC start, at GC end, and live heap
    # MB goal   goal heap size
    # P         number of processors used

Note:
go version go1.15.5 linux/amd64

See also:
Go 1.13 RSS keeps on increasing, suspected scavenging issue
https://github.com/golang/go/issues/36398
https://github.com/golang/go/issues/39295
https://go.googlesource.com/proposal/+/master/design/14951-soft-heap-limit.md
https://docs.google.com/document/d/1wmjrocXIWTr1JxU-3EQBI6BK6KgtiFArkG47XK73xIQ/edit#
https://blog.cloudflare.com/go-dont-collect-my-garbage/

yes, but if you use **top** to see the memory of the process, it's very high. — user10044988, Nov 23 '20 at 08:26
Your example programs don’t run long enough to have released any memory. — JimB, Nov 23 '20 at 12:10
No it’s not. The scavenger runs every 5 minutes. Garbage collection does not release memory. — JimB, Nov 23 '20 at 12:53
Running `GC` just prevents the extra allocations in the first place, it has nothing to do with the scavenger. If you want to see why the GC runs when it does, watch the `gctrace` output — JimB, Nov 23 '20 at 13:08

Memory is not even getting freed (back to OS)

1 Answers1