encoding/gob: Encode() memory leak? #2067

gopherbot · 2011-07-13T03:50:20Z

by christopher.helck:

What steps will reproduce the problem?
1. Compile and run the attached program.
2.
3.

What is the expected output?
The program simply saves the same data structure over and over again. It should run for
a very long time.


What do you see instead? Memory dump
It runs out of memory. I suspect that either gob.Encode has a leak, or my data structure
is bad. 

runtime: memory allocated by OS not in usable range
runtime: out of memory: cannot allocate 4390912-byte block (536084480 in use)
throw: out of memory

runtime.throw+0x43 /home/chris/go/src/pkg/runtime/runtime.c:102
    runtime.throw(0x8125085, 0x430)
runtime.mallocgc+0x2cd /home/chris/go/src/pkg/runtime/malloc.c:60
    runtime.mallocgc(0x42ffff, 0x1, 0x1, 0x1, 0x8137b98, ...)
makeslice1+0x71 /home/chris/go/src/pkg/runtime/slice.c:46
    makeslice1(0x809b92c, 0x42ffff, 0x42ffff, 0xcf8c7c, 0x1, ...)
runtime.makeslice+0x95 /home/chris/go/src/pkg/runtime/slice.c:26
    runtime.makeslice(0x809b92c, 0x42ffff, 0x0, 0x42ffff, 0x0, ...)
bytes.*Buffer·grow+0x13e /home/chris/go/src/pkg/bytes/buffer.go:85
    bytes.*Buffer·grow(0x977d289c, 0x1, 0x217ffd, 0x80603ff)
bytes.*Buffer·WriteByte+0x3c /home/chris/go/src/pkg/bytes/buffer.go:182
    bytes.*Buffer·WriteByte(0x977d289c, 0x217f00, 0x806ec29, 0x977d289c)
gob.*encoderState·encodeUint+0x46 /home/chris/go/src/pkg/gob/encode.go:56
    gob.*encoderState·encodeUint(0x97f5e360, 0x0, 0x0)
gob.encStructTerminator+0x39 /home/chris/go/src/pkg/gob/encode.go:328
    gob.encStructTerminator(0x97f5d2e0, 0x97f5e360, 0x97f02d78)
gob.*Encoder·encodeStruct+0xde /home/chris/go/src/pkg/gob/encode.go:371
    gob.*Encoder·encodeStruct(0x977d2870, 0x977d289c, 0x97f5b840, 0x97f02d78, 0x97f5e1f4, ...)
gob._func_016+0x5f /home/chris/go/src/pkg/gob/encode.go:573
    gob._func_016(0x97e4cb18, 0x8061316, 0x97f5d310, 0x97f5e340, 0x97f02d78, ...)
gob.*Encoder·encodeStruct+0xde /home/chris/go/src/pkg/gob/encode.go:371
    gob.*Encoder·encodeStruct(0x977d2870, 0x977d289c, 0x97f5b820, 0x97f02d70, 0x97f5e2f4, ...)
gob._func_016+0x5f /home/chris/go/src/pkg/gob/encode.go:573
    gob._func_016(0x97e4ccf8, 0x8061419, 0x0, 0x97f5e320, 0x97f02d70, ...)
gob.*Encoder·encodeArray+0xf9 /home/chris/go/src/pkg/gob/encode.go:391
    gob.*Encoder·encodeArray(0x977d2870, 0x977d289c, 0x97f04238, 0x97f5e2e0, 0x4, ...)
gob._func_013+0xdb /home/chris/go/src/pkg/gob/encode.go:542
    gob._func_013(0x97e4ccd8, 0x97e4ccd0, 0x97e4cce0, 0x806154e, 0x0, ...)
gob.encodeReflectValue+0xfc /home/chris/go/src/pkg/gob/encode.go:405
    gob.encodeReflectValue(0x97f5e300, 0x809b488, 0xa5371160, 0x0, 0x978253c0, ...)
gob.*Encoder·encodeMap+0x130 /home/chris/go/src/pkg/gob/encode.go:419
    gob.*Encoder·encodeMap(0x977d2870, 0x977d289c, 0x809bbe4, 0x97b76a50, 0x0, ...)
gob._func_015+0x113 /home/chris/go/src/pkg/gob/encode.go:564
    gob._func_015(0x97e4cc98, 0x97e4cca0, 0x97e4ccb8, 0x97e4cca8, 0x97e4ccc0, ...)
gob.*Encoder·encodeStruct+0xde /home/chris/go/src/pkg/gob/encode.go:371
    gob.*Encoder·encodeStruct(0x977d2870, 0x977d289c, 0x97f5b7c0, 0x97826780, 0x80b7a18, ...)
gob.*Encoder·encode+0x144 /home/chris/go/src/pkg/gob/encode.go:687
    gob.*Encoder·encode(0x977d2870, 0x977d289c, 0x80b7a10, 0x97826750, 0x0, ...)
gob.*Encoder·EncodeValue+0x1b8 /home/chris/go/src/pkg/gob/encoder.go:236
    gob.*Encoder·EncodeValue(0x977d2870, 0x80b7a10, 0x97826750, 0x0, 0x0, ...)
gob.*Encoder·Encode+0x46 /home/chris/go/src/pkg/gob/encoder.go:168
    gob.*Encoder·Encode(0x977d2870, 0x80b7a10, 0x97826750, 0x977c8960, 0x2, ...)
main.save+0xbf /home/chris/gotest/src/gobble/memory/main.go:101
    main.save(0x977d75d0, 0x0, 0x0)
main.main+0x3f /home/chris/gotest/src/gobble/memory/main.go:109
    main.main()
runtime.mainstart+0xf /home/chris/go/src/pkg/runtime/386/asm.s:93
    runtime.mainstart()
runtime.goexit /home/chris/go/src/pkg/runtime/proc.c:178
    runtime.goexit()



Which compiler are you using (5g, 6g, 8g, gccgo)? 8g


Which operating system are you using?
Linux Lime 32 bit


Which revision are you using?  (hg identify)
16bfa562ba76 weekly/weekly.2011-07-07



Please provide any additional information below.

I've noticed that when I keep the arrays of pointers fairly small there is no leak. It's
only when they get bigger. When I have time I'll try to stream line this program. As is,
it is pretty close to my application that has this problem (except my app has 100,000+
Rectangles)

Attachments:

main.go (2161 bytes)

gopherbot · 2011-07-14T01:13:17Z

Comment 1 by christopher.helck:

I have created a simpler example that I've attached along with the output (gobble.txt).
Problem seem very size sensitive. The program has a few loops that setup the initial
data which is then saved over and over again. I've made the loop sizes as small as I
can, while still having the program fail. It is possible that someone with different
memory or hardware will need to adjust the loop counts. Basically err on the side of big.
Failure is consistent. If it fails once it will always fail.
One thing that is weird, the data file that is successfully written is very small
<300 bytes. My sense is that the object being saved should be much bigger.

Attachments:

main.go (1511 bytes)
gobble.txt (1660 bytes)

gopherbot · 2011-07-19T03:58:57Z

Comment 2 by christopher.helck:

One last comment. If I add runtime.GC() inside the main loop, the problem goes away. So
perhaps this is a GC issue.

gopherbot · 2011-07-24T04:16:13Z

Comment 3 by christopher.helck:

I have a greatly simplified the program that produces the same problem:
---------------------------
package main
import (
    "gob"
    "os"
    "runtime"
)
type Pile map[int][]int
func NewPile() *Pile {
    p := make(Pile)
    for i := 0; i<50000; i++ {
        p[i] = append(p[i], 16)
    }
    return &p
}
func save(pile *Pile) os.Error {
    f, _ := os.Create("/dev/null")
    defer f.Close()
    encoder := gob.NewEncoder(f)
    return encoder.Encode(*pile)
}
func main() {
    pile := NewPile()
    for {
        save(pile)
    }
    runtime.GC()                 // Move this inside loop for more detail
}
--------------------------------------
I run with GOGCTRACE enabled. I've modified malloc.goc so the trace prints the before
and after heap size in bytes, not MBytes. Here is the output:
-----------------------------------------------
gc1: 0+0+0 ms 96640 -> 95824 Bytes 931 -> 865 (931-66) objects 493 pointer lookups
(477 size, 16 addr)
gc2: 0+0+0 ms 367264 -> 365280 Bytes 2968 -> 2927 (3034-107) objects 701 pointer
lookups (617 size, 84 addr)
gc3: 4+0+0 ms 732232 -> 732232 Bytes 15754 -> 15754 (15861-107) objects 7606
pointer lookups (4064 size, 3542 addr)
gc4: 2+0+0 ms 1466264 -> 1466264 Bytes 38411 -> 38411 (38518-107) objects 8914
pointer lookups (4714 size, 4200 addr)
gc5: 3+0+0 ms 2935936 -> 2796032 Bytes 72752 -> 63652 (72859-9207) objects 8994
pointer lookups (4760 size, 4234 addr)
gc6: 4+6+0 ms 6173296 -> 4102216 Bytes 204690 -> 63691 (213897-150206) objects
9033 pointer lookups (4770 size, 4263 addr)
gc7: 5+8+0 ms 8209064 -> 5388472 Bytes 248997 -> 63718 (399203-335485) objects
9041 pointer lookups (4772 size, 4269 addr)
gc8: 6+12+0 ms 10778976 -> 6912512 Bytes 322731 -> 63748 (658216-594468) objects
9057 pointer lookups (4777 size, 4280 addr)
gc9: 7+13+0 ms 13829464 -> 9271944 Bytes 363864 -> 63782 (958332-894550) objects
9099 pointer lookups (4781 size, 4318 addr)
gc10: 9+16+0 ms 18800728 -> 13089632 Bytes 444930 -> 63837 (1339480-1275643)
objects 9156 pointer lookups (4789 size, 4367 addr)
gc11: 12+24+0 ms 26297760 -> 18025816 Bytes 626354 -> 63923 (1901997-1838074)
objects 9228 pointer lookups (4801 size, 4427 addr)
gc12: 15+34+0 ms 36199752 -> 24412032 Bytes 851764 -> 64027 (2689838-2625811)
objects 9330 pointer lookups (4814 size, 4516 addr)
gc13: 21+49+0 ms 48828304 -> 32676536 Bytes 1116077 -> 64176 (3741888-3677712)
objects 9514 pointer lookups (4834 size, 4680 addr)
gc14: 39+64+0 ms 65942248 -> 44057552 Bytes 1487501 -> 64374 (5165213-5100839)
objects 9697 pointer lookups (4863 size, 4834 addr)
gc15: 47+100+0 ms 88115592 -> 58946240 Bytes 1990836 -> 64640 (7091675-7027035)
objects 9966 pointer lookups (4897 size, 5069 addr)
gc16: 47+114+0 ms 117895344 -> 79621232 Bytes 2594030 -> 64981 (9621065-9556084)
objects 10334 pointer lookups (4944 size, 5390 addr)
gc17: 62+151+0 ms 159322216 -> 108207376 Bytes 3486504 -> 65459
(13042588-12977129) objects 10823 pointer lookups (5006 size, 5817 addr)
gc18: 82+208+0 ms 216417552 -> 146541504 Bytes 4731204 -> 66120
(17708333-17642213) objects 11447 pointer lookups (5091 size, 6356 addr)
gc19: 113+273+0 ms 293086192 -> 198624832 Bytes 6376653 -> 67055
(24018866-23951811) objects 12441 pointer lookups (5209 size, 7232 addr)
gc20: 153+429+0 ms 397252440 -> 269071360 Bytes 8621778 -> 68264
(32573589-32505325) objects 13779 pointer lookups (5365 size, 8414 addr)
runtime: memory allocated by OS not in usable range
runtime: memory allocated by OS not in usable range
runtime: out of memory: cannot allocate 65536-byte block (536870912 in use)
throw: out of memory
runtime.throw+0x43 /home/chris/go/src/pkg/runtime/runtime.c:102
    runtime.throw(0x8119080, 0x20)
runtime.MCache_Alloc+0x8f /home/chris/go/src/pkg/runtime/mcache.c:26
    runtime.MCache_Alloc(0x38f000, 0x2, 0x10, 0x1, 0xb77cfff0, ...)
runtime.mallocgc+0xeb /home/chris/go/src/pkg/runtime/malloc.c:36
    runtime.mallocgc(0x10, 0x0, 0x1, 0x1, 0x806cd05, ...)
runtime.mal+0x43 /home/chris/go/src/pkg/runtime/malloc.c:301
    runtime.mal(0xc, 0x80985b0)
unsafe.New+0x84 /home/chris/go/src/pkg/runtime/iface.c:763
    unsafe.New(0x80b4e1c, 0x80985b0, 0x80b4e1c, 0x80985b0)
reflect.New+0x70 /home/chris/go/src/pkg/reflect/value.go:1679
    reflect.New(0x977e7240, 0x80985b0, 0x0, 0x977e7240)
gob.unsafeAddr+0x74 /home/chris/go/src/pkg/gob/decode.go:1264
    gob.unsafeAddr(0x80985a8, 0xb77cfff0, 0x0, 0xb77ce401, 0x3, ...)
gob.encodeReflectValue+0xdf /home/chris/go/src/pkg/gob/encode.go:405
    gob.encodeReflectValue(0xb6c202a0, 0x80985a8, 0xb77cfff0, 0x0, 0x978522a0, ...)
gob.*Encoder·encodeMap+0x130 /home/chris/go/src/pkg/gob/encode.go:419
    gob.*Encoder·encodeMap(0xb57e7a20, 0xb57e7a4c, 0x809970c, 0x977dd8c0, 0x0, ...)
gob._func_015+0x113 /home/chris/go/src/pkg/gob/encode.go:564
    gob._func_015(0x97abc170, 0x97abc178, 0x97abc190, 0x97abc180, 0x97abc198, ...)
gob.*Encoder·encodeSingle+0xa8 /home/chris/go/src/pkg/gob/encode.go:355
    gob.*Encoder·encodeSingle(0xb57e7a20, 0xb57e7a4c, 0x977de6b0, 0xb760aa50, 0x8099714, ...)
gob.*Encoder·encode+0x181 /home/chris/go/src/pkg/gob/encode.go:689
    gob.*Encoder·encode(0xb57e7a20, 0xb57e7a4c, 0x809970c, 0x977dd8c0, 0x0, ...)
gob.*Encoder·EncodeValue+0x1b8 /home/chris/go/src/pkg/gob/encoder.go:236
    gob.*Encoder·EncodeValue(0xb57e7a20, 0x809970c, 0x977dd8c0, 0x0, 0x0, ...)
gob.*Encoder·Encode+0x46 /home/chris/go/src/pkg/gob/encoder.go:168
    gob.*Encoder·Encode(0xb57e7a20, 0x809970c, 0x977dd8c0, 0x977dd8c0, 0xb6c200a0, ...)
main.save+0xb9 /home/chris/gotest/src/gobble/memory/main.go:25
    main.save(0x977d05f8, 0x0, 0x0)
main.main+0x32 /home/chris/gotest/src/gobble/memory/main.go:31
    main.main()
runtime.mainstart+0xf /home/chris/go/src/pkg/runtime/386/asm.s:93
    runtime.mainstart()
runtime.goexit /home/chris/go/src/pkg/runtime/proc.c:244
    runtime.goexit()
----- goroutine created by -----
_rt0_386+0xc1 /home/chris/go/src/pkg/runtime/386/asm.s:80
-----------------------------------------------
If I change the code and place the runtime.GC() inside the loop then I get lots of lines
like these:
------------------------------------------
gc41: 26+6+0 ms 46841144 -> 44562568 Bytes 214148 -> 64121 (5465242-5401121)
objects 9643 pointer lookups (4840 size, 4803 addr)
gc42: 27+6+0 ms 48057656 -> 45508768 Bytes 214161 -> 64135 (5615282-5551147)
objects 9657 pointer lookups (4843 size, 4814 addr)
gc43: 28+6+0 ms 48930128 -> 46651552 Bytes 214173 -> 64146 (5765320-5701174)
objects 9673 pointer lookups (4844 size, 4829 addr)
------------------------------------------------

rsc · 2011-07-25T17:35:30Z

Comment 4:

Owner changed to @rsc.

Status changed to Accepted.

rsc · 2011-10-06T16:35:21Z

Comment 5:

changeset:   9912:aaf8ddb0c780
user:        Russ Cox <rsc@golang.org>
date:        Sat Oct 01 13:00:53 2011 -0400
summary:     runtime: fix map memory leak

Status changed to Fixed.

gopherbot · 2012-02-16T16:26:35Z

Comment 6 by sbotond:

I have encountered a similar problem in a software I'm developing while using the latest
weekly release (weekly.2010.02.14). So I've "gofixed" the code above
(https://gist.github.com/1845614) and compiled it with the latest weekly release and
I've got the following output:
-------------------------------------------------------
Linux hostname 2.6.38-13-generic #54-Ubuntu SMP Tue Jan 3 13:44:52 UTC 2012 i686 i686
i386 GNU/Linux
runtime: memory allocated by OS not in usable range
runtime: memory allocated by OS not in usable range
runtime: out of memory: cannot allocate 655360-byte block (536870912 in use)
throw: out of memory
goroutine 1 [running]:
reflect.Value.MapKeys(0x80aa62c, 0x32ad53b0, 0x156, 0x80cd1b8, 0x8078cc5, ...)
        /home/sb/go/src/pkg/reflect/value.go:970 +0x130
encoding/gob.(*Encoder).encodeMap(0x24efb380, 0x24efb3a0, 0x80aa62c, 0x32ad53b0, 0x156,
...)
        /home/sb/go/src/pkg/encoding/gob/encode.go:414 +0x5c
encoding/gob._func_015(0x188e2ee8, 0x188e2ef0, 0x188e2f08, 0x188e2ef8, 0x188e2f10, ...)
        /home/sb/go/src/pkg/encoding/gob/encode.go:601 +0x136
encoding/gob.(*Encoder).encodeSingle(0x24efb380, 0x24efb3a0, 0x18638490, 0x32ad53b0,
0x80aa62c, ...)
        /home/sb/go/src/pkg/encoding/gob/encode.go:354 +0xa9
encoding/gob.(*Encoder).encode(0x24efb380, 0x24efb3a0, 0x80aa62c, 0x1861cbc0, 0x150, ...)
        /home/sb/go/src/pkg/encoding/gob/encode.go:729 +0x189
encoding/gob.(*Encoder).EncodeValue(0x24efb380, 0x80aa62c, 0x1861cbc0, 0x150, 0x0, ...)
        /home/sb/go/src/pkg/encoding/gob/encoder.go:246 +0x1fb
encoding/gob.(*Encoder).Encode(0x24efb380, 0x80aa624, 0x1861cbc0, 0x1861cbc0,
0x32ad53a0, ...)
        /home/sb/go/src/pkg/encoding/gob/encoder.go:177 +0x52
main.save(0x18600358, 0x0, 0x0)
        /home/sb/gobl/test.go:24 +0xbd
main.main()
        /home/sb/gobl/test.go:30 +0x32
-------------------------------------------------------
I've tried to increase arena_size in runtime/malloc.goc, but it had no effect.
So it seems to me that the issue is still present on 32 bit architectures.

gopherbot added fixed labels Feb 16, 2012

gopherbot assigned rsc Feb 16, 2012

mikioh changed the title ~~gob.Encode() memory leak?~~ encoding/gob: Encode() memory leak? Feb 26, 2015

golang locked and limited conversation to collaborators Jun 24, 2016

gopherbot added the FrozenDueToAge label Jun 24, 2016

rsc removed their assignment Jun 22, 2022

This issue was closed.

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

encoding/gob: Encode() memory leak? #2067

encoding/gob: Encode() memory leak? #2067

gopherbot commented Jul 13, 2011

gopherbot commented Jul 14, 2011

gopherbot commented Jul 19, 2011

gopherbot commented Jul 24, 2011

rsc commented Jul 25, 2011

rsc commented Oct 6, 2011

gopherbot commented Feb 16, 2012

encoding/gob: Encode() memory leak? #2067

encoding/gob: Encode() memory leak? #2067

Comments

gopherbot commented Jul 13, 2011

gopherbot commented Jul 14, 2011

gopherbot commented Jul 19, 2011

gopherbot commented Jul 24, 2011

rsc commented Jul 25, 2011

rsc commented Oct 6, 2011

gopherbot commented Feb 16, 2012