Building The Conversation

How we shaved 2 seconds off our Rails start up time

Our app takes no small amount of time to start up. This appears to be par for the course for Rails on 1.9.2, but Pete (on loan from Envato for a few days, hooray for dev share!) and I did a quick spike to see if there was anything specific to our environment causing unnecessary delays.

There are a number of ways to approach this problem, of which in this post I will talk about just one: ruby-prof. You can use it unobtrusively to get a call graph for your application.

    gem install ruby-prof
    ruby-prof --printer=graph_html ./script/rails runner > profile.html


This will show large amounts of time spent in requires and initializers. That is disappointing, but to be expected. We were looking for something more anomalous. And we found it:

    40.45%   11.83%   22.35   6.54   0.00   15.81   1962610   Pathname#to_s


Pathname#to_s was being called millions of times and taking more than its fair share of the cake. To confirm this assumption we also ran ruby-prof against a blank Rails app, which only called Pathname#to_s a measly 59 times.

The next step was to find what was calling our rogue method so many times. There are no doubt elegant ways to do this, but we are not above a quick hack. Copying the source of the method from the rubydocs, we added some extra diagnostic information and pasted the new definition in config/environment.rb above any other requires.

    class Pathname
      def to_s
        puts
        puts
        puts 
        puts @path
        puts caller
        @path.dup
      end
    end


Of course, letting our startup process run to completion would create a lot of output, but CTRL+C a few moments in should give us enough information to notice any recurring patterns.

Sure enough, some paths showed up repeatedly. (I haven’t included the stack traces because they turned out not to be relevant.)

    /Volumes/conversation/tc/lib
    /Volumes/conversation/tc/app


lib, app, lib, app, over and over and over again. That smells like our load path.

    # config/environment.rb
    module TheConversation
      class Application < Rails::Application
        config.autoload_paths << Rails.root.join("app")
        config.autoload_paths << Rails.root.join("lib")
      end
    end


That looks like it! Let’s convert them to strings before adding them.

    # config/environment.rb
    module TheConversation
      class Application < Rails::Application
        config.autoload_paths << Rails.root.join("app").to_s
        config.autoload_paths << Rails.root.join("lib").to_s
      end
    end


Sure enough this cut a good few seconds off our load time. ruby-prof, I owe you a beer.