Rack-Cache on Rails 3 - the unadvertised caching option

Mar 29, 2012 Published by Tony Primerano

Today I was poking around in the rails tmp/cache directory and I saw an entry I did not expect. It appeared that a controller action was being cached but I was not using, page, action or fragment caching.

I was setting an expiration header on the action response and as it turns out there is a handy gem in rails now called rack-cache. Rack-cache will create cache entries for items that you set future a expiration for. Since this isn't mentioned in the Rails Caching Guide it took me a little while to track it down.

Here's a quick example of it in action

Create a dummy app

rails new rack-cache
cd rack-cache
bundle exec rails generate controller RackCache cache_this

Edit the cache_this method

class RackCacheController < ApplicationController
def cache_this
    render :text => Time.zone.now.to_s
  end
end

Fire it up in production mode so caching is enabled

RAILS_ENV=production bundle exec rails s -p6666

When you hit the page in the browser and hit reload you'll see the time change

http://localhost:6666/rack_cache/cache_this

2012-03-29 00:40:09 UTC
2012-03-29 00:40:29 UTC

Now lets change the action slightly

class RackCacheController < ApplicationController
  def cache_this
    expires_in(5.minutes, :public => true)
    render :text => "The time is #{Time.zone.now.to_s}"
  end
end

Now each time you reload the page you get the same time

The time is 2012-03-29 00:58:07 UTC
The time is 2012-03-29 00:58:07 UTC

Without a reload the browser won't bother asking for the resource for another 5 minutes.  With the reload we get a 304 message.

Normally a simple clear of your browser cache would get you a new time but Rack-Cache also cached this on the server.  So clear all you want, you'll not get an update until 5 minutes after the time in the window.   If there are 10 folks hitting this page they will all see the same time.   The 1st person to hit it after expiration will update the time.

The time is 2012-03-29 01:04:01 UTC

So where is the output cached?  By default Rails used the ActiveSupport::Cache::FileStore which lives in tmp/cache -- configurable via config.cache_store.

ls -tr tmp/cache/
 assets    B15    2A5    A92    B2C    B31
 # B31 is newest dir
 find tmp/cache/B31
 tmp/cache/B31
 tmp/cache/B31/A20
 tmp/cache/B31/A20/1c4fa8db52f778f10f535fe2253f3a63f92fd87b

The cached response is in

tmp/cache/B31/A20/1c4fa8db52f778f10f535fe2253f3a63f92fd87b

cat tmp/cache/B31/A20/1c4fa8db52f778f10f535fe2253f3a63f92fd87b
 o: ActiveSupport::Cache::Entry    :@compressedF:@expires_in0:@created_atf1332983041.303097:
 @value[I"(The time is 2012-03-29 01:04:01 UTC:EF

This is a pretty powerful caching option that Rails developers should understand and use when appropriate.    In some cases, not knowing this feature was in place has broken applications. Maybe I'll edit the Rails Guide to include this information.

I noticed that rack-cache was filling our apache error log with entries

cache: [GET /somepath] miss
cache: [GET /anotherpath/logo?1333186605] fresh
cache: [POST /yet/another/path] invalidate, pass

Turn off the verbose option by adding this to your production.rb

config.action_dispatch.rack_cache =  {:metastore=>"rails:/", :entitystore=>"rails:/", :verbose=>false}

To disable rack-cache altogether just do this

config.action_dispatch.rack_cache =  nil

Some useful links

  • Thank you so much for this post! I have been banging my head against a wall because of rack caching for a while now. For the longest time I thought it was nginx doing this caching, because I saw nginx had the page hit, but not Rails. Then I recently had the revelation that perhaps it was Passenger doing the caching, which led me to the tmp/cache directory. When that didn't seem to be it, I finally landed here and was able to fix my issue!

  • A photo of Wm Lane Wm Lane says:

    tokens indicate that the item was not found in the cache but has been saved for the next request.

  • A photo of CaDs CaDs says:

    Man, you just make my day! Thanks thanks thanks thanks! I have been chasing this ghost for almost one week!