Instrument Rails cache code

This allows us to track how much time of a transaction is spent in
dealing with cached data.

config/initializers/metrics.rb

@@ -7,6 +7,7 @@ if Gitlab::Metrics.enabled?
   # ActiveSupport.
   require 'gitlab/metrics/subscribers/action_view'
   require 'gitlab/metrics/subscribers/active_record'
+  require 'gitlab/metrics/subscribers/rails_cache'
 
   Gitlab::Application.configure do |config|
     config.middleware.use(Gitlab::Metrics::RackMiddleware)

lib/gitlab/metrics/subscribers/rails_cache.rb

@@ -0,0 +1,39 @@
+module Gitlab
+  module Metrics
+    module Subscribers
+      # Class for tracking the total time spent in Rails cache calls
+      class RailsCache < ActiveSupport::Subscriber
+        attach_to :active_support
+
+        def cache_read(event)
+          increment(:cache_read_duration, event.duration)
+        end
+
+        def cache_write(event)
+          increment(:cache_write_duration, event.duration)
+        end
+
+        def cache_delete(event)
+          increment(:cache_delete_duration, event.duration)
+        end
+
+        def cache_exist?(event)
+          increment(:cache_exists_duration, event.duration)
+        end
+
+        def increment(key, duration)
+          return unless current_transaction
+
+          current_transaction.increment(:cache_duration, duration)
+          current_transaction.increment(key, duration)
+        end
+
+        private
+
+        def current_transaction
+          Transaction.current
+        end
+      end
+    end
+  end
+end

spec/lib/gitlab/metrics/subscribers/rails_cache_spec.rb

@@ -0,0 +1,71 @@
+require 'spec_helper'
+
+describe Gitlab::Metrics::Subscribers::RailsCache do
+  let(:transaction) { Gitlab::Metrics::Transaction.new }
+  let(:subscriber) { described_class.new }
+
+  let(:event) { double(:event, duration: 15.2) }
+
+  describe '#cache_read' do
+    it 'increments the cache_read duration' do
+      expect(subscriber).to receive(:increment).
+        with(:cache_read_duration, event.duration)
+
+      subscriber.cache_read(event)
+    end
+  end
+
+  describe '#cache_write' do
+    it 'increments the cache_write duration' do
+      expect(subscriber).to receive(:increment).
+        with(:cache_write_duration, event.duration)
+
+      subscriber.cache_write(event)
+    end
+  end
+
+  describe '#cache_delete' do
+    it 'increments the cache_delete duration' do
+      expect(subscriber).to receive(:increment).
+        with(:cache_delete_duration, event.duration)
+
+      subscriber.cache_delete(event)
+    end
+  end
+
+  describe '#cache_exist?' do
+    it 'increments the cache_exists duration' do
+      expect(subscriber).to receive(:increment).
+        with(:cache_exists_duration, event.duration)
+
+      subscriber.cache_exist?(event)
+    end
+  end
+
+  describe '#increment' do
+    context 'without a transaction' do
+      it 'returns' do
+        expect(transaction).not_to receive(:increment)
+
+        subscriber.increment(:foo, 15.2)
+      end
+    end
+
+    context 'with a transaction' do
+      before do
+        allow(subscriber).to receive(:current_transaction).
+          and_return(transaction)
+      end
+
+      it 'increments the total and specific cache duration' do
+        expect(transaction).to receive(:increment).
+          with(:cache_duration, event.duration)
+
+        expect(transaction).to receive(:increment).
+          with(:cache_delete_duration, event.duration)
+
+        subscriber.increment(:cache_delete_duration, event.duration)
+      end
+    end
+  end
+end