Fix rspec errors, and add more tests to MethodCall and ActionView

lib/gitlab/metrics/method_call.rb

@@ -42,14 +42,16 @@ module Gitlab
         start_cpu = System.cpu_time
         retval = yield
 
-        @real_time += System.monotonic_time - start_real
+        real_time = System.monotonic_time - start_real
+        cpu_time = System.cpu_time - start_cpu
+
+        @real_time += real_time
+
         @cpu_time += System.cpu_time - start_cpu
         @call_count += 1
 
-        if above_threshold?
-          self.class.call_real_duration_histogram.observe(@transaction.labels.merge(labels), @real_time / 1000.0)
-          self.class.call_cpu_duration_histogram.observe(@transaction.labels.merge(labels), @cpu_time / 1000.0)
-        end
+        self.class.call_real_duration_histogram.observe(@transaction.labels.merge(labels), real_time / 1000.0)
+        self.class.call_cpu_duration_histogram.observe(@transaction.labels.merge(labels), cpu_time / 1000.0)
 
         retval
       end

lib/gitlab/metrics/subscribers/action_view.rb

@@ -15,10 +15,24 @@ module Gitlab
 
         private
 
+        def self.metric_view_rendering_duration_seconds
+          @metric_view_rendering_duration_seconds ||= Gitlab::Metrics.histogram(
+            :gitlab_view_rendering_duration_seconds,
+            'View rendering time',
+            Transaction::BASE_LABELS.merge({ path: nil }),
+            [0.001, 0.002, 0.005, 0.01, 0.02, 0.05, 0.1, 0.500, 2.0, 10.0]
+          )
+        end
+
         def track(event)
           values = values_for(event)
           tags   = tags_for(event)
 
+          self.class.metric_view_rendering_duration_seconds.observe(
+            current_transaction.labels.merge(tags),
+            event.duration
+          )
+
           current_transaction.increment(:view_duration, event.duration)
           current_transaction.add_metric(SERIES, values, tags)
         end

spec/initializers/8_metrics_spec.rb

@@ -3,7 +3,6 @@ require 'spec_helper'
 describe 'instrument_classes' do
   let(:config) { double(:config) }
 
-  let(:unicorn_sampler) { double(:unicorn_sampler) }
   let(:influx_sampler) { double(:influx_sampler) }
 
   before do
@@ -11,9 +10,7 @@ describe 'instrument_classes' do
     allow(config).to receive(:instrument_methods)
     allow(config).to receive(:instrument_instance_method)
     allow(config).to receive(:instrument_instance_methods)
-    allow(Gitlab::Metrics::UnicornSampler).to receive(:initialize_instance).and_return(unicorn_sampler)
-    allow(Gitlab::Metrics::InfluxSampler).to receive(:initialize_instance).and_return(influx_sampler)
-    allow(unicorn_sampler).to receive(:start)
+    allow(Gitlab::Metrics::Samplers::InfluxSampler).to receive(:initialize_instance).and_return(influx_sampler)
     allow(influx_sampler).to receive(:start)
     allow(Gitlab::Application).to receive(:configure)
   end

spec/lib/gitlab/metrics/method_call_spec.rb

 require 'spec_helper'
 
 describe Gitlab::Metrics::MethodCall do
-  let(:method_call) { described_class.new('Foo#bar', 'foo') }
+  let(:transaction) { double(:transaction, labels: {}) }
+  let(:method_call) { described_class.new('Foo#bar', :Foo, '#bar', transaction) }
 
   describe '#measure' do
     it 'measures the performance of the supplied block' do
@@ -11,6 +12,18 @@ describe Gitlab::Metrics::MethodCall do
       expect(method_call.cpu_time).to be_a_kind_of(Numeric)
       expect(method_call.call_count).to eq(1)
     end
+
+    it 'observes the performance of the supplied block' do
+      expect(described_class.call_real_duration_histogram)
+        .to receive(:observe)
+              .with({ module: :Foo, method: '#bar' }, be_a_kind_of(Numeric))
+
+      expect(described_class.call_cpu_duration_histogram)
+        .to receive(:observe)
+              .with({ module: :Foo, method: '#bar' }, be_a_kind_of(Numeric))
+
+      method_call.measure { 'foo' }
+    end
   end
 
   describe '#to_metric' do
@@ -19,7 +32,7 @@ describe Gitlab::Metrics::MethodCall do
       metric = method_call.to_metric
 
       expect(metric).to be_an_instance_of(Gitlab::Metrics::Metric)
-      expect(metric.series).to eq('foo')
+      expect(metric.series).to eq('rails_method_calls')
 
       expect(metric.values[:duration]).to be_a_kind_of(Numeric)
       expect(metric.values[:cpu_duration]).to be_a_kind_of(Numeric)

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

 require 'spec_helper'
 
 describe Gitlab::Metrics::Subscribers::ActionView do
-  let(:transaction) { Gitlab::Metrics::Transaction.new }
+  let(:env) { {} }
+  let(:transaction) { Gitlab::Metrics::Transaction.new(env) }
 
   let(:subscriber) { described_class.new }
 
@@ -29,5 +30,14 @@ describe Gitlab::Metrics::Subscribers::ActionView do
 
       subscriber.render_template(event)
     end
+
+    it 'observes view rendering time' do
+
+      expect(described_class.metric_view_rendering_duration_seconds)
+        .to receive(:observe)
+              .with({ view: 'app/views/x.html.haml' }, 2.1)
+
+      subscriber.render_template(event)
+    end
   end
 end

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

@@ -64,7 +64,7 @@ describe Gitlab::Metrics::Subscribers::RailsCache do
         end
 
         it 'increments the cache_read_miss total' do
-          expect(described_class.metric_cache_read_miss_total).to receive(:increment)
+          expect(described_class.metric_cache_read_miss_total).to receive(:increment).with({})
 
           subscriber.cache_read(event)
         end
@@ -78,6 +78,12 @@ describe Gitlab::Metrics::Subscribers::RailsCache do
 
             subscriber.cache_read(event)
           end
+
+          it 'does not increment cache_read_miss total' do
+            expect(described_class.metric_cache_read_miss_total).not_to receive(:increment).with({})
+
+            subscriber.cache_read(event)
+          end
         end
       end
     end
@@ -131,6 +137,12 @@ describe Gitlab::Metrics::Subscribers::RailsCache do
 
         subscriber.cache_fetch_hit(event)
       end
+
+      it 'increments the cache_read_hit total' do
+        expect(described_class.metric_cache_read_hit_total).to receive(:increment).with({})
+
+        subscriber.cache_fetch_hit(event)
+      end
     end
   end
 
@@ -155,6 +167,12 @@ describe Gitlab::Metrics::Subscribers::RailsCache do
 
         subscriber.cache_generate(event)
       end
+
+      it 'increments the cache_read_miss total' do
+        expect(described_class.metric_cache_read_miss_total).to receive(:increment).with({})
+
+        subscriber.cache_generate(event)
+      end
     end
   end
 
@@ -188,6 +206,14 @@ describe Gitlab::Metrics::Subscribers::RailsCache do
 
         subscriber.observe(:delete, event.duration)
       end
+
+      it 'observes cache metric' do
+        expect(described_class.metric_cache_operation_duration_seconds)
+          .to receive(:observe)
+                .with(transaction.labels.merge(operation: :delete), event.duration/1000.0)
+
+        subscriber.observe(:delete, event.duration)
+      end
     end
   end
 end