Rails: rails vs ./script/rails

Long time Rails developer Jesse Storimer (of Shopify) recently blogged about the efficiency of the new (since 3.0) rails command versus using plain old ./script/rails. You can find his piece here: The rails command and exec(2). You should definitely read that before moving on.

So Jesse’s premise is that you should consider using ./script/rails instead of the rails command because of the overhead involved with the rails script and exec. When I read this, I was skeptical. Just how much overhead can there be in a simple wrapper like the rails script? Why ask rhetorical questions when we can know for sure!?

I performed this testing in our staging environment:

  • Linode 512 instance running Debian 6.0
  • Rails 3.1.1
  • Ruby 1.9.3-p0
  • Bundler 1.0.21
  • Gems in bundle: 68

Since this is a capistrano deployed environment, we rely on bundler, so I wasn’t able to test the bare rails wrapper. Maybe another time.

I ran two sets of tests. First, I figured I’d run a test against rails runner because it wasn’t immediately obvious to me how I’d execute rails console using the GNU time utility. Once the console is open, the REPL interface would sit there waiting on me and be included in the time results. Easy fix. I simply added a call to exit to my ~/.irbrc file causing irb to execute immediately and reliably without waiting on a slow human. Once I figured out how I’d test the console, I wired up my tests.

TL;DR – Avoiding the wrapper bundle exec rails saves you about 1 second for every execution of console or runner. Meh. Although, a full second can seem much longer when you’re reloading your console 5 times in a row because of some stupid error you keep making.

Read on to see the methodology and analysis.

Files

Exec: count gems (no file, just executed at a prompt)

# Be sure to subtract 1 for the header line!
bundle show | wc -l

File: test_script

puts "Runners gon' run!"

File: ~/.irbrc

# Be sure to remove this later or you'll be reeeeeally confused
exit

File: bench_runner.sh

#!/usr/bin/env bash

echo "Runner tests: 4 times each"
echo
echo "cmd: bundle exec rails runner -e staging test_script"
time bundle exec rails runner -e staging test_script
time bundle exec rails runner -e staging test_script
time bundle exec rails runner -e staging test_script
time bundle exec rails runner -e staging test_script
echo
echo "cmd: ./script/rails runner -e staging test_script"
time ./script/rails runner -e staging test_script
time ./script/rails runner -e staging test_script
time ./script/rails runner -e staging test_script
time ./script/rails runner -e staging test_script

File: bench_console.sh

#!/usr/bin/env bash

echo "Console tests: 4 times each"
echo
echo "cmd: bundle exec rails console staging"
time bundle exec rails console staging
time bundle exec rails console staging
time bundle exec rails console staging
time bundle exec rails console staging
echo
echo "cmd: ./script/rails console staging"
time ./script/rails console staging
time ./script/rails console staging
time ./script/rails console staging
time ./script/rails console staging

Test Results

Let’s have a look at the results for runner:

Runner tests: 4 times each

cmd: bundle exec rails runner -e staging test_script
Runners gon' run!

real    0m9.949s
user    0m9.190s
sys 0m0.715s
Runners gon' run!

real    0m9.519s
user    0m8.753s
sys 0m0.724s
Runners gon' run!

real    0m9.652s
user    0m8.898s
sys 0m0.712s
Runners gon' run!

real    0m9.898s
user    0m9.105s
sys 0m0.747s

cmd: ./script/rails runner -e staging test_script
Runners gon' run!

real    0m8.765s
user    0m8.101s
sys 0m0.621s
Runners gon' run!

real    0m8.417s
user    0m7.731s
sys 0m0.642s
Runners gon' run!

real    0m8.991s
user    0m8.290s
sys 0m0.657s
Runners gon' run!

real    0m8.530s
user    0m7.828s
sys 0m0.658s

And now console:

Console tests: 4 times each

cmd: bundle exec rails console staging
Loading staging environment (Rails 3.1.1)

real    0m9.712s
user    0m8.885s
sys 0m0.782s
Loading staging environment (Rails 3.1.1)

real    0m9.725s
user    0m8.905s
sys 0m0.774s
Loading staging environment (Rails 3.1.1)

real    0m9.661s
user    0m8.861s
sys 0m0.754s
Loading staging environment (Rails 3.1.1)

real    0m9.742s
user    0m9.024s
sys 0m0.675s

cmd: ./script/rails console staging
Loading staging environment (Rails 3.1.1)

real    0m8.617s
user    0m7.978s
sys 0m0.596s
Loading staging environment (Rails 3.1.1)

real    0m9.168s
user    0m8.385s
sys 0m0.738s
Loading staging environment (Rails 3.1.1)

real    0m8.589s
user    0m7.868s
sys 0m0.677s
Loading staging environment (Rails 3.1.1)

real    0m8.573s
user    0m7.846s
sys 0m0.684s

Analysis

Time to do the math. Since we’re interested in the time we have to wait before we can do more work, we’ll look at the real field results (using Ruby, of course).

Runner:

# average times for bundle exec rails runner
([9.949, 9.519, 9.652, 9.898].reduce(:+).to_d / 4).to_s

# average times for ./script/rails runner
([8.765, 8.417, 8.991, 8.530].reduce(:+).to_d / 4).to_s

Using bundle exec rails runner: 9.7545s avg
Using ./script/rails runner: 8.67575s avg

Result: avoiding bundle exec rails for runner saves you an average of 1.07875 seconds every time you execute runner.

Console:

# average times for bundle exec rails console
([9.712, 9.725, 9.661, 9.742].reduce(:+).to_d / 4).to_s

# average times for ./script/rails console
([8.617, 9.168, 8.589, 8.573].reduce(:+).to_d / 4).to_s

Using bundle exec rails console: 9.71s avg
Using ./script/rails console: 8.73675s avg

Result: avoiding bundle exec rails for console saves you an average of 0.97325 seconds every time you boot a console.

Pow config for grown-ups

After I posted my Pow running config Python script, my good friend and colleague Nolan Meyers sent over a link to Powder, a gem for working with Pow. The list of things you can do with Powder is conveniently listed in the README.