simple performance stats on Rails cache usage

cache_instrumentation.rb

class CacheInstrumentation
  def self.filter(controller)
    begin
      cache_timing = { :min => nil, :max => nil, :keys => [], :count => 0, :total => 0.0 }

      # redefine Rails.cache.fetch for this request
      real_fetch_method = Rails.cache.method(:fetch)
      Rails.cache.metaclass.send(:define_method, :fetch) do |*args, &block|
        begin
          start_time = Time.now.to_f
          real_fetch_method.call(*args, &block)
        ensure
          elapsed = Time.now.to_f - start_time

          [:min, :max].each do |sym|
            cache_timing[sym] = [cache_timing[sym], elapsed].compact.send(sym)
          end
          cache_timing[:count] += 1
          cache_timing[:total] += elapsed
          cache_timing[:keys] << args.first.dup
        end
      end

      # Run the rest of the dispatch chain
      yield
    ensure
      average = cache_timing[:total] / cache_timing[:count].to_f rescue 0.0
      Rails.logger.debug "Cache Stats for #{controller.class}##{controller.action_name}:  Calls: #{cache_timing[:count]}  Unique Calls: #{cache_timing[:keys].uniq.size}  Total: #{millis(cache_timing[:total])}  Avg: #{millis(average)}  Min: #{millis(cache_timing[:min])}  Max: #{millis(cache_timing[:max])}"
      Rails.cache.metaclass.send(:define_method, :fetch, real_fetch_method) # un-monkey-patch
    end
  end

  # helper for above
  def self.millis(seconds)
    ms = seconds.nil? ? 0 : seconds * 1000
    '%.2f ms' % ms
  end
end


class ApplicationController
  around_filter CacheInstrumentation
end