Up to Main Index Up to Journal for May, 2012
JOURNAL FOR TUESDAY 1ST MAY, 2012
______________________________________________________________________________
SUBJECT: Oh bother ... don't think it's my memory leak :(
DATE: Tue May 1 22:14:11 BST 2012
So I'm still chasing memory leaks. Going through my code adding lots of
debugging, making the code a mess *sigh*
Now I've come up with a simple test case:
- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - ->8 - - - -
package main
import (
"net"
"os"
"runtime"
"runtime/pprof"
)
func main() {
ln, err := net.Listen("tcp", "localhost:4001")
if err != nil {
println("Listen Error")
return
}
m := new(runtime.MemStats)
oa, oho := uint64(0), uint64(0)
oi := 0
for i := 0; i < 10000; i++ {
if conn, err := ln.Accept(); err != nil {
println("Accept error")
return
} else {
conn.Close()
runtime.GC()
runtime.ReadMemStats(m)
if oa != m.Alloc || oho != m.HeapObjects {
// Print #connections, #connections since last Alloc/HeapObjects
// change, current Alloc and HeapObjects
println("Connected", i, (i - oi), m.Alloc, m.HeapObjects)
oi, oa, oho = i, m.Alloc, m.HeapObjects
}
}
}
f, err := os.Create("memprof")
pprof.WriteHeapProfile(f)
f.Close()
}
- - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - - ->8 - - - -
It just accepts a connection and closes it. I've been testing it with 10001
connections using:
seq 1 10001 | xargs -iz telnet 127.0.0.1 4001
A sample run displays:
Connected 0 0 344400 337
Connected 1 1 345072 339
Connected 3 2 345744 341
Connected 8 5 346416 343
Connected 580 572 417776 346
Connected 1392 812 417968 347
Connected 2142 750 418160 348
Connected 2768 626 418336 349
Connected 4259 1491 418512 350
Connected 4326 67 418688 351
Connected 4927 601 418880 352
Connected 6261 1334 419056 353
Connected 6990 729 419232 354
Connected 7113 123 419408 355
Connected 7822 709 419584 356
Connected 7897 75 419792 357
Connected 8460 563 419968 358
In the 3rd column you can see the allocated memory rising and in the 4th
column you can see the number of HeapObjects rising.
Using pprof to look at the memory profile the program writes out at the end we
can see where the object allocations are:
$pprof --inuse_objects tester memprof
Adjusting heap profiles for 1-in-524288 sampling rate
Welcome to pprof! For help, type 'help'.
(pprof) top
Total: 10922 objects
10922 100.0% 100.0% 10922 100.0% os.NewFile
0 0.0% 100.0% 10922 100.0% main.main
0 0.0% 100.0% 10922 100.0% net.(*TCPListener).Accept
0 0.0% 100.0% 10922 100.0% net.(*TCPListener).AcceptTCP
0 0.0% 100.0% 10922 100.0% net.(*netFD).accept
0 0.0% 100.0% 10922 100.0% net.(*netFD).setAddr
0 0.0% 100.0% 10922 100.0% runtime.main
0 0.0% 100.0% 10922 100.0% schedunlock
Ok, so all the allocations are in os.NewFile, lets look at that:
(pprof) list os.NewFile
Total: 10922 objects
ROUTINE ====================== os.NewFile in /usr/local/go/src/pkg/os/file…
10922 10922 Total objects (flat / cumulative)
. . 34: }
. . 35: return uintptr(f.fd)
. . 36: }
. . 37:
. . 38: // NewFile returns a new File with the given file descr…
---
. . 39: func NewFile(fd uintptr, name string) *File {
. . 40: fdi := int(fd)
. . 41: if fdi < 0 {
. . 42: return nil
. . 43: }
10922 10922 44: f := &File{&file{fd: fdi, name: name}}
. . 45: runtime.SetFinalizer(f.file, (*file).close)
. . 46: return f
---
. . 47: }
. . 48:
. . 49: // Auxiliary information if the File describes a direct…
. . 50: type dirInfo struct {
. . 51: buf []byte // buffer for directory I/O
(pprof) quit
Looks like the finalizers are not running to release the File objects :( I've
tried adding runtime.Gosched(), runtime.GC() and time.Sleep() all over the
place, even changing GOMAXPROCS > 1, but nothing seems to work ... might be
time to file a bug?
--
Diddymus
Up to Main Index Up to Journal for May, 2012