runtime: temporary object is not garbage collected

[chengzhicn]

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

go1.8 linux/amd64

What operating system and processor architecture are you using (go env)?

Debian 8 x64

What did you do?

https://play.golang.org/p/CHd8wCf5oP

What did you expect to see?

All objects should get garbage collected since there is no reference to them

What did you see instead?

stateBuf & x still holding memory

[bradfitz]

/cc @randall77 @aclements

[davecheney]

I don't believe this is a bug. The memory profile records objects that were allocated. It does not record which objects were collected. Can you please explain the problem you are having with your program, not this sample code. Thank you

…

On Thu, Mar 9, 2017 at 1:46 PM, Brad Fitzpatrick ***@***.***> wrote: /cc @randall77 <https://github.com/randall77> @aclements <https://github.com/aclements> — You are receiving this because you are subscribed to this thread. Reply to this email directly, view it on GitHub <#19469 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAAcAz3k7JS-bI6Yv6MUwDKlGbUXwHVVks5rj2gYgaJpZM4MXlAy> .

[chengzhicn]

The real program read a large json file, decode it, and call subroutine based on the value in the json file, then wait the subroutine to finish which takes a long time(normally hours).

I noticed the program using a lot of memory even though the subroutine has very low memory footprint. Profiler shows the stateBuf & x never get garbage collected despite the fact that all of them have been set to nil.

[aclements]

@davecheney, I believe @chengzhicn is right that these are being retained. The profile shows "in use" objects by default, and the program forced a few GCs before getting the profile. Furthermore, with the following tweaked version, you can get a more detailed profile and reasonably run with GODEBUG=allocfreetrace=1:

package main

import (
	"bytes"
	"encoding/json"
	"io"
	"io/ioutil"
	"os"
	"runtime"
	"runtime/debug"
	"runtime/pprof"
	"strconv"
)

type Decoder struct {
	decoder *json.Decoder
	r       io.Reader
}

func NewDecoder(r io.Reader) *Decoder {
	return &Decoder{json.NewDecoder(r), r}
}

func (dec *Decoder) Decode(v interface{}) (err error) {
	return dec.decoder.Decode(v)
}

func writeJson() {
	var buf bytes.Buffer
	buf.WriteString(`{`)
	//for i := 0; i < 100000; i++ {
	for i := 0; i < 10; i++ {
		buf.WriteString(`"`)
		buf.WriteString(strconv.Itoa(i))
		buf.WriteString(`":{"FileName":"10000000000","Size":40,"Next":0,"Values":[1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20]},`)
	}
	buf.WriteString(`"tail":{}}`)
	ioutil.WriteFile("state.json", buf.Bytes(), 0644)
}

func main() {
	writeJson()
	runtime.MemProfileRate = 1
	stateBuf, _ := ioutil.ReadFile("state.json")
	state := make(map[string]interface{})
	x := NewDecoder(bytes.NewBuffer(stateBuf))
	x.Decode(&state)
	state = nil
	stateBuf = nil
	x = nil
	runtime.GC()
	debug.FreeOSMemory()
	fmem, _ := os.Create("leak.prof")
	pprof.WriteHeapProfile(fmem)
}

If you search for ".refill" in the allocfreetrace, you'll see that the last uint8 buffer it allocates never gets freed.

[davecheney]

If you search for ".refill" in the allocfreetrace, you'll see that the

last uint8 buffer it allocates never gets freed. Thanks Austin. But `x`, the decoder is nil'ed out, so there should be no reference to the internal buf structure.

…

On Thu, Mar 9, 2017 at 2:04 PM, Austin Clements ***@***.***> wrote: @davecheney <https://github.com/davecheney>, I believe @chengzhicn <https://github.com/chengzhicn> is right that these are being retained. The profile shows "in use" objects by default, and the program forced a few GCs before getting the profile. Furthermore, with the following tweaked version, you can get a more detailed profile and reasonably run with GODEBUG=allocfreetrace=1: package main import ( "bytes" "encoding/json" "io" "io/ioutil" "os" "runtime" "runtime/debug" "runtime/pprof" "strconv" ) type Decoder struct { decoder *json.Decoder r io.Reader } func NewDecoder(r io.Reader) *Decoder { return &Decoder{json.NewDecoder(r), r} } func (dec *Decoder) Decode(v interface{}) (err error) { return dec.decoder.Decode(v) } func writeJson() { var buf bytes.Buffer buf.WriteString(`{`) //for i := 0; i < 100000; i++ { for i := 0; i < 10; i++ { buf.WriteString(`"`) buf.WriteString(strconv.Itoa(i)) buf.WriteString(`":{"FileName":"10000000000","Size":40,"Next":0,"Values":[1,2,3,4,5,6,7,8,9,10,11,12,13,14,15,16,17,18,19,20]},`) } buf.WriteString(`"tail":{}}`) ioutil.WriteFile("state.json", buf.Bytes(), 0644) } func main() { writeJson() runtime.MemProfileRate = 1 stateBuf, _ := ioutil.ReadFile("state.json") state := make(map[string]interface{}) x := NewDecoder(bytes.NewBuffer(stateBuf)) x.Decode(&state) state = nil stateBuf = nil x = nil runtime.GC() debug.FreeOSMemory() fmem, _ := os.Create("leak.prof") pprof.WriteHeapProfile(fmem) } If you search for ".refill" in the allocfreetrace, you'll see that the last uint8 buffer it allocates never gets freed. — You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub <#19469 (comment)>, or mute the thread <https://github.com/notifications/unsubscribe-auth/AAAcA9A5exGgbBWXS_q2du39QEe5eAZbks5rj2xQgaJpZM4MXlAy> .

[aclements]

I'm having trouble interpreting the raw liveness maps for main for some reason, but the output of -live shows that autotmp_21 is considered live at the call to runtime.GC() and it looks like autotmp_21 contains a pointer to the json.Decoder.

I believe this is a bad interaction between inlining and liveness analysis. If you turn off inlining everything gets garbage collected. @randall77?

But x, the decoder is nil'ed out, so there should be no reference to the internal buf structure.

Well, yes, I think that's the point. Why isn't the json decoder's buf structure getting freed given that all of the references to it should be gone? (Admittedly, the problem isn't really that "x" isn't getting garbage collected. "x" is a variable, not an object, so this statement doesn't really type check. In fact, x doesn't even exist in the binary; it's been optimized away. But the underlying question of why the decoder's resources aren't getting freed is still a question.)

[josharian]

Probably unrelated, but this reminds me of #18336.

[randall77]

On input to SSA, there is a VARKILL of autotmp_21 immediately after the call to x.Decode
(autotmp_21 is the storage that x points to). That is correct.

autotmp_21 is not marked as addrtaken. I think that might be the underlying bug. SSA sees the VARKILL, but it decides that it is going to registerize autotmp_21 so it doesn't need the VARKILL.
Frankly I'm surprised autotmp_21 gets correctly initialized before its address is passed to Decode.

[randall77]

I think I take back most of what I said last time. I think I got confused about which autotmp was which.

Here's a simple repro:

package main

import "runtime"

type T struct {
	p *int
}

func f(p *int) {
	_ = &T{p: p}
	runtime.GC()
}

$ go tool compile -live ~/go/issue19469b.go
/Users/khr/go/issue19469b.go:9: live at entry to f: p
/Users/khr/go/issue19469b.go:11: live at call to GC: .autotmp_1

.autotmp_1 is the stack-allocated T generated by the struct literal. .autotmp_1 will make the GC consider what p pointed to live at the runtime.GC call, which is incorrect.

The problem is there is no VARKILL for autotmp_1. It gets allocated on the stack and initialized, but then it is considered live for the rest of the function because it is (correctly) marked addrtaken.

I'm not seeing any obvious fix for this. To place the VARKILL correctly you'd need to do some dataflow of the pointer-to-autotmp_1 to see where it was used.

[aclements]

@randall77, it sounds like we understand the problem fairly well, just not how to solve it. Should this be moved from 1.9 to unplanned (or simply closed as unfortunate)?

[bradfitz]

Kicked down the road to 1.10 at least. Definitely not 1.9 material.

[randall77]

Yes, I don't see any obvious solution to this. It would need at least another compiler pass.

[randall77]

This should be fixed by stack tracing.
(CLs https://go-review.googlesource.com/c/go/+/134155 and https://go-review.googlesource.com/c/go/+/134156)