Dan Manges

Action Dependent Validations and Why :on => :update is Bad

Dan Manges — Thu, 04 Dec 2008 05:16:06 GMT

ActiveRecord validations typically apply all the time. For example, a User object may be required to always have an email_address.


class User < ActiveRecord::Base
  validates_presence_of :email_address
end

But validations can also be set depending on the action being taken on the object. For example, let's say when a User is first created it does not need to have a password. Before the user can set his or her password, he needs to click an activation link in an e-mail. We can tell ActiveRecord to only require a password when updating the User.


class User < ActiveRecord::Base
  validates_presence_of :password, :on => :update
end

But :on => :update is almost never what you want.

The Smell

Let's take a quick look at the validation behavior of this workflow. We initially create a User with only an e-mail address.


  User.create! :email_address => "daniel.manges@gmail.com"
  #=> #

So far, so good. Now what if something comes up where we want to verify that all the records in the database are valid? We'll find the user and make sure valid? returns true.


user = User.find(1)
user.valid?
#=> false

user.errors.full_messages
#=> ["Password can't be blank"]

The record is invalid. But is it really? No. Users don't have to have passwords until activating. I think for any record in the database, you should be able to load the object, call valid?, and get true. But this isn't just a theoretical issue, running validations :on => :update usually causes actual problems.

The Intention of Validating on Update

We spend a lot of time as software developers trying to determine the intention of other developers. If code is fairly clean, we can easily tell what it does. But determining if the some of the behavior is intended or incidental is more difficult. Consider this code:


class User < ActiveRecord::Base
  validates_presence_of :password, :on => :update
end

I translate this code into: the very first time a User is updated after being created it must have a password.

That's a really strong constraint. What if I want to update the user another way without setting a password? If the user is activating his account, I want him to set his password. But an admin should be allowed to change some attributes on the user without setting the password. Because of the constraint imposed by this validation, what happens a lot of time is this:


user.some_flag = true
user.save(false)

If you're not familiar with save(false), it saves the record without running validations. Because the validations won't allow the user to be updated without setting a password, it's easy to resort to doing this. But it's dangerous - skipping validations can end up being a nightmare. You can't add a new validation and be sure that it will never be violated - you have to look for all occurrences of save(false) to make sure none of them are circumventing.

The Solution

Let's go back to the requirement. When a user activates his account, he must set a password. To implement this, we need a way to have a validation run only on activation. Here's one way to do this:


class User < ActiveRecord::Base
  
  def save_on_activation
    return false unless valid_for_activation?
    save!
  end
  
  def valid_for_activation?
    valid? # run all validations
    errors.add(:password, "cannot be blank") if password.blank?
    errors.empty?
  end
end

Having save_on_activation and valid_for_activation? methods makes it easy to control when the validations apply. If you like the declarative nature of the ActiveRecord validations, you could set some state and then use the :if option like this:


class User < ActiveRecord::Base
  validates_presence_of :password, :if => :activating?
  
  def save_on_activation
    @activating = true
    save
  ensure
    @activating = false
  end
  
  def activating?
    @activating
  end
end

With this implementation, setting the @activating instance variable causes the validation to be run.

Validation Groups

If you need a lot of separate validation groups like this, managing all the validations can become tricky. For example, this save_on_activation method applies the validation on the appropriate action, but what about when a user is updating his profile, which includes a password edit field? We need to make sure he can't set a blank password. So we want this validation to run on both activation and edit.

Validatable is a validation framework that allows grouping validations in a declarative style. I haven't used it with Rails 2.x, but with Rails 1.2 you could include Validatable in an ActiveRecord class and it would just work. Anyway, with validatable the code would look like this:


class User < ActiveRecord::Base
  include Validatable
  
  validates_presence_of :password, :groups => [:activation, :edit]
  
  def save_on_activation
    return false unless valid_for_activation?
    save  
  end
end

Summary

For some requirements :on => :update seems to be the answer. One is the example from this blog post, where an attribute isn't required when something is created, but it is required when the record is updated later. Another is legacy data. It's typical for legacy data not to comply with a validation, but new records and updated legacy records should adhere to it. In either of these scenarios I think it's better to make custom save and valid methods than it is to use :on => :update.

comments | twitter

Rails Application Visualization

Dan Manges — Tue, 28 Oct 2008 07:50:55 GMT

Before we went live with the new Rails site at CarePages, we decided to use Munin for monitoring. We needed to write a few custom plugins to visualize application health. Fortunately, Munin plugins are really easy to write - I'll provide the source for a couple of them. We wrote plugins for Passenger process status, Passenger memory stats, Rails response time, Rails hits, the ARMailer queue, and the BJ queue. Munin also comes with default plugins for things like CPU and memory usage that are good to use for correlation.

Passenger Status

Passenger has a passenger-status command that will output the status of all the Rails (or Rack) processes. It will provide the maximum number of processes that can be spawned, how many processing are currently running, and how many are in use. The output looks like this:

$ sudo passenger-status
----------- General information -----------
max      = 16
count    = 4
active   = 2
inactive = 3

----------- Applications -----------
/redacted/releases/20081024053350: 
  PID: 18984     Sessions: 0
  PID: 18980     Sessions: 0
  PID: 20126     Sessions: 1
  PID: 15735     Sessions: 1

And here's the Munin graph. Parsing the output of the passenger-status command was simple, and provided good visibility into the application health. Here's the source for the passenger-status munin plugin.

Passenger Memory Stats

Passenger also provides memory stats via passenger-memory-stats. It will show the amount of memory being used per process. Here's what it looks like in the form of a Munin graph. You can see that as processes go idle when there's low traffic over night, Passenger kills them, freeing up memory. You can also see the application slowly leaking memory during the day.

Rails Hits

We wanted to be able to correlate utilization with actual traffic, so we also made a plugin to graph requests that hit Rails. We set up a custom log to make this easier, but in the end we had a plugin that would chart how many requests were hitting Rails every 5 minutes per app server.

Rails Response Time

And of course, we wanted to be able to see the app performance using mean and median response times. We logged Rails' X-Runtime header in our custom log, and we used that to produce yet another Munin graph. I'll blog about the details of that custom log later - we found several good uses for it.

CPU

Munin comes with some default plugins that are good to correlate with the application-specific plugins that we wrote. For example, here's the CPU usage graph.

MySQL Queries

Munin also has bundled plugins for MySQL, making it easy to keep an eye on queries / second and slow queries.

Background Queues

Finally, it was also easy to write plugins to keep an eye on background queues. Here's one that watches the AR Mailer queue.

And another that watches the BJ queue (source).

comments | twitter

Increasing Code Coverage May Be Harmful

Dan Manges — Fri, 17 Oct 2008 05:30:04 GMT

I should start by clarifying: I'm referring to increasing code coverage by running a code coverage tool, looking for untested code, and writing tests for it. Here's an example.

Let's say you run your test coverage report and you find the following method is not tested.


class BankAccount
  def masked_number
    ("*" * 8) + number.to_s[-4, 4]
  end  
end

It's easy to see what this method does. I can get 100% coverage in a few seconds.


describe "masked_number" do
  it "returns 8 asterisks followed by the
        last 4 characters of the account number" do
    account = BankAccount.new :number => 123456781234
    account.masked_number.should == "********1234"
  end
end

Is the method tested? Yes. Is it tested well? No. What is it supposed to return if there is no account number? What if the account number is longer than 12 digits - should it still return 8 asterisks, or should it return more? Because masked_number didn't have any tests, you have no idea if the author of the method considered these scenarios or not.

So let's say we assume that the original author of this method considered these possibilities and did the right thing. So we add a few more tests.


describe "masked_number" do
  it "returns 8 asterisks if the account number is blank" do
    account = BankAccount.new :number => nil
    account.masked_number.should == "********"
  end

  it "returns 8 asterisks followed by the
        last 4 characters of the number for a
        14 digit account number" do
    account = BankAccount.new :number => 12345678901234
    account.masked_number.should == "********1234"
  end
end

We now have 3 tests for this method, covering a few possible input values. Awesome. Maybe...

Now let's say a developer picks up a bug ticket from QA: "For an account number of length X, the account mask should show X - 4 asterisks and the last 4 digits of the account number. Right now it always shows 8 asterisks. For example, a 14 digit account number should have 10 asterisks."

So the developer decides to do TDD and write a test, but he or she notices the test that's already there. Now the quick thing to do would be to assume that the QA ticket is right and update the existing test. But that's not the responsible thing to do. If a test is there, indicating that a 14 digit account number should have 8 asterisks, somebody must have desired that behavior. Before changing the test and the code, the developer should find out who wrote the test. Does somebody else think it should be 8 asterisks? Does one part of the application always want 8, while another wants 10?

When faced with untested code, there are 3 approaches you can take, and all of them have drawbacks.

(1) Thoroughly test the method.
Advantage: the method is now well tested.
Disadvantage: it may lead future developers astray by making something coincidental seem intentional.

(2) Do the minimal amount of testing to cover the method.
Advantage: the method has some basic tests for it.
Disadvantage: you're focused on the wrong goal. You should strive for well tested code, not 100% code coverage. There's a big difference.

(3) Don't test it until you can verify the requirements. Then thoroughly test it.
Advantage: avoiding the disadvantages of options 1 and 2.
Disadvantage: verifying the requirements can be time consuming, and until you do, you have untested code.

If the requirements aren't clear, in my opinion, it's a tough choice. The best option is to avoid all 3 by being disciplined with testing. But honestly, I'd lean towards not testing the method. If a developer comes across a bug in the untested method, then he/she should write a test for that bug. Working on the bug also provides a good opportunity to ask questions about the requirements. If a developer needs to change the method due to a new requirement, then he/she should write a test for the change. If a developer wants to refactor the method and wants to be sure that his refactoring doesn't break anything, he might want to reconsider. Yes, poor test coverage inhibits refactoring.

Essentially, what I'm saying is that trying to increase test coverage by looking for untested code and writing tests for it may be harmful due to the disadvantages listed under approaches #1 and #2.

Keep in mind that tests can never guarantee correct requirements were implemented. But if you see a test that says 1 + 1 should be 3, you shouldn't change it until you find out more about why it's that way. Similarly, 100% coverage never guarantees that the code is well tested. But doing the minimum amount of effort to cover code makes the team less confident in the tests. I'd rather have 90% coverage, and feel that the 90% is a solid, well tested, 90%, than have 100% but feel that most of the code isn't well tested.

comments | twitter

Ruby DSLs: instance_eval with delegation

Dan Manges — Wed, 08 Oct 2008 04:59:02 GMT

I saw the warning issued on Ola's blog: don't overuse instance_eval. JEG II blogged about a compromise, and why had an idea. But I like variation of Jim Weirich's MethodDirector.

how instance_eval works

If you're not familiar with instance_eval, it evaluates a block of code with self set to the object that's receiving the instance_eval call. Here's an example.


add_two = Proc.new { self + 2 }

puts 1.instance_eval(&add_two)
#=> 3

puts 2.instance_eval(&add_two)
#=> 4

Here's a second example using an implicit method receiver.


call_reverse = Proc.new { reverse }

p "abc".instance_eval(&call_reverse)
#=> "cba"

p ["x", "y", "z"].instance_eval(&call_reverse)
#=> ["z", "y", "x"]

the problem with instance_eval

Ola described it really well, so I'm just going to quote him and then show an example.

So what's the problem with it? Well, the problem is that blocks are generally closures. And you expect them to actually be full closures. And it's not obvious from the point where you write the block that that block might not be a full closure. That's what happens when you use instance_eval: you reset the self of that block into something else - this means that the block is still a closure over all local variables outside the block, but NOT for method calls. I don't even know if constant lookup is changed or not.

Using instance_eval changes the rules for the language in a way that is not obvious when reading a block. You need to think an extra step to figure out exactly why a method call that you can lexically see around the block can actually not be called from inside of the block.

Here's an example. Let's take a look at a quasi migration using create_table and _not_ using instance_eval.


class MyMigration < MigrationExample
  def self.up
    create_table "people" do |t|
      t.string "first_name", "last_name"
    end
  end
end

To implement this, we could need t to reference a TableDefinition class that would be used to build up columns. But we could get rid of t if we were to use instance_eval. Because instance_eval could change self to reference the TableDefinition, we could use the implicit method receiver and change the migration to look something like this.


class MyMigration < MigrationExample
  def self.up
    create_table "people" do
      string "first_name", "last_name"
    end
  end
end

But let's take a look at the consequences of this approach. Here's a little fake migration class that just prints output.


class MigrationExample
  def self.create_table(table_name, &block)
    table = TableDefinition.new table_name
    table.evaluate &block
    table.create
  end
end

class TableDefinition
  def initialize(table_name, &block)
    @table_name = table_name
    @columns = []
  end
  
  def evaluate(&block)
    instance_eval &block
  end
  
  def string(*columns)
    @columns << columns
  end
  
  def create
    puts "creating the '#{@table_name}' table with columns: #{@columns.join(", ")}"
  end
end

So here we're using instance_eval to evaluate the block passed to create_table. And if we run the migration, we'll see that the table gets created.

MyMigration.up
#=> creating the 'people' table with columns: first_name, last_name

But what happens if we want to use a little helper method in our migration? Let's try it by doing something completely trivial and extracting a name method.


class MyMigration < MigrationExample
  def self.up
    create_table "people" do
      string name("first"), name("last")
    end
  end
  
  def self.name(which)
    "#{which}_name"
  end
end

And now if we run the migration...

MyMigration.up
# NoMethodError: undefined method 'name' for #<TableDefinition:0x89e18 @columns=[], @table_name="people">

Ouch. Because self is set to the TableDefinition class while instance_evaling the block, our method call to name was sent to the table definition object instead of our migration class.

Here's one approach to solve this problem.

instance_eval + delegation

So the problem is that instance_eval hijacks self, making our method call to name fail. But what if we can get the name call sent back to the object that it would have gone to if we didn't change self?

We can accomplish this by capturing what self is before we change it with instance_eval. Then if our class doesn't respond to a method, we'll assume it was meant for the original receiver.


class TableDefinition
  def evaluate(&block)
    @self_before_instance_eval = eval "self", block.binding
    instance_eval &block
  end
  
  def method_missing(method, *args, &block)
    @self_before_instance_eval.send method, *args, &block
  end
end

Looking at the create_table block again...


create_table "people" do
  string name("first"), name("last")
end

The call to string will be called on TableDefinition. But the name method call will hit method missing and be delegated back to the migration. Here's the output if we run the migration again.

MyMigration.up
# creating the 'people' table with columns: first_name, last_name

We've removed the need for the block local variable t, but also preserved the capability to use local helper methods.

summary

This approach may be useful in some internal DSLs, but it still involves Ruby magic that may be confusing. Especially if you're trying to use instance variables. But if all you want is the ability to use helper methods and/or attribute readers, instance_eval + delegation back to the original self will work.

comments | twitter

The Power of Implementing Ruby in Ruby

Dan Manges — Sat, 04 Oct 2008 19:36:25 GMT

If you're not familiar with Mixology, it's a gem that enables modules to be both mixed into and unmixed from objects, creating a great way to implement the state pattern in Ruby.

The First Test

The first test for Mixology is fairly straightforward. Let's say we have an object with a foo method that returns "foo from object", and a module with a foo method that returns "foo from mixin". When we mix in the module, foo should return "foo from mixin". We should then be able to unmix the module from the object and have the foo method return "foo from object" again.


def test_unmix
  object = Class.new { def foo; "foo from object"; end }.new
  mixin = Module.new { def foo; "foo from mixin"; end }

  object.mixin mixin
  assert_equal "foo from mixin", object.foo

  object.unmix mixin
  assert_equal "foo from object", object.foo
end

Getting the First Test to Pass

Using MRI, we're at the point where we need to drop down into C code to implement this. My C skills aren't too great, which is why Patrick Farley implemented Mixology. But my Ruby skills are much better. Because Rubinius implements as much of Ruby in Ruby as possible, we can get this test to pass with 100% Ruby code.


module Mixology
  def mixin(mod)
    reset_method_cache
    IncludedModule.new(mod).attach_to metaclass
    reset_method_cache
    self
  end
  
  def unmix(mod_to_unmix)
    last_super = metaclass
    this_super = metaclass.direct_superclass
    while this_super
      if (this_super == mod_to_unmix ||
          this_super.respond_to?(:module) && this_super.module == mod_to_unmix)
        reset_method_cache
        last_super.superclass = this_super.direct_superclass
        reset_method_cache
        return self
      else
        last_super = this_super
        this_super = this_super.direct_superclass
      end
    end
    self
  end
  
  protected
  
  def reset_method_cache
    self.methods.each do |name|
      name = self.metaclass.send(:normalize_name,name)
      Rubinius::VM.reset_method_cache(name)
    end
  end
end

Object.send :include, Mixology

And now if we run the test, we'll have green.

$ rubinius test/mixology_test.rb
require 'test/unit/testcase' has been deprecated
Loaded suite test/mixology_test
Started
.
Finished in 0.024741 seconds.

1 tests, 1 assertions, 0 failures, 0 errors

It's not every day when you want implement something like unmixing a module. But if you do want to, Rubinius empowers you to do much more at the Ruby level. It's also a great way to learn more about Ruby's internals. For example, the IncludedModule class used in this implementation is how Ruby puts modules in the inheritance hierarchy for an object.

Source on Github

There are still 5 pending tests before Mixology's whole test suite passes in Rubinius. If you want to give it a shot, fork my github repo.

comments | twitter

Testing Fragment Caching

Dan Manges — Thu, 02 Oct 2008 14:22:31 GMT

The Risk in Fragment Caching

From The need for speed: Making Basecamp faster:

We've begun using Memcached in a variety of spots. Caching can be tricky with dynamic apps like Basecamp since different people often see different things, but we've implemented it carefully where it could be used to its best advantage.

37signals is right. Fragment caching can be tricky. The risk is that a user sees the wrong content, but that risk can be mitigated with tests.

Testing Fragment Caching

Since it's really easy for a developer or designer to make a change that causes problems with caching, it's a good idea to write a test for any pages that are using fragment caching.

Essentially what you need to test is that page content is exactly the same for a user regardless of whether fragments hit the cache or not. So the basic steps are:
(1) with caching off, capture the page content from user1's perspective
(2) with caching on, view the page using user2
(3) with caching still on, view the page using user1 and make sure the body matches the captured body from step 1.

You should run a test following these steps for a few combinations of user1 and user2. The more complicated the cache key is, the more tests you should have.

Here's an implementation using test/unit with Rails.


def test_fragment_caching_on_some_page
  user1 = create_user :first_name => "Nick"
  user2 = create_user :first_name => "Dan"
  check_fragment_caching(user1, user2) do |user|
    @request.session[:user_id] = user.id
    get :some_page
  end
end

def check_fragment_caching(user1, user2)
  Rails.cache.clear
  ActionController::Base.perform_caching = false
  yield user1
  user_1_not_cached_body = @response.body
  
  ActionController::Base.perform_caching = true
  yield user2
  
  yield user1
  assert_equal user_1_not_cached_body, @response.body
end

Example

Let's look at a simple example of how this works. Let's create a fragment with a static cache key.

<% cache "some_fragment" do -%>
  hello
<% end -%>

And the test will pass.

Started
.
Finished in 0.147882 seconds.

1 tests, 1 assertions, 0 failures, 0 errors

But now a developer comes along and decides to greet users by name.

<% cache "some_fragment" do -%>
  hello <%= current_user.first_name %>
<% end -%>

You can see that this will create a caching problem. If the first user to visit the page is named Dan, the fragment will be cached as "hello Dan." Then the next user, who isn't named Dan, will be greeted with "hello Dan." But the test should catch this.

Started
F
Finished in 0.15005 seconds.

  1) Failure:
test_fragment_caching_on_some_page(SomeControllerControllerTest)
method check_fragment_caching in some_controller_controller_test.rb at line 30
method test_fragment_caching_on_some_page in some_controller_controller_test.rb at line 14
<"  hello Nick\n"> expected but was
<"  hello Dan\n">.

Now that there is user specific information displayed inside the fragment, we'll need to update the cache key.

<% cache ["some_fragment", current_user] do -%>
  hello <%= current_user.first_name %>
<% end -%>

And if we run the test, we're back to green.

Started
.
Finished in 0.149098 seconds.

1 tests, 1 assertions, 0 failures, 0 errors

Changing the cache key won't always be the answer. Sometimes you'll want to re-think the change to the page, add a dynamic element using javascript, or take a different approach altogether. But the important part is catching the caching bug quickly.

Summary

Try to hit the all your pages that use fragment caching with different users. Try with an admin/non-admin, users under different accounts, etc. And hopefully if somebody makes a change that messes up the caching, your test will give fast feedback.

comments | twitter

Reminder Tests

Dan Manges — Tue, 23 Sep 2008 14:38:13 GMT

"How are we going to remember to X if/when we Y?"

I ask myself that, or hear a team member ask a question like that, at least once a week.

The first question is: do you need to do X if/when you do Y because there's some sort of duplication? If so, eliminate the duplication. But there are situations where there's not duplication. In that case, write a test. The test either needs to check that X is always true, or it needs to detect if Y happens. Here are some examples in Ruby, but this technique applies to any language.

Using Piston to Install Plugins

"How are we going to remember to use piston when we install plugins?"

Piston is a great tool for installing plugins. It records the repository that the plugin was installed from, along with the remote revision. One reason that this is so important is that plugins are often not released with versions like gems are. They're usually just installed from trunk (or master, for the git users). So in the future, when you want to update the plugin, it helps if you know where you installed it from and which revision it was on when you installed it.

So let's say you tell everybody on your development team: "when you install a plugin, use piston." Everybody sees the benefit and agrees that it's a good idea. But inevitably, somebody will install a plugin and forget. Or you'll get a new team member who doesn't know about piston. You can leave a comment somewhere - maybe a development guidelines wiki page, or a README in the vendor/plugins directory. But it would be much better to have an executable reminder. One that tells you if you forgot. So write a test that checks that all plugins were installed with piston.


test "all plugins are installed with piston" do
  Dir.glob("#{RAILS_ROOT}/vendor/plugins/*").each do |plugin_dir|
    piston_root = `svn propget piston:root #{plugin_dir}`
    if piston_root.blank?
      raise "The #{plugin_dir} plugin was not installed with piston."
      # could leave comments here about how to install a plugin with piston
    end
  end
end

Presto. Now if anybody forgets to use piston, there's a test that reminds him or her.

Updating a Dependency

"How are we going to remember to remove this code when we update to the next version of Rails?"

I recently needed to apply a bug fix from edge rails to my Rails 2.1.0 project. I thought about applying it directly to vendor/rails since the next release of Rails should include the fix. And of course, I would have written a test for it to make sure it did. But team policy was to avoid making changes directly to vendor. So I decided to make an extension to override the buggy Rails method. I didn't want the code to stick around after we updated Rails though. At that point it would become unnecessary, and only increase the chances that the fix might be incompatible with something else in Rails. So I wrote a test that would fail when we updated to the next version of Rails.


test "this is only necessary for rails 2.1.0" do
  assert_equal "2.1.0", Rails::VERSION::STRING
  # we can remove this code once we update to the next version of rails
  # (as long as the tests for the fix still pass)
end

You could use this technique for any reminder that you need to give to somebody updating a dependency.

Database Changes

"How are we going to remember to use the AFTER option when we add a column?"

I usually use the MySQL AFTER option when adding columns to database tables so that they're alphabetized. It makes it easier to run a SELECT * query and then look for a certain column, especially if the table has more than a handful of columns. But it's easy to forget to add a column that way. Hence, a test as a reminder.


test "columns are in alphabetical order" do
  # use add_column .... :after => "existing_column" to insert sorted
  ActiveRecord::Base.connection.tables.each do |table|
    columns = ActiveRecord::Base.connection.columns(table).map(&:name)
    columns -= ["id"]
    assert_equal columns.sort, columns
  end
end

Embedded Images

Here's an example from CarePages' domain. CarePages sends welcome e-mails on the behalf of providers and affiliates to new users. Unfortunately, we noticed that some of the welcome messages (which are stored in the database) had image tags embedded directly in them. This meant that if we ever moved the image file, we would break the welcome message. The best solution would have been to change the messages in a way that would make sure moving an image file wouldn't break the message. But under time constraints, we decided to just write a test that those images were there.


test "embedded images are present" do
  # if any of these files move
  # welcome message that will need to be updated
  assert File.exists?("#{RAILS_ROOT}/public/images/clients/some_image.jpg")
  assert File.exists?("#{RAILS_ROOT}/public/images/clients/another_image.jpg")
end

This way, if anybody moves the image file, they also know to update the welcome message.

Summary

Using tests for reminders is a great way to make sure you don't forget anything. But don't go overboard with it. You shouldn't have reminder tests failing daily - unless you're team is really forgetful about something they need to be doing all the time.

comments | twitter

Rails: Performance Tuning Workflow

Dan Manges — Sun, 21 Sep 2008 08:07:32 GMT

Note: Even if you're familiar with benchmarking and profiling, take a look at the profiling section of this post. There's a nice helper method and an interesting real world example.

Improving the runtime for a page from 0.75 to 0.25 seconds may not make much of a difference to the end user's experience. But it triples the number of requests that your app servers can handle. This post covers improving performance at this level. Before you get here, you need to have your database well tuned with proper indexes, etc. Going through this workflow will make your website a little snappier and increase your overall capacity. I recently went through this process with CarePages, and we were able to make significant performance improvements in one afternoon.

CPU Time is Precious

The first performance bottleneck for a web app is always external resources. Most web apps use a database, so that's the common resource that can slow down your web app. But let's say your database is well indexed and handling the load of the web app fine. Also, let's assume that you don't have any other slow external resources like webservices that you call. The next bottleneck is usually the CPU if you have your own servers. If your website is running on a small slice or on shared hosting, you might hit memory limits before you max out the CPU.

Consider a box with 8 CPU cores and 4 GB of memory. 8 Rails processes with no slow external resources could likely max out 8 CPU cores. But for the example let's say it takes 16 Rails processes under full utilization to max out the CPU. Even if each Rails instance is using 150 MB of memory, that's only 2.4 GB of memory.

So if CPU time is your precious resource, you need to know how you're spending it. It helps if you have some custom logging in place, but essentially the information that you need is which page is taking up the most CPU time. It might not be your slowest page. You need to multiply the mean runtime for a page by the number of times it's hit. So if one page averages 0.2 seconds runtime, but it gets hit 20 times more frequently than a page that takes 1 second, you're spending four times as much time processing the 0.2 second page.

Note that when I'm referring to a page, I mean the controller and action. For example, I'm not considering /people/1 and /people/3 separate pages - they're both the people/show page.

At CarePages we have an Apache log that logs the controller, action, and Rails runtime. We run a script that groups the runtimes by controller and action, and then calculates the total runtime for a controller/action divided by the total runtime for all requests. What we found the first time we did this was that one of our pages was taking nearly 40% of the overall CPU time. It wasn't the slowest page, but it was the most frequently hit page. We had two other pages that were taking about 19% and 13% of the overall CPU time. This gave us a good place to start - if we could make the 40% page twice as fast, we would lower our overall CPU usage by 20%.

If you go through this process and find a relatively even distribution of CPU time across pages, you should look for ways to improve performance across the board rather than focusing on improving the performance of a few individual pages.

Benchmarking

So now that you have a page to work on, it's time to benchmark. There are tools for Benchmarking in the form of Rails tests, and Rails 2.1 and 2.2 will have more of these tools, but I find that it's easiest to benchmark by hitting a web server. A QA environment is usually perfect for this as it will have hardware that is comparable to the hardware being used in production.

The goal of benchmarking to produce a baseline. We need to be able to make changes and know if those changes make things better, worse, or have no effect.

I usually use curl or apache bench for benchmarking. With either tool, you need to log in to your web app, navigate to the page you want to benchmark, and then grab the session cookie. Firefox's web developer toolbar provides a nice view of the cookies.

Once you have the cookie, hit the page using curl a few times and grep for the X-Runtime response header. I'm going to go through these steps myself right now so I can provide a real world example and get some work done while blogging. Replace the cookie and URLs that I'm using with URLs for your app.

curl --silent --head \
  --cookie "_carepages_session=eb52948f037bda387dfa9d83b6bad62986a624cf" \
  http://undisclosed.carepages.com/forums/cancer | grep X-Runtime

Throw it in a bash while loop to hit the page a few times.

while true; do curl --silent --head \
  --cookie "_carepages_session=eb52948f037bda387dfa9d83b6bad62986a624cf" \
  http://undisclosed.carepages.com/forums/cancer | grep X-Runtime; done

You should get a list of runtimes.

  X-Runtime: 0.32921
  X-Runtime: 0.33260
  X-Runtime: 0.33032
  X-Runtime: 0.33234
  X-Runtime: 0.33143
  X-Runtime: 0.33070
  X-Runtime: 0.33100
  X-Runtime: 0.32865
  X-Runtime: 0.33608

You can also use apache bench, which will calculate the mean response time per request.

ab -c 1 -n 20 \
  -C "_carepages_session=eb52948f037bda387dfa9d83b6bad62986a624cf" \
  http://undisclosed.carepages.com/forums/cancer

That command will make 20 requests, 1 at a time. Look for the time per request in the output. It should be fairly close to the X-Runtime values.

...
Time per request: 336.413 [ms] (mean)
...

Hopefully you get fairly consistent response times. If not, you'll need to keep the inconsistency in mind while making changes.

Now you have a baseline. In my output, I'm hitting the /forums/cancer page for CarePages. It consistently takes around 0.33 seconds to process.

Profiling

The next question is why is this page taking X seconds to process? You need to profile the code to find out where you're spending those CPU cycles. To do this you'll need to install the ruby-prof gem.

It's easiest to start by profiling the entire processing for a request, and then making it more focused only if necessary. I use an around_filter in my ApplicationController to make profiling easier.


require "ruby-prof"
class ApplicationController < ActionController::Base
  around_filter :profile
  
  def profile
    return yield if params[:profile].nil?
    result = RubyProf.profile { yield }
    printer = RubyProf::GraphPrinter.new(result)
    out = StringIO.new
    printer.print(out, 0)
    response.body.replace out.string
    response.content_type = "text/plain"
  end
end

This allows you to profile a request by tacking ?profile=true on to the end of a URL. The response will then contain the profiling results instead of the normal response body. You may want to add a line of code so that this is only available in non-production environments. You also could update this code to embed the profiling in the response body rather than replacing the entire body with it.

I'm going to use this to profile the cancer forum page that I benchmarked by opening http://undisclosed.carepages.com/forums/cancer?profile=true in my browser. If you do the same for your web app, you should get the profiling results back in plain text call graph form.

Here's a snippet of output from the profiling that I just did that looks quite suspicious. (I removed a few columns to make the output narrower).

--------------------------------------------------------------------------------
                      0.55      96/96     Rsm::SeoUrls::InstanceMethods#to_param
  65.48%   0.00%      0.55         96     Rsm::SeoUrls::InstanceMethods#seo_urls_permalink
                      0.00     96/281     String#tr
                      0.00     96/408     String#downcase
                      0.55    192/192     ActiveRecord::Base#attributes
                      0.00     96/283     String#+
                      0.00    96/1914     String#strip
                      0.00  192/12138     Hash#[]
                      0.00    96/2035     String#gsub
                      0.00   96/10887     Kernel#nil?
                      0.00    96/7006     String#to_s
                      0.00      96/96     String#squeeze
                      0.00    192/192     Topic#attribute_for_url
--------------------------------------------------------------------------------

The percentage in the left column is the percent of the total processing time that a certain method took. You want to look for anything that jumps out as taking longer than you think it should.

This chunk of profiling means that 65.48% of the time spent processing /forums/cancer was inside the Rsm::SeoUrls::InstanceMethods#seo_urls_permalink method. Spending more than half of the processing time generating permalinks is way too long.

Let's take a look at the seo_urls_permalink method from the seo_urls plugin.


def seo_urls_permalink
  if !self.attributes[attribute_for_url]
    begin
      string=self.title
    rescue
      begin
        string=self.name
      rescue
        raise("No attribute was specified for seo_urls to use and 'name' and 'title' weren't available")
      end
    end
  else
    string=self.attributes[attribute_for_url]
  end
  if string.nil?
    return ""
  else
    t = "-"+(string.to_s.downcase.strip.gsub(/[^-_\s[:alnum:]]/, '').squeeze(' ').tr(' ', '-'))
  end
end

There are definitely a few inefficiencies here. The first is the multiple rescues. They're pointless - Ruby's respond_to? method should be used instead. The other inefficiency is the call to attributes. We only need to access one attribute, but we're accessing the entire hash. This wouldn't be a problem, except that Rails does typecasting when accessing the attributes. In particular the time zone conversion on time columns is a little slow. Let's rewrite this method.


def seo_urls_permalink
  attr = attribute_for_url
  attr = :title if attr.nil? && respond_to?(:title)
  attr = :name if attr.nil? && respond_to?(:name)
  unless attr
    raise("No attribute was specified for seo_urls to use and 'name' and 'title' weren't available")
  end
  string = send(attr)
  return "" if string.nil?
  "-"+(string.to_s.downcase.strip.gsub(/[^-_\s[:alnum:]]/, '').squeeze(' ').tr(' ', '-'))
end

I ran the tests for the seo_urls plugin, and they passed. It's time to find out if this change makes a difference by running the benchmarks again.

while true; do curl --silent --head \
  --cookie "_carepages_session=eb52948f037bda387dfa9d83b6bad62986a624cf" \
  http://undisclosed.carepages.com/forums/cancer | grep X-Runtime; done

  X-Runtime: 0.07943
  X-Runtime: 0.16852
  X-Runtime: 0.07982
  X-Runtime: 0.16367
  X-Runtime: 0.07924
  X-Runtime: 0.16349
  X-Runtime: 0.07905
  X-Runtime: 0.16404
  X-Runtime: 0.07916
  X-Runtime: 0.16441
  X-Runtime: 0.07875

Awesome. The processing time is now half of what is was before. I'll submit a patch for the seo_urls plugin. Interestingly, some response times are quite a bit faster than others. I may be hitting the point where garbage collection is kicking in more during some requests than during others.

Here's the new profiling for my /forums/cancer page, looking at the seo_urls_permalink method.

--------------------------------------------------------------------------------
                      0.01        96/96     Rsm::SeoUrls::InstanceMethods#to_param
   4.76%   0.00%      0.01           96     Rsm::SeoUrls::InstanceMethods#seo_urls_permalink
                      0.00       58/333     Kernel#send-3
                      0.00      96/2207     String#to_s
                      0.00        96/96     String#squeeze
                      0.01        10/13     Kernel#send-5
                      0.00       96/282     String#tr
                      0.00       96/217     String#downcase
                      0.00       96/283     String#+
                      0.00       96/186     String#strip
                      0.00      96/2041     String#gsub
                      0.00      96/1766     Kernel#nil?
                      0.00      192/192     ActiveRecord::AttributeMethods#respond_to?
                      0.00       28/578     Kernel#send-2
--------------------------------------------------------------------------------

I'm now spending 4.76% of the total processing time in seo_urls_permalink, compared to 65.48% before.

Repeat

Continue repeating this process until the processing time distribution per controller and action is mostly even. At that point, it's time to look to improve the performance of the pages with the slowest mean processing time. Or you could look for ways to improve the performance of every page.

Don't get too caught up on the distribution though. If you have a page that takes 20% of the overall processing for your site, but you don't see any easy wins, take a look at the next page. Doubling the speed of page that takes 10% of the overall time will still increase capacity by 5%.

comments | twitter

Asset Versioning in Rails

Dan Manges — Sat, 06 Sep 2008 19:47:31 GMT

<script src="/javascripts/jquery.js?1212761793" type="text/javascript"></script>

"What are those numbers Rails puts after my image, css, and javascript files?"
— Some Rails developer

That's the time (cast to an integer) that the file was last modified. Rails tags assets with a timestamp to solve potential issues with browser caching and to improve page load time.

Whenever the file changes, the query string will change, causing browsers to download a fresh version of the asset instead of using a cached copy. This ensures that users will never be using an old css/js/image file. Because the query string will change any time the file changes, you can set a far future expires header, telling the browser that it can cache the asset indefinitely.

Rails takes care of the query string, but you need to set up the expires header in your web server config.

Setting a Far Future Expires Header

The Rails documentation provides the following sample configuration to set the expires header in Apache.

ExpiresActive On
<FilesMatch "\.(ico|gif|jpe?g|png|js|css)$">
  ExpiresDefault "access plus 1 year"
</FilesMatch>

But there could be a problem with setting the expires header this way. If you have an image/css/js file that does not have a version, when you update that file, your users will still be using the old copy that's cached in their browser. Because the response header told the browser to cache the file as long as it wants to, it could be a while before the user gets the new version.

You really only want to set the expires header when serving up versioned assets. Here's one way to do that with Apache.

RewriteCond %{REQUEST_URI} (css|js|jpe?g|png|gif|ico)$ [NC]
RewriteCond %{QUERY_STRING} ^[0-9]+$
RewriteRule ^(.*)$ $1 [E=set_expires_header:true,L]

Header add Expires "Wed, 04 Aug 2010 16:46:21 -0500" env=set_expires_header

I'm not an Apache guru, so there may be a more elegant way to do this. Also, on the project where I'm doing this, the Apache config file is generated. We set the expires header to 2 years from the time of the file generation. I don't know of a way to dynamically set the date otherwise.

We can use curl to check that requesting the image with the asset version will set the expires header.

$ curl --head http://localhost:9999/images/rails.png?1213412
HTTP/1.1 200 OK
Date: Fri, 05 Sep 2008 02:34:25 GMT
Server: Apache/2.2.8 (Unix) mod_ssl/2.2.8 OpenSSL/0.9.7l Phusion_Passenger/2.0.2
Last-Modified: Thu, 04 Sep 2008 13:40:13 GMT
Accept-Ranges: bytes
Content-Length: 6646
Expires: Wed, 04 Aug 2010 16:46:21 -0500
Content-Type: image/png

And if we request the image without the version, there's no expires header.

$ curl --head http://localhost:9999/images/rails.png
HTTP/1.1 200 OK
Date: Fri, 05 Sep 2008 02:34:13 GMT
Server: Apache/2.2.8 (Unix) mod_ssl/2.2.8 OpenSSL/0.9.7l Phusion_Passenger/2.0.2
Last-Modified: Thu, 04 Sep 2008 13:40:13 GMT
Accept-Ranges: bytes
Content-Length: 6646
Content-Type: image/png

Forcing the Browser to Update Its Cache

You want to make sure that whenever you update your asset files, your users aren't using a stale cached copy. Rails takes care of this, because whenever the query string after the file changes, the browser will treat it like a new file and download it. I read that (according to the HTTP spec) Safari won't cache files that use a query string, but I did some testing with Safari 3.1.2 on OS X and that doesn't appear to be true.

The only thing that you have to do to update the query string is modify and file and possibly restart your app server. As of Rails 2.1, the query string won't change unless you restart your server. Older versions of Rails will update it without the restart. In practice, the Rails 2.1 behavior is fine since you only update files when doing deployments, and you're restarting your server then anyway.

Even if you're not setting the far-future expires header, it's a good idea to version your assets. Browsers will cache files without any expires header for a while, and some users are going to be behind proxies that have their own crazy caching strategy.

There's a few more good practices with asset versioning that Rails doesn't do for you - I'll be blogging about them soon.

comments | twitter

Deploying from a Subversion Tag using Vlad

Dan Manges — Wed, 27 Aug 2008 03:18:15 GMT

On the Rails project I'm currently working on, the team decided to use Vlad for deployment. If you're not familiar with Vlad, it's just like Capistrano with 2 big architectural differences.

(1) Vlad uses the command line ssh client instead of using net/ssh.
(2) Vlad uses Rake for tasks, and Capistrano has its own task system.

Deploying from a subversion tag using Capistrano is pretty easy: all you have to do is set the repository to the tag you want to deploy from. We can use the same approach in Vlad, but we need an additional step.

Before we get there, the first step is to write a task to prompt for the tag to use.


namespace :vlad do
  task :set_repository do
    tag = Readline.readline("tag to deploy (or trunk): ")
    if tag == "trunk"
      set :repository, "http://repo/trunk/"
    else
      set :repository, "http://repo/tags/#{tag}"
    end
  end
end

We then need to make the update task depend on the set_repository task.


namespace :vlad
  remote_task :update => %w[set_repository]
end

Due to how Vlad checks out the code, there's one more step. Vlad makes deployments faster by having an scm directory where the code is checked out. It does a checkout to the scm directory and exports from there to a release directory. The problem is if we had previously deployed trunk, but are now trying to deploy a tag, Vlad will try to checkout the tag on top of the trunk checkout, which subversion complains about.

svn: '.' is already a working copy for a different URL

We can fix this by modifying the update task to do an svn switch on the scm directory.


namespace :vlad do
  namespace :svn do
    remote_task :switch, :roles => [:app] do
      run "if [[ -d #{scm_path}/.svn ]]; then cd #{scm_path} && svn switch #{repository}; fi"
    end
  end
  
  remote_task :update => %w[set_repository svn:switch]
end

The if statement is there so that this task doesn't fail on the very first checkout to the scm directory.

I looked through the code, but couldn't find a built-in way to make this easier. But perhaps I overlooked something. This is using Vlad 1.2.0.

comments | twitter