SYNOPSIS very slow memory leak running rails. i'm not sure if it's in ruby, rails, or some combination of them. dike.rb suggests it's in cgi/session.rb but i'll be damned if i've been able to fix it. regardless the leak is related to setting up session, not creating new ones mind you, just yanking them out of the database. DESCRIPTION i was having a bad time with a particular project leaking very slowly and not having luck fixing it. i decided to start with a bare bones rails project: nothing but a simple text response to see if it had the same behavirour. it did not. the i added db sessions - to my suprise the app started leaking *very* slowly. this leak takes hours and hours to leak even 1k, and at times you will think the gc is kicking in and doing it's job, but slowly over time the vsize and rsize will rise. after at *least* 100k requests though - you should see this leak. you should just be able to run this application, but i'll go through what i did to reproduce. you can download the entire project, including this README, from http://s3.amazonaws.com/drawohara.com.downloads/leak.tgz SETUP you shouldn't need to do any of this, but here it is: this project was created by rails leak --database-sqlite3 database session were turns on via config.action_controller.session_store = :active_record_store in environment.rb and then rake db:session:create RAILS_ENV=production rake db:migrate ran were run a single controller exists which does the following class HomeController < ApplicationController def self.stats controller GC.start uri = controller.request.request_uri[0,300] n_req = @number_of_requests n_obj = ObjectSpace.each_object{} n_sym = Symbol.all_symbols.size pid = Process.pid stdout = `ps wwwaux -p #{ pid }`.strip.split(%r/\n/) vsize, rsize = stdout.last.split(%r/\s+/)[4,2] "uri: #{ uri }, n_req: #{ n_req }, n_obj: #{ n_obj }, n_sym: #{ n_sym }, pid: #{ pid }, vsize: #{ vsize }, rsize: #{ rsize }" end before_filter do |controller| @number_of_requests ||= 0 if @number_of_requests % 100 == 0 @before = "@@ >> #{ stats controller }" end end after_filter do |controller| if @number_of_requests % 100 == 0 @after = "@@ << #{ stats controller }" controller.logger.info @before controller.logger.info @after @before = @after = @before_symbols = @after_symbols = nil end @number_of_requests += 1 end def index render :text => "#{ 42 }\n" end end was created. note that it just dumps out text and reports some memory stats to the log every 100 runs. session, while loaded by rails, are not even used. the only other thing done was to tweak ./script/server to run lighttpd on 4242, the entire ./script/server file #!/usr/bin/env ruby ARGV.replace %w'lighttpd -p 4242' if ARGV.empty? require File.dirname(__FILE__) + '/../config/boot' require 'commands/server' TO SEE THE LEAK * start the server: RAILS_ENV=production ./script/server -p 4242 2>&1 | tee log/production.log * prime your cookies and make sure the page isn't barfing curl --silent --cookie-jar cookie-jar --cookie cookie-jar http://localhost:4242/home/ * hammer the server: while true;do curl --silent --cookie-jar cookie-jar --cookie cookie-jar http://localhost:4242/home/;done >/dev/null or something like cat cookie-jar # read cookie name and value while true;do ab -n 100 -C _rails.leak_session_id=BAh7BiIKZmxhc2hJQzonQWN0aW9uQ29udHJvbGxlcjo6Rmxhc2g6OkZsYXNo%250ASGFzaHsABjoKQHVzZWR7AA%253D%253D--7570d18c401107a26bce83d4a73219ad294bd296 http://localhost:4242/home/>/dev/null;echo 42;done the first is simpler, the second a bit faster. the cookie settings keep a new session from being created each time. this is *important*. * watch the rsize grow. this takes a long time, but you *can* see it over 30 minutes ~ 25,000 requests. there is an example log in log/leak.log.gz while true;do echo ---;grep @@ log/production.log |head; echo -; grep @@ log/production.log |tail; sleep 1;done what you'll see in the beginning is something like this: ->: pid: 4858, vsize: 54516, rsize: 21632, uri: /home/, n: 68662 <-: pid: 4858, vsize: 54532, rsize: 21604, uri: /home/, n: 40408 ->: pid: 6146, vsize: 54548, rsize: 21764, uri: /home/, n: 82697 <-: pid: 6146, vsize: 61192, rsize: 28312, uri: /home/, n: 40513 @@ >> uri: /home/, n_req: 0, n_obj: 40091, n_sym: 10382, pid: 3610, vsize: 53676, rsize: 21036 @@ << uri: /home/, n_req: 0, n_obj: 39478, n_sym: 10387, pid: 3610, vsize: 53676, rsize: 21028 @@ >> uri: /home/, n_req: 100, n_obj: 40104, n_sym: 10387, pid: 3610, vsize: 53676, rsize: 21048 @@ << uri: /home/, n_req: 100, n_obj: 39479, n_sym: 10387, pid: 3610, vsize: 53676, rsize: 21056 @@ >> uri: /home/, n_req: 200, n_obj: 40211, n_sym: 10387, pid: 3610, vsize: 53676, rsize: 21040 @@ << uri: /home/, n_req: 200, n_obj: 39485, n_sym: 10387, pid: 3610, vsize: 53660, rsize: 21004 ... followed by *many* requests and then ... @@ >> uri: /home/, n_req: 90000, n_obj: 40101, n_sym: 10387, pid: 3610, vsize: 54676, rsize: 22136 @@ << uri: /home/, n_req: 90000, n_obj: 39500, n_sym: 10387, pid: 3610, vsize: 54676, rsize: 22098 @@ >> uri: /home/, n_req: 90100, n_obj: 40204, n_sym: 10387, pid: 3610, vsize: 54676, rsize: 22088 @@ << uri: /home/, n_req: 90100, n_obj: 39070, n_sym: 10387, pid: 3610, vsize: 54676, rsize: 22056 @@ >> uri: /home/, n_req: 90200, n_obj: 40201, n_sym: 10387, pid: 3610, vsize: 54676, rsize: 22160 @@ << uri: /home/, n_req: 90200, n_obj: 39580, n_sym: 10387, pid: 3610, vsize: 54660, rsize: 22074 note that, although memory definitely increases, the object count and symbol count do not. * my system info Darwin 8.10.1 i386 ruby 1.8.6 (2007-06-18 patchlevel 5000) [i686-darwin8.10.1] Rails Edge from svn as of Fri Oct 2 14:02:57 MDT 2007 * if you tweak config/environment.rb to use file or cookie based sessions the leak seems to go away. by 'seems' i mean it is either extremely tiny or vanishes - it's hard to say which.