Merge branch '18528-cpu-time-instrumentation' into 'master'

Measure CPU time for instrumented methods

See merge request !4640

CHANGELOG

@@ -77,6 +77,7 @@ v 8.9.0 (unreleased)
   - All classes in the Banzai::ReferenceParser namespace are now instrumented
   - Remove deprecated issues_tracker and issues_tracker_id from project model
   - Allow users to create confidential issues in private projects
+  - Measure CPU time for instrumented methods
 
 v 8.8.5 (unreleased)
   - Ensure branch cleanup regardless of whether the GitHub import process succeeds

doc/development/instrumentation.md

@@ -97,15 +97,16 @@ def #{name}(#{args_signature})
   trans = Gitlab::Metrics::Instrumentation.transaction
 
   if trans
-    start    = Time.now
-    retval   = super
-    duration = (Time.now - start) * 1000.0
+    start     = Time.now
+    cpu_start = Gitlab::Metrics::System.cpu_time
+    retval    = super
+    duration  = (Time.now - start) * 1000.0
 
     if duration >= Gitlab::Metrics.method_call_threshold
-      trans.increment(:method_duration, duration)
+      cpu_duration = Gitlab::Metrics::System.cpu_time - cpu_start
 
       trans.add_metric(Gitlab::Metrics::Instrumentation::SERIES,
-                       { duration: duration },
+                       { duration: duration, cpu_duration: cpu_duration },
                        method: #{label.inspect})
     end
 

lib/gitlab/metrics/instrumentation.rb

@@ -149,13 +149,16 @@ module Gitlab
             trans = Gitlab::Metrics::Instrumentation.transaction
 
             if trans
-              start    = Time.now
-              retval   = super
-              duration = (Time.now - start) * 1000.0
+              start     = Time.now
+              cpu_start = Gitlab::Metrics::System.cpu_time
+              retval    = super
+              duration  = (Time.now - start) * 1000.0
 
               if duration >= Gitlab::Metrics.method_call_threshold
+                cpu_duration = Gitlab::Metrics::System.cpu_time - cpu_start
+
                 trans.add_metric(Gitlab::Metrics::Instrumentation::SERIES,
-                                 { duration: duration },
+                                 { duration: duration, cpu_duration: cpu_duration },
                                  method: #{label.inspect})
               end
 

spec/lib/gitlab/metrics/instrumentation_spec.rb

@@ -57,7 +57,7 @@ describe Gitlab::Metrics::Instrumentation do
           and_return(transaction)
 
         expect(transaction).to receive(:add_metric).
-          with(described_class::SERIES, an_instance_of(Hash),
+          with(described_class::SERIES, hash_including(:duration, :cpu_duration),
                method: 'Dummy.foo')
 
         @dummy.foo
@@ -137,7 +137,7 @@ describe Gitlab::Metrics::Instrumentation do
           and_return(transaction)
 
         expect(transaction).to receive(:add_metric).
-          with(described_class::SERIES, an_instance_of(Hash),
+          with(described_class::SERIES, hash_including(:duration, :cpu_duration),
                method: 'Dummy#bar')
 
         @dummy.new.bar