One of my long-running problems with Rails (and Ruby in general) is that it’s difficult to debug memory leaks. I’ve had a number of cases where I’ve stuck something into a long-lived array or hash and discovered much later that my Ruby process was eating over 100 MB of RAM. While ps makes it easy to see when Ruby’s using lots of RAM, actually figuring out where it went is a lot harder.

Several people have been working on memory leak debuggers for Rails, and for Typo in general, including Steve Longdo, but I didn’t have a lot of luck actually finding leaks with their tools. I asked the Seattle Ruby Group for help, and Ryan Davis gave me a quick little memory leak spotter that he uses. I made a few additions to it, and it helped me discover that my Typo development tree was leaking 1-3 strings per hit, but it didn’t help me figure out where the leak was happening. After playing with a few options, I settled on dumping all strings to a file once per memory profiler loop, and then I diffed the files that showed my problem. It took about 15 seconds to discover a bug in my route cache code, and about 30 seconds more to fix it.

I’ll package this up as a Rails plugin eventually, but I thought it might be worth sharing here for now. Just load this code and then call MemoryProfiler.start. By default it logs a record of the 20 classes with the biggest changes over the last 10 seconds; you can change the cycle speed by adding :delay => 20 to the start command, and you can dump all strings to a file on each loop by adding :string_debug => true. Don’t leave string debugging on for too long; it’ll eat a ton of disk space.

class MemoryProfiler
  DEFAULTS = {:delay => 10, :string_debug => false}
  
  def self.start(opt={})
    opt = DEFAULTS.dup.merge(opt)

    Thread.new do
      prev = Hash.new(0)
      curr = Hash.new(0)
      curr_strings = []
      delta = Hash.new(0)
    
      file = File.open('log/memory_profiler.log','w')
    
      loop do
        begin
          GC.start
          curr.clear
          
          curr_strings = [] if opt[:string_debug]
          
          ObjectSpace.each_object do |o|
            curr[o.class] += 1 #Marshal.dump(o).size rescue 1
            if opt[:string_debug] and o.class == String
              curr_strings.push o
            end
          end

          if opt[:string_debug]
            File.open("log/memory_profiler_strings.log.#{Time.now.to_i}",'w') do |f|
              curr_strings.sort.each do |s|
                f.puts s
              end
            end
            curr_strings.clear
          end

          delta.clear
          (curr.keys + delta.keys).uniq.each do |k,v|
            delta[k] = curr[k]-prev[k]
          end

          file.puts "Top 20"
          delta.sort_by { |k,v| -v.abs }[0..19].sort_by { |k,v| -v}.each do |k,v|
            file.printf "%+5d: %s (%d)\n", v, k.name, curr[k] unless v == 0
          end
          file.flush

          delta.clear
          prev.clear
          prev.update curr
          GC.start
        rescue Exception => err
          STDERR.puts "** memory_profiler error: #{err}"
        end
        sleep opt[:delay]
      end
    end
  end
end

As usual, the good bits are Ryan’s, and the bad bits are mine.