From 120fbbd4875f340b5c863b7e0e3eabcb2796e15d Mon Sep 17 00:00:00 2001 From: Paco Guzman Date: Mon, 13 Jun 2016 18:41:37 +0200 Subject: [PATCH] Measure CPU time for instrumented methods --- CHANGELOG | 1 + doc/development/instrumentation.md | 11 ++++++----- lib/gitlab/metrics/instrumentation.rb | 11 +++++++---- spec/lib/gitlab/metrics/instrumentation_spec.rb | 4 ++-- 4 files changed, 16 insertions(+), 11 deletions(-) diff --git a/CHANGELOG b/CHANGELOG index 2aed8eb322b..e71a154d1d5 100644 --- a/CHANGELOG +++ b/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 diff --git a/doc/development/instrumentation.md b/doc/development/instrumentation.md index 9168c70945a..50d2866ca46 100644 --- a/doc/development/instrumentation.md +++ b/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 diff --git a/lib/gitlab/metrics/instrumentation.rb b/lib/gitlab/metrics/instrumentation.rb index 0f115893a15..ad9ce3fa442 100644 --- a/lib/gitlab/metrics/instrumentation.rb +++ b/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 diff --git a/spec/lib/gitlab/metrics/instrumentation_spec.rb b/spec/lib/gitlab/metrics/instrumentation_spec.rb index 220e86924a2..c6e979b69a4 100644 --- a/spec/lib/gitlab/metrics/instrumentation_spec.rb +++ b/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