Paluy on Miscellaneous

Of course I'm an optimist - I don't see much point in being anything else. - Winston Churchill

Debugging Rails Application - Part 2

In previous post, I described which tools I use for debugging Rails (Ruby) applications.

In this post I will show you how to debug your Garbage Collector.

Why should I debug my GC?

First, you should understand how ruby allocates memory for new objects. What happened inside your OS, each time you write book = Book.new?

How Ruby Memory Works

RVM defines Process Heap for each Ruby process. Than, it creates first Ruby Heap. Each Ruby Heap contains allocated objects. There is a “Free List” array inside the heap.

Ruby Heap - Free List

While new object allocated, the RVM looks for an empty place in “Free List” and allocates it for a newly creted one. If the “Free List” is empty (all slots are allocated), RVM calls to Garbage Collector (GC).

The Garbage Collector finds non-reachable objects and remove them. If “Free List” is still empty, another Heap allocated.

Conclusion: The more objects we have, the longer GC process. And it’s a cause for slow application.

How should I debug my GC?

I suggest to use pry-debugger.

There are several tools we can use while debugging:

  • ObjectSpace class
  • Heap dump (via GC patch)

But to get it all functionality you need to use patched version of Ruby.

To enable heap dump support, pass the -enable-gcdebug option to the rvm install command:

1
rvm install 1.9.3 -C --enable-gcdebug -n gcdebug

ObjectSpace class

An example of method I used to get a better output:

1
2
3
4
5
6
7
8
9
10
11
12
13
def get_object_stats
  return_value = Hash.new
  ObjectSpace::each_object(Object) {|my_object|
    unless return_value[my_object.class.to_s.downcase].nil?
      return_value[my_object.class.to_s.downcase][:count] += 1
    else
      return_value[my_object.class.to_s.downcase] = Hash.new
      return_value[my_object.class.to_s.downcase][:name] = my_object.class
      return_value[my_object.class.to_s.downcase][:count] = 1
    end
  }
  return_value.sort_by {|k,v| -v[:count]}
end

Source

Heap dump

1
2
3
4
5
6
7
8
GC.enable_stats if defined?(GC) && GC.respond_to?(:enable_stats)
GC.start # clean up heap
# ...
# YOUR CODE GOES HERE
# ...
# dump it, including class names of heap objects
GC.dump_file_and_line_info(filename: "heap.dump", include_class_names: true)
stat_string = "allocated: #{GC.allocated_size/1024}K total in #{GC.num_allocations} allocations, GC calls: #{GC.collections}, GC time: #{GC.time / 1000} msec"

Other interesting solutions to check:

Note: the memprof works only with Ruby 1.8.x

My slides at RubyUnderground

Comments