Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Memory leak? #61

Open
yuui opened this issue May 28, 2014 · 8 comments
Open

Memory leak? #61

yuui opened this issue May 28, 2014 · 8 comments

Comments

@yuui
Copy link

yuui commented May 28, 2014

I wrote a snippet with zookeeper gem, and got some kind of memory leak problem.

Ruby version:

ruby 2.1.2p95 (2014-05-08 revision 45877) [x86_64-darwin12.0]

Gem version:

zookeeper (1.4.8)

Zookeeper server installed with Homebrew:

zookeeper: stable 3.4.6 (bottled), HEAD
$ irb
irb(main):001:0> require 'zookeeper'
=> true
irb(main):002:0> cli = Zookeeper.new("localhost:2181")
=> #<Zookeeper::Client:0x007fd7648aedd0 @host="localhost:2181", ...

At this time, I see this irb process uses 12.4MB memory with Activity Monitor on OS X.
And I run the following code:

rb(main):003:0> loop { cli.get_chidldren(path: "/") }

Then the memory size rises and rises to 17.1MB beyond 12.4MB while running.
I stop this infinite loop with Ctrl+C after about 10 second from starting, but Activity Monitor keeps showing 17.1MB.

Is this some memory leak? Or another reason?

@eric
Copy link
Member

eric commented May 28, 2014

Does the growth ever stop? If you run GC.start after each iteration does it make a difference?

On Tue, May 27, 2014 at 7:00 PM, Masanori Tanaka [email protected]
wrote:

I wrote a snippet with zookeeper gem, and got some kind of memory leak problem.
Ruby version:

ruby 2.1.2p95 (2014-05-08 revision 45877) [x86_64-darwin12.0]

Gem version:

zookeeper (1.4.8)

Zookeeper server installed with Homebrew:

zookeeper: stable 3.4.6 (bottled), HEAD
$ irb
irb(main):001:0> require 'zookeeper'
=> true
irb(main):002:0> cli = Zookeeper.new("localhost:2181")
=> #<Zookeeper::Client:0x007fd7648aedd0 @host="localhost:2181", ...

At this time, I see this irb process uses 12.4MB memory with Activity Monitor on OS X.
And I run the following code:

rb(main):003:0> loop { cli.get_chidldren(path: "/") }

Then the memory size rises and rises to 17.1MB beyond 12.4MB while running.
I stop this infinite loop with Ctrl+C after about 10 second from starting, but Activity Monitor keeps showing 17.1MB.

Is this some memory leak? Or another reason?

Reply to this email directly or view it on GitHub:
#61

@yuui
Copy link
Author

yuui commented May 28, 2014

Yes, the growth itself stopped after aborting the loop. I tried GC.start after loop stopped, but nothing changed on memory use.

@eric
Copy link
Member

eric commented May 28, 2014

Can you put the GC.start inside the loop?

On Tue, May 27, 2014 at 7:10 PM, Masanori Tanaka [email protected]
wrote:

Yes, the growth itself stopped after aborting the loop. I tried GC.start after loop stopped, but nothing has changed on memory use.

Reply to this email directly or view it on GitHub:
#61 (comment)

@yuui
Copy link
Author

yuui commented May 28, 2014

Thanks, eric. I have tried the following:

irb(main):004:0> loop { cli.get_children(path: "/"); GC.start }

The memory growth got very slow than before! But it was increasing slightly yet, and the memory use remained after aborting the loop. Hmm...

@yuui
Copy link
Author

yuui commented May 28, 2014

For more investigation, I sampled proc_map of the irb process (before and after running iteration) with GDB on my Linux box and got a difference:

$ diff proc_map_before.txt proc_map_after.txt
127c127
< 7f62da9e5000-7f62dbddf000 rw-p 00000000 00:00 0                          [heap]
---
> 7f62da9e5000-7f62dc072000 rw-p 00000000 00:00 0                          [heap]

Only heap memory area has been widen.

@yuui
Copy link
Author

yuui commented May 28, 2014

Additionally, I did profiling by looping 100000 times with GC::Profiler:

irb(main):001:0> GC::Profiler.enable; require 'zookeeper'; cli = Zookeeper.new("localhost:2181"); 100000.times { cli.get_children(path: "/") }; puts GC::Profiler.result
GC 457 invokes.
Index    Invoke Time(sec)       Use Size(byte)     Total Size(byte)         Total Object                    GC Time(ms)
    1               0.110               797800              1321920                33048         1.38500000000002509992
    2               0.118               944200              1321920                33048         0.97899999999986886401
    3               0.154               985640              2366400                59160         2.88799999999994616573
    4               0.189               986320              2366400                59160         2.71200000000004770584
    5               0.225               987840              2366400                59160         2.60099999999996445155
    6               0.260               989040              2366400                59160         2.52199999999969115549
    7               0.295               990880              2366400                59160         2.43199999999960114749
    8               0.331               992320              2366400                59160         2.41299999999994296829
    9               0.366               993880              2366400                59160         2.44600000000044781601
   10               0.402               994600              2366400                59160         2.47400000000014275159

(...snip...)

  354              12.200              1195960              2366400                59160         2.16799999998684711500
  355              12.230              1196920              2366400                59160         2.18900000000132877176
  356              12.260              1198160              2366400                59160         2.13799999999508827386
  357              12.290               877160              2366400                59160         5.15099999999257818217
  358              12.330               878400              2366400                59160         2.61199999999028875663

(...snip...)

  442              15.437               986840              2366400                59160         2.80300000000366367203
  443              15.473               988320              2366400                59160         2.49699999999997146460
  444              15.508                    0                    0                    0         1.55600000000255533905
=> nil

@yuui
Copy link
Author

yuui commented May 28, 2014

Does this have something to do with the problem?

Memory leaks in zoo_multi API
https://issues.apache.org/jira/browse/ZOOKEEPER-1562

Above was fixed in Zookeeper Client library version 3.4.6.

@yuui
Copy link
Author

yuui commented May 28, 2014

I applied the ZOOKEEPER-1562 patch, built gem and used it on my forked develop branch.
Plus, using GC.start within loop block, memory leak doesn't happen almost (not 100%) any more!

irb(main):106:0> ObjectSpace.each_object(Zookeeper::Continuation).each { |c| c.inspect }
=> 104

When I inspect heap memory, it seems Zookeeper::Continuation objects remain after exiting from loop block. Would it be a cause to release objects by running GC.start within loop block?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants