Object#extend leaks memory on Ruby 1.9.1

The Garbage Collector is really strange business in the Ruby land. For me, it is the major performance drain currently. If you are not aware of the limitations here’s a list:

  1. The GC is mark and sweep, it needs to scan the whole heap for each run. It is directly affected by heap size O(n).
  2. The GC cannot be interrupted and hence all threads must wait for it to finish (shameful pause on big heaps).
  3. The GC marks objects in the objects themselves destroying any value of copy on write.
  4. The GC does not (edit: usually) give memory back to the system. What goes in does not (edit: usually) go out.
  5. It is a bit on the conservative side. Meaning garbage can stay because it is not sure that it is so.

Needless to say, some of these are being addressed, specially 3 and 5. But the patches are not yet accepted in the current Ruby release. I believe though that they will find their way to 1.8.x which is being maintained by Engine Yard. The EY guys are really working hard to solve the issues of Ruby as a server platform which is the most popular use for it today thanks to Rails.

Alas, my issue today involves Ruby 1.9.1 (it does not affect 1.8.x). See I have built this toy server to experiment with multi process applications and some Unix IPC facilities. I did make the design a bit modular to make it easier to test and debug different aspects of the stack. So I have these tcp, http handler modules that extend the connection object (a socket) whenever a connection is accepted. Here’s a sample:

conn = server_socket.accept
conn.extend HttpHandler
..
..

This worked really great and I was even able to chain handlers to get more stack functionality (a handler will simply include those that it requires). This worked great, until I looked at memory usage.

I discovered that after showering the server with requests it will start to grow in size. This is acceptable as it is making way for new objects. But given the way the GC works it should have allocated enough heap locations after a few of those ab runs. On the contraty, even when I am hitting the same file with ab the server keeps growing. After 10 or more ab runes (each doing 10000 requests) it is still consuming more memory. So I suspected there is a leak some where. I tested a hello world and found that the increase was very consistent. Every 10K requests the process gains 0.1 to 0.2 MB. (10 to 20 Bytes per request). So I started removing components one after another till I was left with a bare server that only requires socket and reactor.

 

When I tested that server the process started to gain memory then after like 3 or 4 ab runs it stabilized. It would no longer increase its allocated memory no matter how many times I run ab on it. So the next logical move was to re-insert the first level of the stack (the tcp handler module). Once I did that the issue started appearing again. So the next test was to disable the use of the tcp handler but still decorate my connections with it. The issue still appeared. Since the module is not overriding Module.extended to do any work upon it extending an object it became clear that it is the guilty party.

Instead of Object#extend I tried reopening the BasicSocket class and including the required module there. After doing that memory usage pattern resembled the bare bones server. It would increase for a few runs and then remain flat as long as you are hitting the same request.

To isolate the problem further I created this script:

# This code is Ruby 1.9.x and above only

@extend = ARGV[0]

module BetterHash
  def blabla
  end
end

unless @extend
  class Hash
  include BetterHash
  end
end

t = Time.now
1_000_000.times do
  s = {}
  s.extend BetterHash if @extend 
end
after = Time.now - t
puts "done with #{GC.count} gc runs after #{after} seconds"
sleep # so that it doesn't exit before we check the memory

using extend:

351 GC runs, 9.108 seconds, 18.7 MB

using include:

117 GC runs, 0.198 seconds, 2.8 MB

Besides being much faster, the resulting process was much smaller. Around 16MB smaller. I am suspecting that the leak is around 16 bytes or a little less per extend invokation. This means that a server that uses a single extend per request will increase around 160KB in size after every 10K requests. Not that huge but it will pile up fast if left for a while and the server is under heavy load. 

A quick grep in Rails sources showed that this pattern is being used heavily throughout the code. But it is used to extend base classes rather than objects. Hence it will not be invoked on every request and the effect will be mostly limited to the initial start size (a few bytes actually). You should avoid using it dynamically at request serving time though, till it gets fixed.

 

About these ads

13 responses to this post.

  1. Posted by Lourens Naudé on April 18, 2009 at 10:28 pm

    Muhammad,Great investigation, however also factor rb_cache_clear overhead in, which fires on extend, for the results snippet.One definitely won’t want to use extend or include in a loop as each of those affects all, or a chunk, of mri’s method cache.More details on this in the next few days.- Lourens

    Reply

  2. Posted by oldmoe on April 18, 2009 at 10:46 pm

    I am eagerly awaiting your Ruby instrumentation tools Lourens.

    Reply

  3. Posted by José Valim on April 19, 2009 at 7:46 am

    Great post Muhammad!What concerns me the most is not the extend leaking, which might be fixed soon, but the fact that GC patches will likely arrive first to Ruby 1.8.6.Of course, kudos to Engine Yard to taking care of it, but we have to be sure that the community will be motivated to jump to 1.9 as soon as possible.

    Reply

  4. Posted by Hongli Lai on April 19, 2009 at 9:52 am

    “The GC does not give memory back to the system. What goes in does not go out.”I’m pretty sure it does give memory back to the system. Ruby will free a heap if it’s empty, using free() (at which point it would be up to free() to decide whether to return that memory to the system or not).The problem is that often the heap is fragmented, so you end up with lots of heaps that are not entirely empty, and they keep occupying space.

    Reply

  5. Posted by oldmoe on April 19, 2009 at 11:03 am

    @Jose, I do hope this happens as well, but look at the brighter side, if EY incorporates the fixes in 1.8.6 the 1.9 team will be more tempted to do so as well.@Hongli, I must say that I was not 100% sure about Ruby never releasing memory. In all cases, I believe that even a Mark and Sweep GC can benefit a lot from compaction if this leads to it releasing more memory to the host OS (or keeping it around but excluding it from the GC overhead). Seems to be a good addition to REE or what do you think?

    Reply

  6. Posted by Hongli Lai on April 19, 2009 at 12:20 pm

    Yes it would. I believe some researcher managed to implement compaction while keeping the GC conservative, but I haven’t heard of him ever since he gave his presentation on some Ruby conference.

    Reply

  7. Posted by morshdy on April 21, 2009 at 6:43 pm

    Typo: replacing right with write will make it all right.

    Reply

  8. Posted by oldmoe on April 22, 2009 at 10:53 am

    morshdy! thanks for the tip, where on earth are you now? long time no see

    Reply

  9. Posted by Carl on April 25, 2009 at 1:31 am

    10 to 20 Bytes is 0.00001 to 0.00002 MB, not 0.1 to 0.2 MB.

    Reply

  10. Posted by oldmoe on April 25, 2009 at 11:37 am

    10 to 20 Bytes per request. The 0.1 to 0.2 MB increase is after every 10,000 requests.

    Reply

  11. Posted by Con on April 28, 2009 at 2:16 pm

    Which platform did you run the example Ruby script?

    Reply

  12. Posted by oldmoe on April 28, 2009 at 2:43 pm

    @conruby -v: ruby 1.9.1p0 (2009-01-30 revision 21907) [i686-linux]

    Reply

  13. Posted by Roger Pack on July 5, 2009 at 3:20 am

    I think this ended up not being a bug is that right?=r

    Reply

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

Follow

Get every new post delivered to your Inbox.

%d bloggers like this: