Why is this variable retained on the heap?

Hello all

I feel that I haven’t explained my previous question very well, I’ll try to that in this new topic a bit better.
Previous topic can be found here (This topic can be closed)

I am using the pprof package to do some memory profiling and the results indicates there are some variables stored on the heap that I cannot explain, maybe it is even a memory leak.

I write the memory profile with the following code and it is called from the robot frame work using a restApi. (So it’s running in it’s own routine.)

func onGetMemProfile(w http.ResponseWriter, r *http.Request) {
    memProfile, err := os.Create("memProfile.pprof")
    if err != nil {
      	fmt.Println("memProfile could not be created.")
    }
    runtime.GC() //Runs garbage collection
    if err := pprof.WriteHeapProfile(memProfile); err != nil {
       fmt.Println("could not write memory profile: ", err)
    }
}

When I investigate the difference between 2 memory profiles after a certain scenario, the profiling tools tell me there is a string variable retained on the heap, something I cannot explain.

This happens in this code snippet:

func (info *Info) Values(path string) (ret []gjson.Result, status QueryStatus) {
    status = QueryUnknown
    test := info.data + " "

    result := gjson.Get(test, path)
    if result.Exists() {
        status = QuerySuccessful
        ret = result.Array()
    } else {
        status = QueryConfigMissing
    }
    return
}

Without copying the info.data into the test variable, the profiling tools indicate that info.data memory is retained on a higher level. With this copy, info.data is not retained according to the profiling data.

The profiling tools output is the following (for the inuse_space sample) :

Total:      7.56kB     7.56kB (flat, ■■■) 0.013%
258            .          .           } 
259            .          .            
260            .          .           func (info *Info) Values(path string) (ret []gjson.Result, status QueryStatus) { 
261            .          .           	status = QueryUnknown 
262            .          .            
263       7.56kB     7.56kB           	test := info.data + " " 
264            .          .            
265            .          .           	result := gjson.Get(test, path) 
266            .          .           	if result.Exists() { 
267            .          .           		status = QuerySuccessful 
268            .          .           		ret = result.Array() 

Note that in the scenario we are testing, this function is called many times over. When looking into the profiling alloc_object & inuse_object sample space only 10 out of 1344 times the string is retained on the heap.

alloc_object sample  : 263         1344       1344          test := info.data + " " 
inuse_object sampe   : 263           10         10          test := info.data + " " 

I’ve checked the gjson for outstanding bugs related to the get, but didn’t find anything.
I’ve checked the code in a debugger to verify that the result does not contain any pointers to the test variable.

Questions:

  • Am I interpreting the profiling results correctly? Is the test variable still residing on the heap after I finish my scenario?

  • Is the code to write the heap profile correct? Do I use it correctly? Does it matter on wich gouroutine the writeheapProfile() function is called?

  • Why would the test variable be retained on the heap? (I do not see any reference to it anymore)

  • Is this behavior indicative of a memory leak?

  • Why would the GC not clean-up the test variable in all cases? What could explain why the variable is not cleaned up in 10 / 1344 cases?

  • Does this indicate a bug in the gjson library?

Thanks in advance for any help.

have you tried
go build -gcflags="-m"
To look at the escape analysis?

The question in your title is clear: Why is this variable retained on the heap? The questions in your your text in this and your previous question reflect your (incorrect?) assumptions about the Go garbage collector and tools.

You need to understand how garbage collection in general and in Go in particular work. You also need to understand how the Go tools work.

The first question to answer is what is your go version. Go is optimized and is subject to continuous change. For example, the upcoming version introduces a new and improved memory management technique.

The next question to answer is what Go tool to use. pprof uses sampling to identify hot spots in a program. For stack and heap allocations, start with the Go compiler. For a basic introduction to allocations (in 2019), watch this video:

Understanding Allocations: the Stack and the Heap - GopherCon SG 2019.

What results did you get? Can you explain them?

I’m forced to use a quite old version:

go version go1.10.1 linux/amd64

Thank you for the link, it confirmed what I assumed.

I have now, it took me a while to figure out how to do it on all files not just the main.go.

I changed

   go build -gcflags "-m=2 -l"  directory_name
   go build -gcflags "-m=2 -l"  ./... 

The escape analysis clearly states that the string i create escapes to the heap.

info.data + " " escapes to heap

I’m still not sure why. The data is not shared upwards, only downwards. The link given by petrus, suggest that size can play a role here. (The data is larger then 2kb) But I thought the stack would grow to accommodate this.

Below graph indicates the number of objects (info.data + " ") that are stored on the heap for each call that is made to the Values() function. This information is gotten by taking the memprofile difference between @init and after each call to the Values() function

I assumed that each call to runtime.GC() (called for each unit on the X-axis) would clean up all unused data on the heap. The graph tells me that this is simply not true. It shows that some objects are cleaned up at a later point in time.

I probably need to take a look at the Garbage collector workings for my Go version.

So my question from the original thread remains.
Is the behavior I am seeing a memory leak or an effect of the Garbage Collector inner workings.

Best regards

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.