GC problem

501 views
Skip to first unread message

Serhat Şevki Dinçer

unread,
Apr 29, 2017, 6:34:33 AM4/29/17
to golang-nuts
Hi,
I have a gc.go:

package main

import (
    "fmt"
    "runtime/debug"
)

const N = 3e8

func f(x int) {
    ls := make([]uint64, N)
    for i := N - 1; i >= 0; i-- {
        ls[i] = uint64(i)
    }
    fmt.Println(ls[x])
}

func main() {
    debug.SetGCPercent(10)
    f(8)
    f(9)
}


1st call suscessfully returns, I have enough ram on my laptop, but the 2nd call fails with "fatal error: runtime: out of memory"
The output is in gc.txt. So what's happening ?
gc.txt

Jesper Louis Andersen

unread,
Apr 29, 2017, 4:34:22 PM4/29/17
to Serhat Şevki Dinçer, golang-nuts
Your program completes without any trouble on my machine, but do note if we enter the following in an emacs scratch buffer and hit C-j to use it as a glorified calculator:

(/ (* 3e8 8) (* 1024 1024 1024))
2.2351741790771484

If each element in your array takes up 8 bytes, which is the case for a 64bit integer, then you need at least 2.2 gigabytes of memory to allocate the array. Looking at your output, it is clear your operating system is not allowing you to malloc some contiguous piece of space for this. There are a couple of possible things to look out for:

* 32bit systems can often allocate a constrained amount of memory in one go.
* You may be limited articifically by the operating system, either through cgroups or the 'ulimit' facility, though the latter has a rather peculiar way of working on linux.
* You may not have enough memory in your system.

In practice, a garbage collector will usually seek to allocate more space than what is needed. If we run your program with 

[jlouis@lady-of-pain z]$ GODEBUG=gctrace=1 ./z
gc 1 @0.000s 16%: 0.003+0+0.34 ms clock, 0.014+0/0/0+1.3 ms cpu, 0->0->0 MB, 0 MB goal, 8 P (forced)
gc 2 @0.020s 0%: 0.066+256+0.048 ms clock, 0.26+0/0.038/0.097+0.19 ms cpu, 2288->2288->2288 MB, 2289 MB goal, 8 P
8
9

we can see the garbage collector collects twice. The first one is probably forced by the SetGCPercentage call. The second because of the rather large allocation that is happening. And the amount of needed memory more or less coincides with the 3e8 * 8 calculation above.

--
You received this message because you are subscribed to the Google Groups "golang-nuts" group.
To unsubscribe from this group and stop receiving emails from it, send an email to golang-nuts...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

Serhat Sevki Dincer

unread,
May 1, 2017, 10:09:02 AM5/1/17
to Jesper Louis Andersen, golang-nuts

Your program completes without any trouble on my machine, but do note if we enter the following in an emacs scratch buffer and hit C-j to use it as a glorified calculator:

(/ (* 3e8 8) (* 1024 1024 1024))
2.2351741790771484

If each element in your array takes up 8 bytes, which is the case for a 64bit integer, then you need at least 2.2 gigabytes of memory to allocate the array.
Thanks for the arithmetic help, yes I am allocating 2+ gb ram

Looking at your output, it is clear your operating system is not allowing you to malloc some contiguous piece of space for this.
My os IS allowing me to allocate the ram. Note that the "2nd" call fails.

There are a couple of possible things to look out for:

* 32bit systems can often allocate a constrained amount of memory in one go.
* You may be limited articifically by the operating system, either through cgroups or the 'ulimit' facility, though the latter has a rather peculiar way of working on linux.
* You may not have enough memory in your system.

In practice, a garbage collector will usually seek to allocate more space than what is needed. If we run your program with 
Mine is a laptop with 4 gb ram & Ubuntu 64-bit 16.04

[jlouis@lady-of-pain z]$ GODEBUG=gctrace=1 ./z
gc 1 @0.000s 16%: 0.003+0+0.34 ms clock, 0.014+0/0/0+1.3 ms cpu, 0->0->0 MB, 0 MB goal, 8 P (forced)
gc 2 @0.020s 0%: 0.066+256+0.048 ms clock, 0.26+0/0.038/0.097+0.19 ms cpu, 2288->2288->2288 MB, 2289 MB goal, 8 P
8
9

we can see the garbage collector collects twice. The first one is probably forced by the SetGCPercentage call. The second because of the rather large allocation that is happening. And the amount of needed memory more or less coincides with the 3e8 * 8 calculation above.
If I have just the 1st call, there is no crash. After the 1st call returns, 2nd call should be able to succeed.
So what's happening?

peterGo

unread,
May 1, 2017, 2:02:03 PM5/1/17
to golang-nuts, jesper.lou...@gmail.com
I am unable to reproduce your issue.

$ cat /proc/meminfo | grep 'MemTotal'
MemTotal:        3946772 kB
$ uname -v -p -r -s
Linux 4.4.0-75-generic #96-Ubuntu SMP Thu Apr 20 09:56:33 UTC 2017 x86_64
$ go version
go version go1.8.1 linux/amd64
$ cat ssd.go

package main

import (
    "fmt"
    "runtime/debug"
)

const N = 3e8

func f(x int) {
    ls := make([]uint64, N)
    for i := N - 1; i >= 0; i-- {
        ls[i] = uint64(i)
    }
    fmt.Println(ls[x])
}

func main() {
    debug.SetGCPercent(10)
    f(8)
    f(9)
}
$ go run ssd.go
8
9
$


Peter

Jesper Louis Andersen

unread,
May 1, 2017, 2:12:06 PM5/1/17
to Serhat Sevki Dincer, golang-nuts
What (i think) is happening is that the GC runs concurrently with your program. After the call f(8) you have 2.2 gigabyte memory allocated. When you start the call to f(9) the GC starts a mark phase, but concurrently to that your program allocates 2.2 gigabyte more space. And before it manages to complete that allocation, you need around 4.5 gigabyte on heap space.

What confounds is that the program terminates after the call to f(9), so we don't get to see the heap in its final state. We can, however, alter your main function to manually collect before exiting since this will block the exit as well:

func main() {
debug.SetGCPercent(10)
f(8)
f(9)
runtime.GC()
}

And now the GODEBUG=gctrace=1 output is:

[jlouis@lady-of-pain z]$ GODEBUG=gctrace=1 ./z
gc 1 @0.000s 17%: 0.054+0+0.28 ms clock, 0.16+0/0/0+0.86 ms cpu, 0->0->0 MB, 0 MB goal, 8 P (forced)
gc 2 @0.313s 0%: 0.060+247+0.050 ms clock, 0.24+0/0.013/0.11+0.20 ms cpu, 2288->2288->2288 MB, 2289 MB goal, 8 P
8
gc 3 @0.855s 0%: 0.009+247+0.047 ms clock, 0.074+0/0.030/247+0.37 ms cpu, 4577->4577->2288 MB, 4578 MB goal, 8 P
9
gc 4 @1.103s 0%: 0.010+0+0.25 ms clock, 0.086+0/0.030/247+2.0 ms cpu, 2288->2288->0 MB, 2288 MB goal, 8 P (forced)

which shows gc #3 has a heap of 4.6 gigabyte it manages to shrink down one step to 2.28 gigabyte. Our own forced gc is #4 which then eliminates the heap entirely.

The "problem" is that when you allocate big chunks like these, the GC doesn't really stand a chance and can't work on your program quickly enough to free up space before your program requests more. The GC is simply being overloaded because there are only two allocations, and both are very large. To verify, you can try inserting a runtime.GC() between the f(8) and f(9) calls which block until the GC is done. This should make your program able to run in 2.2 gigs of memory space.

The solution is to allocate less data, get more RAM, or allocate what you need up front where it is less likely to get you into trouble.

Sokolov Yura

unread,
May 2, 2017, 12:09:19 AM5/2/17
to golang-nuts
GC is triggered *after* allocation than crosses boundary. So your second allocation is actually tries to complete before first allocation freed. And Ubuntu with 4GB memory doesn't allow to allocate 4GB memory cause overcommit is not enabled by default.

Use C/C++, or buy more memory, or change your datastructure from slice to slice of slice and allocate second dimension lazely, or call runtime.GC() explicitely between calls to f() (it will block until GC finishes).

Serhat Sevki Dincer

unread,
May 2, 2017, 7:00:21 AM5/2/17
to Sokolov Yura, golang-nuts
The allocation request (make) is made to the runtime which covers GC, right? GC percent is also set to 10%.
After 1st call returns, my app has about 2gb ram allocated. When 2nd call requests allocation, runtime cannot:
- first allocate another 2gb
- free the 1st buffer later
due to the definition of the GOGC (GC percent).
I think this is a GC bug.

2 May 2017 07:09 tarihinde "Sokolov Yura" <funny....@gmail.com> yazdı:
GC is triggered *after* allocation than crosses boundary. So your second allocation is actually tries to complete before first allocation freed. And Ubuntu with 4GB memory doesn't allow to allocate 4GB memory cause overcommit is not enabled by default.

Use C/C++, or buy more memory, or change your datastructure from slice to slice of slice and allocate second dimension lazely, or call runtime.GC() explicitely between calls to f() (it will block until GC finishes).

--
You received this message because you are subscribed to a topic in the Google Groups "golang-nuts" group.
To unsubscribe from this topic, visit https://groups.google.com/d/topic/golang-nuts/HrZpsyfb3i0/unsubscribe.
To unsubscribe from this group and all its topics, send an email to golang-nuts+unsubscribe@googlegroups.com.

Юрий Соколов

unread,
May 2, 2017, 9:09:19 AM5/2/17
to Serhat Sevki Dincer, golang-nuts
There is nowhere told that GOGC defines border that could not be reached. GOGC defines proportion that triggers GC, ie GC is triggered AFTER GOGC proportion crossed, not before.

In fact, if you allocates by small portions, then GC tries to predict when you will reach this border, and tries to start earlier. But it doesn't stop your program if you run faster and cross this border, cause current Golang GC us concurrent and tries to minimize GC pause. How could it minimize GC pause if it ought to stop whole your program to not cross GOGC proportion?

And you partially right: GC of old Go's versions may stop program before GOGC proportion crossed. So, if you try Go 1.0 most likely your programm will run.

But new behaviour is much better.

The point: you should know your instrument and environment. No one GC enabled runtime will be happy if you allocate huge arrays (perl/python/php are exceptions, cause they use reference counting). If you ought to allocate huge arrays in GC runtime, use off-heap allocation (Java men learn that hard way).

For example, you may use mmap to allocate huge array.

Or, I'll repeat my self, use datastructure without huge continuous allocation (ie slice of slices for your example). Then GC will have a chance to trigger ealier and free some memory before it exhausted.

2 мая 2017 г. 1:59 PM пользователь "Serhat Sevki Dincer" <jfcg...@gmail.com> написал:

Jesper Louis Andersen

unread,
May 2, 2017, 9:20:05 AM5/2/17
to Serhat Sevki Dincer, Sokolov Yura, golang-nuts
I don't think it is a GC bug, but rather a trade-off of several desirable properties.

The system does the following:

- allocates 2gb
- Since the current heap size is 0 the 10% gc limit is reached and a GC is started concurrently with the program
- While the program processes the array, the GC finishes (using a separate CPU core probably)
- The heap is now 2gb
- The next 2gb is requested
- Since the current heap size is 2gb, the limit of 10% is around 200mb. This is reached, so a new concurrent allocation is started
- The system mallocs the 2gb in
- At this point, your program needs 4gb memory, but the GC is running and immediately frees up 2 gigabytes
- ...
- The 2gigabytes are given back to the OS if nothing else in the program needs it.

TL;DR: You must construct additional pylons!

You have two options if the malloc is denied by the operating system:

- Crash the program. This is the current behavior
- Block the program, try to GC and see if that frees up enough space.

I think Java did the blocking solution for a while. The problem with blocking is that your program now has latency problems. Worse, a system that is about to die ends up in a perpetual state where is grinds to a halt while trying to squeeze out more bytes from the GC, but fails to do so, which retrigger another blocking GC, and so on. Trying to recover from lack of memory is almost always a futile endeavor which rarely ends up with good results.

Go is a language created at solving systems problems. Systems problems generally want low latency operation over high throughput, so a GC which blocks the program is always undesirable.

Also, your program is somewhat extreme because it requests almost all of the systems available memory very quickly. I know of no garbage collected language implementation which fares well in that situation :)

To unsubscribe from this group and all its topics, send an email to golang-nuts...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "golang-nuts" group.
To unsubscribe from this group and stop receiving emails from it, send an email to golang-nuts...@googlegroups.com.

Serhat Sevki Dincer

unread,
May 3, 2017, 11:24:40 AM5/3/17
to Юрий Соколов, golang-nuts
Ok if GOGC is the trigger point, then out-of-memory error should be consistent on all Ubuntu 64-bit 4gb systems, right?
If so, why cant peterGo reproduce the crash?

2 May 2017 16:08 tarihinde "Юрий Соколов" <funny....@gmail.com> yazdı:

Jesper Louis Andersen

unread,
May 3, 2017, 12:52:41 PM5/3/17
to Serhat Sevki Dincer, Юрий Соколов, golang-nuts
TL;DR: It depends on the kernels configuration and the amount of swap space.

Longer explanation:

When a malloc() is granted by the kernel, it allocates the space virtually. It doesn't yet assign physical DRAM space to the allocation because it speculates that you are not going to use all the space up front, and thus allocating it a bit at a time is more efficient. Whenever you access a new portion of the virtual space, a kernel trap is triggered and the kernel allocates physical space for the given portion and resumes the program.

Linux kernels can overcommit memory. This means the kernel can hand out memory it doesn't have guaranteed available. It does so in the hope that when you actually need the space, some other program has completed and then it can use that space. Another way to get more memory is by using swap space as additional memory, albeit at a slower pace.

What likely happens on peterGo's machine is the following: The extra 2.2gb memory is allocated virtually, but as you walk through that memory space getting kernel trapped all the time, the garbage collection completes and advices the kernel there is a large space of memory which isn't needed anymore. So when it finally comes along and needs space because it is about to run out, a newly freed up portion is available. The alternative hypothesis is that peterGo has ample amounts of swap space available and uses this partially.

Ubuntu doesn't overcommit by default, as already stated in this thread. Solaris/Illumos can't overcommit memory at all for instance.

Note that the scenario is likely to be brittle: depending on timing, your program may either run much slower than envisioned, or not even run at all when you are close to the boundary of available memory in a machine. The kernel will also have to find the space somewhere, usually by erasing the disk cache to make up for the demand of memory pressure.


To unsubscribe from this group and all its topics, send an email to golang-nuts...@googlegroups.com.

For more options, visit https://groups.google.com/d/optout.

--
You received this message because you are subscribed to the Google Groups "golang-nuts" group.
To unsubscribe from this group and stop receiving emails from it, send an email to golang-nuts...@googlegroups.com.

peterGo

unread,
May 3, 2017, 2:19:25 PM5/3/17
to golang-nuts, funny....@gmail.com
Serhat Şevki Dinçer,


"why cant peterGo reproduce the crash?"

Because I have swap space.

$ go build ssd.go
$ cat /proc/swaps
Filename                Type         Size    Used    Priority
/dev/sda5               partition    7999484    0       -1
$ ./ssd
8
9
$ cat /proc/swaps
Filename                Type         Size    Used    Priority
/dev/sda5               partition    7999484 1723860    -1
$


Peter
To unsubscribe from this group and all its topics, send an email to golang-nuts...@googlegroups.com.

peterGo

unread,
May 3, 2017, 2:50:50 PM5/3/17
to golang-nuts, funny....@gmail.com
Serhat Şevki Dinçer,

FYI

Swapfiles by default in Ubuntu
http://blog.surgut.co.uk/2016/12/swapfiles-by-default-in-ubuntu.html

"By default, in Ubuntu, we usually create a swap partition."

"Starting from 17.04 Zesty Zapus release, instead of creating swap partitions, swapfiles will be used by default for non-lvm based installations."

Peter
Reply all
Reply to author
Forward
0 new messages