RubyGems dependency management and memory use... 8

Posted by Steve Longdo Tue, 08 Aug 2006 06:30:00 GMT

I've been looking into the nebulous matter of Rails memory management lately, using Typo4 as my model app. In my research thus far I have noticed that several of the highest memory using items are from the RubyGems library. Particularly the Gem::GemPathSearcher object. After running a few days I have picked up five instances of it taking up nearly 8MB of RAM which is odd because the first time I profiled it there were only four of them. I am not sure why RubyGems needs to be in memory after the app initially loads, especially the ~1.5MB SourceIndex and the 352 Gem::Specification objects for another ~1.6MB. Seems like wiring of any dependencies could be done once at start up. I am not sure if this relates specifically to how Typo uses RubyGems or if all Rails apps incur the memory overhead penalty for RubyGems. If any one with knoweldge of the internal functioning of RubyGems would take the time to educate me on this it would be much appreciated. Also if someone could explain why RubyGems pops up at all since all Typo dependencies are deployed into the vendor folder.

Another one to watch is the slow accumulation of ActiveRecord::ConnectionAdpaters::MysqlColumn, up to 217 instances in memory. Not a particularly large memory hit, but they have steadily grown in number over the last few days. i may swith over to my Postgres database and see if the same thing happens with its connecton adapter.

Finally the allocation of Array objects is interesting. The number of instances in use has gone down by roughly -2000 instances but the memory use of the remaining Arrays has gone up by about 2MB. I need to explode these Arrays and see what they hold and why they stick around so long. Partial output of profiling included below:

Class x852(21194)
Gem::Version x709(24981)
ActiveRecord::ConnectionAdapters::MysqlColumn x217(35410)
Regexp x1343(52312)
Gem::Dependency x309(53743)
Gem::Version::Requirement x662(59168)
Gem::SourceIndex x1(1563056)
Gem::Specification x352(1714117)
Hash x1257(1858255)
String x117204(3869923)
Gem::GemPathSearcher x5(7901012)
Array x6093(11102839)
TOTAL == 28496875

Please do share your experiences with Rails or RubyGems memory use in the comments.
Comments

Leave a response

  1. Daniel about 6 hours later:
    Steve, Can you describe the tools and/or scripts that you're using to do memory profiling for Ruby and Typo? Perhaps I can help by monitoring my Typo installations. Thanks!
  2. Scott Laird about 7 hours later:
    Nice hunting. I'll see what we can do to hunt this down and fix it.
  3. Steve Longdo about 8 hours later:
    Dan - I will do a follow up posting soon with the code I am using to get this information. It is more or less taken from some code on the Ruby mailing list a few years ago. I've just put it inside an admin/controller so I can view the profiling info for the ruby thread that is running.
    I am going to clean up the format a bit and see about getting more detail on dumped items. Ideally make it browseable from an admin page so you can click on the results to dig deeper. I'll provide it as a patch for Typo at that point.
  4. sprewell 3 days later:
    Are you doing this from within webrick, fastcgi, mongrel? Because if this turns out to be environment-dependent, you may not find it if you're not using that environment (I say this because typo seems to stay stable around 29 MB in my ab tests. I haven't tested mongrel but I suspect it's the culprit for memory leaks.). I suggest you first hit all 3 of those with ab and make sure they're all gobbling up memory. If only one of them is, there's your problem.
  5. sprewell 6 days later:
    This might be a FreeBSD issue. I notice you're on textdrive also, which uses FreeBSD. Here's a post in their forums about what's probably the same problem. Testing Typo on textdrive, I find that memory usage jumps 13-16 MB when I access the admin interface and click on the various tabs. I'm unable to reproduce this on my dev box running mac os x.
  6. Steve Longdo 6 days later:
    I've seen the "admin ~10MB spike" behaviour on TextDrive as well.

    On my Mac, using the vanilla ./script/server to start Lightty the virtual memory climbs to 53.3MB right out of the gate. This happens with no page visits or anything. On TextDrive the virtual size starts lower(~33MB) and then climbs, at around ~48MB vitual size it gets killed. Real size rarely crosses 40MB, so I think there are some other issues at work.

    The "~10MB spike" is probably just Ruby allocating more heap which it does in 8MB chunks by default.
  7. sprewell 7 days later:
    According to the Textdrive Acceptable Use Policy, these are the limits on processes:

    * CPU time: 20 minutes
    * Resident memory:48 megabytes
    * Virtual memory: 80 megabytes
    * Open files: 240
    * Running processes: 20

    If your processes are dying at ~48 MB in virtual memory, they're not getting killed by Textdrive (or there's some glitch in the memory-monitoring implementation on your server). I currently have a ruby process running Typo at Textdrive that has a virtual size of 53 MB. In this forum thread at Textdrive, an administrator and some others say that there should be a log file left behind if your process was killed. Do you find any log files when your processes are killed?
  8. Steve Longdo 7 days later:
    A quick way to see this in action is to have lighty setup to manage the fastcgi processes. This was the "recommended setup at TextDrive" for a very long time.
    Then you will get an "awesome" entry in ~/process_watchdog.log that will tell you your Ruby process was identified as a zombie and that it killed the parent pid, which if you have lightty setup to manage fastcgi it will then be that parent process. Or if you are lucky the "not even in the TextDrive Acceptable Use Policy" error: problem=used more than 30 cpu seconds over 90 real seconds will crop up.

    Following their "current" recommended guidelines for Rails apps, nets you having lightty reporting that connections are refused on the socket and that the backend died. Check out this forum thread and also this one, where an admin says that memory related kills don't get logged!He also lays it at the feet of FreeBSD memory reporting. So believe what you read in there for sure :-)
Comments