JRuby and why it might be nice to be back on the JVM

We ported our Rails application to JRuby in order to do some GC comparisons yesterday. Not a ton of changes required. Mostly replacing gems with native dependencies. YAML is a bit more strict than its MRI counterpart…. but all told, thats pretty amazing! Nice job JRuby crew!

That said…. one interesting, entirely un-scientific, test case. After requesting the same URL 6 times, the VM got a lot better. 3.4s to 480ms

Completed in 3380ms (View: 2739, DB: 65) | 200 OK [http://someurl.com/people/3]
Completed in 1299ms (View: 1211, DB: 18) | 200 OK [http://someurl.com/people/3]
Completed in 1020ms (View: 949, DB: 20) | 200 OK [http://someurl.com/people/3]
Completed in 852ms (View: 732, DB: 18) | 200 OK [http://someurl.com/people/3]
Completed in 743ms (View: 628, DB: 31) | 200 OK [http://someurl.com/people/3]
Completed in 485ms (View: 374, DB: 14) | 200 OK [http://someurl.com/people/3]

It doesnt appear to be the DB caching the data. That time stayed consistent.

I didnt use any crazy runtime flags.. Just jetty, a war file, and -server….

If it was something we were memcaching, then after the 2nd request, it would have been consistent.

The amount of time spent in the view improved dramatically.

I didnt think JRuby leveraged JIT’ing yet. Anyone care to guess/explain why it was significantly better per request?

Note: It did trail off in the 300ms range with further testing…

Are your mongrels growing by 20MB/request on Rails 2.2? Blame AssetTag!

After porting our production application to Rails 2.2, we noticed a major memory leak.

Beforehand, monit would restart instances a handful of times a day. After Rails 2.2, monit restarted instances THOUSANDS of times a day.

This is a graph of one of our haproxy instances a couple days ago.

We looked at everything, including time spent rewriting Routes, thinking that was the culprit.

This morning, we all sat around and fought the issue old school style. binary debugging… and found it: AssetTagHelper. See the patch here.

The new thread-safe asset tag code keeps a static AssetTag::Cache = {} of all asset_tags created (css,jss, and all images).

Internally, each AssetTag object keeps a reference to the controller and template objects, and in turn all instance variables you created in your request.

What does that mean? Say you have a people controller, that loads a person and their stuff, and you show images of their stuff via image_tag().

 class PeopleController < ApplicationController
   def show
     @person = Person.find(params[:id])
     @stuff = @people.stuff.find(:all, :limit => 30)
   end
 end

When image_tag() is called, it does rails magic to append file extensions, asset_ids, and the like. To be smart, it caches those objects so it doesnt hit the file system
to figure all that out on every request. The problem is it puts it in a static cache, AssetTag::Cache.

So each PeopleController instance has a reference to 1 person and 30 Stuffs. After 1000 people look at their pages, or better yet google crawls your site, you have 1k @controllers with a total of 1000 People Objects, and 1000*30 Stuff objects. This would normally be fine. The objects leave scope and get GC’ed. But, if you generate an image tag to an unique asset, AssetTag puts that into a cache, AssetTag::Cache, with a reference to the @controller of the request. So All People and their Stuff are kept around forever, unable to be GC’ed…. every time a unique image is rendered via AssetTag. Eventually monit has to kill the process.

The patch we just submitted does 2 things.

1) It now keeps a cache of just the modified path strings, caching the file access stuff. If you have tons of local images, reference them by fully qualified host. Thats better for lots of reasons. Cookie-less asset hosts with multiple subdomains FTW!

2) It stops caching absolute URL paths. You cant do anything on the filesystem to verify them, and keeping a cache of those would also grow unbounded. We have millions of items in our system, each with a reference to an image.

Here is a graph of that haproxy today… Sleeping………

In order to do some testing of your own, here’s a simplistic after_filter you can add to application.rb (or is it now application_controller.rb?). Make sure you run this in production mode or with cache_classes = true. As you click around your site, you should see that the cache retains references to controller instances, just to name a few. After you apply the patch, you’ll see the cache is just strings.

 def assettag_cache
    puts "-"*80
    puts "[AssetTag::Cache] Now #{ActionView::Helpers::AssetTagHelper::AssetTag::Cache.size} items"
    ActionView::Helpers::AssetTagHelper::AssetTag::Cache.values.each do |asset_tag|
      if asset_tag === ActionView::Helpers::AssetTagHelper::AssetTag
        puts "   [Asset] #{asset_tag.instance_variable_get("@source")}  #{asset_tag.instance_variable_get("@controller").class.to_s}"
      else
        puts "   [Asset] #{asset_tag}"
      end
    end
  end

Ohh… and we havent given up on routes… Warren is working on some very interesting enhancements to rails routing. Looking forward to blogging about that soon.

How to save 100m of RAM per mongrel (Part 2)

UPDATE I’ve added a patch to Rails Edge for this fix, which is much different than the patch below. See here

In a previous article, I called out the massive memory usage of the default rails resource behavior, and it seems others have as well. In an attempt to decrease the number of routes, I commented out the “formatted_*” routes, and manually entered them back by hand.

But after some internal discussion/testing with Warren, we realized that was sloppy and error prone. Instead, I hacked Routing segments to allow for an optional format segment, so that formatted routes and normal routes are shared. The one downside, from what I can tell so far, is you lose “formatted_*” named routes + url helpers for those routes, but passing format to a url_for still works

   person_path(:id => 1, :format => "json") =>  /people/1.json

In the below gist, you’ll see a OptionalFormatSegment, which sneakily gets around the ‘.’ regex separator, removes the formatted_* named routes added by default, and should be the same solution as the previous post, but without the need to manually put all the routes back in.

I’m still testing this approach, but am interested in what other folks think.

Note: This monkey-patch only works on Rails 2.2

How to save 100m of RAM per mongrel

UPDATE: See Part 2 of this for a better solution

Note: This monkey-patch only works on Rails 2.2

We recently noticed our mongrels, upon startup, were 244M. Eek.

PID USER            PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
53749 some_user     15   0  337m 244m 2912 S    0  2.0   0:17.49 mongrel_rails

Running Bleakhouse on our rails app, i was amazed at the number of objects created. over 2M!

$ BLEAK_HOUSE=1 ruby-bleak-house ./script/runner 'puts 1'
** Bleakhouse: installed
1
** BleakHouse: working...
** BleakHouse: complete
** Bleakhouse: Run 'bleak /tmp/bleak.53749.0.dump' to analyze.

$ bleak /tmp/bleak.53749.0.dump
Displaying top 20 most common line/class pairs
2,047,025 total objects
2,047,025 filled heap slots
2,403,764 free heap slots
1779063 __null__:__null__:__node__
197423 __null__:__null__:String
16519 __null__:__null__:Array
12728 __null__:__null__:ActionController::Routing::DividerSegment
10495 __null__:__null__:Hash
5676 __null__:__null__:ActionController::Routing::StaticSegment
5436 __null__:__null__:Class
5132 __null__:__null__:Regexp
4525 __null__:__null__:ActionController::Routing::DynamicSegment
2524 __null__:__null__:ActionController::Routing::Route
1307 __null__:__null__:Gem::Version

Whats up with all those routing objects! So i tried a blank routes.rb file….

519,307 total objects
519,307 filled heap slots
233,503 free heap slots

Arghh…. 1.5M objects just because of routes.rb. I know our application is large, lots of resources and nested resources, but thats crazy.

$ rake routes | wc -l
2516

Ok, so taking a closer look, I realized something. Each resource route has a corresponding formatted_* route, lots of which we dont use. So now for some nasty monkey-patching.

ActionController::Routing::RouteSet::Mapper.class_eval do
protected

  def map_unnamed_routes(map, path_without_format, options)
    map.connect(path_without_format, options)
    #map.connect("#{path_without_format}.:format", options)
  end

  def map_named_routes(map, name, path_without_format, options)
    map.named_route(name, path_without_format, options)
    #map.named_route("formatted_#{name}", "#{path_without_format}.:format", options)
  end
end

I then manually added back the formatted routes we needed, careful to use named routes as “map.formatted_foo_bar”

$ rake routes | wc -l
1490
$ bleak /tmp/bleak.56554.0.dump
1,242,796 total objects
1,242,796 filled heap slots
1,224,309 free heap slots

Awesome. I no longer create almost 800k objects.

PID USER            PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
56554 someuser     15   0  249m 156m 2912 S    0  1.3   0:09.92 mongrel_rails

244m –> 156m

This is not a very elegant solution… but I saved almost 100m per mongrel. Ohh.. and it reduced startup time by 50%.

How big are your mongrels?

How does Merb’s router differ from Rails routing? Worth investigating?

MRI Ruby + MySQL + Threads == Stop the world… JRuby doesn’t

As we have been internally discussing how to scale our databases from 10’s of millions of rows to 100’s of millions, database sharding came up.

Depending on your data model and your application, sharding data into tables by some natural key is great if any given request uses only one shard. FiveRun’s DataFabric seems to help with that. Its obviously best to shard the data in the most used way, but occasionally you’ll need to write broadcast queries across shards. It’d be even better if those broadcast queries were executed concurrently. Well, apparently, its not that simple in MRI Ruby.

The mysql (2.7) gem stop’s the world while executing a query. A sloppy but reproducible test is here. This is not a mutex lock on the re-use of a single connection object. Eddie also reached out to the Sequel maintainer, who agrees it is likely due “to the fact that the C drivers don’t release the interpreter lock while they wait for a response from the server.” JRuby, or more accurately JDBC, acts as expected. We even tested DataMapper’s DataObjects::MySQL, as it appears they’ve re-implemented the mysql gem. Unfortunately it suffers from the same stop-the-world issue.

$ ruby mysql_locking_test.rb
Loading MRI MySQL
Serial: 4.00969815254211s
Multi-threaded: 4.00785183906555s

$ data_mapper=true ruby mysql_locking_test.rb
Loading DataMapper
Serial: 4.01330804824829s
Multi-threaded: 4.01132893562317s

$ jruby mysql_locking_test.rb
Loading JDBC-MySQL
Serial: 4.2802369594573975s
Multi-threaded: 1.0499329566955566s

Only in JRuby was the multi-threaded != sequential time, as expected.

Potentially unrelated, no one has touched the mysql gem in 3 years?!?!

$ gem spec -v 2.7 mysql | grep date
date: 2005-10-09 00:00:00 +00:00

So even Ruby ORM frameworks (Sequel, DataMapper) that say they’re thread-safe, are not concurrent on MRI… at least for mysql. For folks not using Rails, which already has a mutex lock higher in the stack, this must be a performance issue. For example, Merb + DataMapper + MySQL. If there is a 2s SQL query, all threads in that process stop for 2s.

Can others verify? “select sleep(2) from dual;” is a great way to test for this.

UPDATE: Multiple have asked, so to clarify. The sample code here creates a new connection PER thread. The mysql docs states: “Two threads can’t send a query to the MySQL server at the same time on the same connection”, but the test is creating a new connection object per thread, so that should not apply.

UPDATE 2: A couple folks have mentioned asynch drivers. One for mysql and one for postgres, but I believe they’re based on NeverBlock, which is Ruby 1.9 only. That sounds like awesome progress. What’s the realistic ETA for folks running 1.9 in a production environment? At least until Christmas for a 1.9 official release?

UPDATE 3: Looks like lots is happening here. There now is a mysql driver that supports async/threaded operations on 1.8! See the NeverBlock MySQL project. Looking forward to testing this in a production environment.

Using helpers in a controller: with_helpers

Although there is supposed to be a clear separation between views and controllers, often when it comes to helper functions, there is a small bit of overlap and there are situations where it’d be nice to simply use a few helpers from inside an action.

ActionController::Base.class_eval do
  def with_helpers(&block)
    template = ActionView::Base.new([],{},self)
    template.extend self.class.master_helper_module
    add_variables_to_assigns
    template.assigns = @assigns
    template.send(:assign_variables_from_controller)
    forget_variables_added_to_assigns
    template.instance_eval(&block)
  end
end

Here is what it looks like in a controller. Although this is a non-sensical example, it shows off how you can use a helper (i.e. link_to) in an action. It also shows how the instance variables (i.e. @person) set in the action are available in the with_helpers block… the same way that instance variables are available in views.

class MyController < ApplicationController
  def my_action
    @person = Person.find(params[:id])
    render :text => with_helpers { link_to(@person.full_name, person_path(@person)) }
  end
end