Merge branch 'reduce-instrumentation-overhead' into 'master'

Reduce instrumentation overhead

## What does this MR do?

This MR reduces the overhead of instrumented methods. See the commit message of 905f8d76 for more information.

## Are there points in the code the reviewer needs to double check?

Not that I can think of.

## Why was this MR needed?

The overhead of method call instrumentation was too great.

## Does this MR meet the acceptance criteria?

- [x] [CHANGELOG](https://gitlab.com/gitlab-org/gitlab-ce/blob/master/CHANGELOG) entry added
- [x] ~~[Documentation created/updated](https://gitlab.com/gitlab-org/gitlab-ce/blob/master/doc/development/doc_styleguide.md)~~
- [x] ~~API support added~~
- Tests
  - [x] Added for this feature/bug
  - [ ] All builds are passing
- [x] Conform by the [style guides](https://gitlab.com/gitlab-org/gitlab-ce/blob/master/CONTRIBUTING.md#style-guides)
- [x] Branch has no merge conflicts with `master` (if you do - rebase it please)
- [x] [Squashed related commits together](https://git-scm.com/book/en/Git-Tools-Rewriting-History#Squashing-Commits)

See merge request !5550

CHANGELOG

@@ -15,6 +15,7 @@ v 8.11.0 (unreleased)
   - Add build event color in HipChat messages (David Eisner)
   - Make fork counter always clickable. !5463 (winniehell)
   - All created issues, API or WebUI, can be submitted to Akismet for spam check !5333
+  - The overhead of instrumented method calls has been reduced
   - Remove `search_id` of labels dropdown filter to fix 'Missleading URI for labels in Merge Requests and Issues view'. !5368 (Scott Le)
   - Load project invited groups and members eagerly in `ProjectTeam#fetch_members`
   - Make branches sortable without push permission !5462 (winniehell)

lib/gitlab/metrics.rb

@@ -124,6 +124,11 @@ module Gitlab
       trans.action = action if trans
     end
 
+    # Returns the prefix to use for the name of a series.
+    def self.series_prefix
+      @series_prefix ||= Sidekiq.server? ? 'sidekiq_' : 'rails_'
+    end
+
     # When enabled this should be set before being used as the usual pattern
     # "@foo ||= bar" is _not_ thread-safe.
     if enabled?

lib/gitlab/metrics/instrumentation.rb

@@ -9,14 +9,17 @@ module Gitlab
     #
     #     Gitlab::Metrics::Instrumentation.instrument_method(User, :by_login)
     module Instrumentation
-      SERIES = 'method_calls'
-
       PROXY_IVAR = :@__gitlab_instrumentation_proxy
 
       def self.configure
         yield self
       end
 
+      # Returns the name of the series to use for storing method calls.
+      def self.series
+        @series ||= "#{Metrics.series_prefix}method_calls"
+      end
+
       # Instruments a class method.
       #
       # mod  - The module to instrument as a Module/Class.
@@ -141,15 +144,15 @@ module Gitlab
         # generated method _only_ accepts regular arguments if the underlying
         # method also accepts them.
         if method.arity == 0
-          args_signature = '&block'
+          args_signature = ''
         else
-          args_signature = '*args, &block'
+          args_signature = '*args'
         end
 
         proxy_module.class_eval <<-EOF, __FILE__, __LINE__ + 1
           def #{name}(#{args_signature})
             if trans = Gitlab::Metrics::Instrumentation.transaction
-              trans.measure_method(#{label.inspect}) { super }
+              trans.method_call_for(#{label.to_sym.inspect}).measure { super }
             else
               super
             end

lib/gitlab/metrics/method_call.rb

@@ -11,8 +11,8 @@ module Gitlab
       def initialize(name, series)
         @name = name
         @series = series
-        @real_time = 0.0
-        @cpu_time = 0.0
+        @real_time = 0
+        @cpu_time = 0
         @call_count = 0
       end
 

lib/gitlab/metrics/system.rb

@@ -35,12 +35,12 @@ module Gitlab
       if Process.const_defined?(:CLOCK_THREAD_CPUTIME_ID)
         def self.cpu_time
           Process.
-            clock_gettime(Process::CLOCK_THREAD_CPUTIME_ID, :millisecond).to_f
+            clock_gettime(Process::CLOCK_THREAD_CPUTIME_ID, :millisecond)
         end
       else
         def self.cpu_time
           Process.
-            clock_gettime(Process::CLOCK_PROCESS_CPUTIME_ID, :millisecond).to_f
+            clock_gettime(Process::CLOCK_PROCESS_CPUTIME_ID, :millisecond)
         end
       end
 
@@ -48,14 +48,14 @@ module Gitlab
       #
       # Returns the time as a Float.
       def self.real_time(precision = :millisecond)
-        Process.clock_gettime(Process::CLOCK_REALTIME, precision).to_f
+        Process.clock_gettime(Process::CLOCK_REALTIME, precision)
       end
 
       # Returns the current monotonic clock time in a given precision.
       #
       # Returns the time as a Float.
       def self.monotonic_time(precision = :millisecond)
-        Process.clock_gettime(Process::CLOCK_MONOTONIC, precision).to_f
+        Process.clock_gettime(Process::CLOCK_MONOTONIC, precision)
       end
     end
   end

lib/gitlab/metrics/transaction.rb

@@ -52,23 +52,16 @@ module Gitlab
       end
 
       def add_metric(series, values, tags = {})
-        @metrics << Metric.new("#{series_prefix}#{series}", values, tags)
+        @metrics << Metric.new("#{Metrics.series_prefix}#{series}", values, tags)
       end
 
-      # Measures the time it takes to execute a method.
-      #
-      # Multiple calls to the same method add up to the total runtime of the
-      # method.
-      #
-      # name - The full name of the method to measure (e.g. `User#sign_in`).
-      def measure_method(name, &block)
-        unless @methods[name]
-          series = "#{series_prefix}#{Instrumentation::SERIES}"
-
-          @methods[name] = MethodCall.new(name, series)
+      # Returns a MethodCall object for the given name.
+      def method_call_for(name)
+        unless method = @methods[name]
+          @methods[name] = method = MethodCall.new(name, Instrumentation.series)
         end
 
-        @methods[name].measure(&block)
+        method
       end
 
       def increment(name, value)
@@ -115,14 +108,6 @@ module Gitlab
 
         Metrics.submit_metrics(submit_hashes)
       end
-
-      def sidekiq?
-        Sidekiq.server?
-      end
-
-      def series_prefix
-        sidekiq? ? 'sidekiq_' : 'rails_'
-      end
     end
   end
 end

spec/lib/gitlab/metrics/instrumentation_spec.rb

@@ -39,6 +39,12 @@ describe Gitlab::Metrics::Instrumentation do
     allow(@dummy).to receive(:name).and_return('Dummy')
   end
 
+  describe '.series' do
+    it 'returns a String' do
+      expect(described_class.series).to be_an_instance_of(String)
+    end
+  end
+
   describe '.configure' do
     it 'yields self' do
       described_class.configure do |c|
@@ -78,8 +84,7 @@ describe Gitlab::Metrics::Instrumentation do
         allow(described_class).to receive(:transaction).
           and_return(transaction)
 
-        expect(transaction).to receive(:measure_method).
-          with('Dummy.foo')
+        expect_any_instance_of(Gitlab::Metrics::MethodCall).to receive(:measure)
 
         @dummy.foo
       end
@@ -157,8 +162,7 @@ describe Gitlab::Metrics::Instrumentation do
         allow(described_class).to receive(:transaction).
           and_return(transaction)
 
-        expect(transaction).to receive(:measure_method).
-          with('Dummy#bar')
+        expect_any_instance_of(Gitlab::Metrics::MethodCall).to receive(:measure)
 
         @dummy.new.bar
       end

spec/lib/gitlab/metrics/system_spec.rb

@@ -28,20 +28,20 @@ describe Gitlab::Metrics::System do
   end
 
   describe '.cpu_time' do
-    it 'returns a Float' do
-      expect(described_class.cpu_time).to be_an_instance_of(Float)
+    it 'returns a Fixnum' do
+      expect(described_class.cpu_time).to be_an_instance_of(Fixnum)
     end
   end
 
   describe '.real_time' do
-    it 'returns a Float' do
-      expect(described_class.real_time).to be_an_instance_of(Float)
+    it 'returns a Fixnum' do
+      expect(described_class.real_time).to be_an_instance_of(Fixnum)
     end
   end
 
   describe '.monotonic_time' do
-    it 'returns a Float' do
-      expect(described_class.monotonic_time).to be_an_instance_of(Float)
+    it 'returns a Fixnum' do
+      expect(described_class.monotonic_time).to be_an_instance_of(Fixnum)
     end
   end
 end

spec/lib/gitlab/metrics/transaction_spec.rb

@@ -46,19 +46,11 @@ describe Gitlab::Metrics::Transaction do
     end
   end
 
-  describe '#measure_method' do
-    it 'adds a new method if it does not exist already' do
-      transaction.measure_method('Foo#bar') { 'foo' }
+  describe '#method_call_for' do
+    it 'returns a MethodCall' do
+      method = transaction.method_call_for('Foo#bar')
 
-      expect(transaction.methods['Foo#bar']).
-        to be_an_instance_of(Gitlab::Metrics::MethodCall)
-    end
-
-    it 'adds timings to an existing method call' do
-      transaction.measure_method('Foo#bar') { 'foo' }
-      transaction.measure_method('Foo#bar') { 'foo' }
-
-      expect(transaction.methods['Foo#bar'].call_count).to eq(2)
+      expect(method).to be_an_instance_of(Gitlab::Metrics::MethodCall)
     end
   end
 

spec/lib/gitlab/metrics_spec.rb

@@ -147,4 +147,10 @@ describe Gitlab::Metrics do
       end
     end
   end
+
+  describe '#series_prefix' do
+    it 'returns a String' do
+      expect(described_class.series_prefix).to be_an_instance_of(String)
+    end
+  end
 end