Commit 040167f0 authored by Pawel Chojnacki's avatar Pawel Chojnacki

Use seconds where possible, and convert to milliseconds for Influxdb consumption

parent ed715b79
---
title: Reduce the number of buckets in gitlab_cache_operation_duration_seconds
merge_request: 15881
author:
type: changed
...@@ -4,7 +4,7 @@ module Gitlab ...@@ -4,7 +4,7 @@ module Gitlab
class MethodCall class MethodCall
MUTEX = Mutex.new MUTEX = Mutex.new
BASE_LABELS = { module: nil, method: nil }.freeze BASE_LABELS = { module: nil, method: nil }.freeze
attr_reader :real_time_seconds, :cpu_time, :call_count, :labels attr_reader :real_time, :cpu_time, :call_count, :labels
def self.call_duration_histogram def self.call_duration_histogram
return @call_duration_histogram if @call_duration_histogram return @call_duration_histogram if @call_duration_histogram
...@@ -27,42 +27,38 @@ module Gitlab ...@@ -27,42 +27,38 @@ module Gitlab
@transaction = transaction @transaction = transaction
@name = name @name = name
@labels = { module: @module_name, method: @method_name } @labels = { module: @module_name, method: @method_name }
@real_time_seconds = 0.0 @real_time = 0.0
@cpu_time = 0 @cpu_time = 0.0
@call_count = 0 @call_count = 0
end end
# Measures the real and CPU execution time of the supplied block. # Measures the real and CPU execution time of the supplied block.
def measure def measure
start_real_seconds = System.monotonic_time start_real = System.monotonic_time
start_cpu = System.cpu_time start_cpu = System.cpu_time
retval = yield retval = yield
real_time_seconds = System.monotonic_time - start_real_seconds real_time = System.monotonic_time - start_real
cpu_time = System.cpu_time - start_cpu cpu_time = System.cpu_time - start_cpu
@real_time_seconds += real_time_seconds @real_time += real_time
@cpu_time += cpu_time @cpu_time += cpu_time
@call_count += 1 @call_count += 1
if call_measurement_enabled? && above_threshold? if call_measurement_enabled? && above_threshold?
self.class.call_duration_histogram.observe(@transaction.labels.merge(labels), real_time_seconds) self.class.call_duration_histogram.observe(@transaction.labels.merge(labels), real_time)
end end
retval retval
end end
def real_time_milliseconds
real_time_seconds.in_milliseconds.to_i
end
# Returns a Metric instance of the current method call. # Returns a Metric instance of the current method call.
def to_metric def to_metric
Metric.new( Metric.new(
Instrumentation.series, Instrumentation.series,
{ {
duration: real_time_milliseconds, duration: real_time.in_milliseconds.to_i,
cpu_duration: cpu_time, cpu_duration: cpu_time.in_milliseconds.to_i,
call_count: call_count call_count: call_count
}, },
method: @name method: @name
...@@ -72,7 +68,7 @@ module Gitlab ...@@ -72,7 +68,7 @@ module Gitlab
# Returns true if the total runtime of this method exceeds the method call # Returns true if the total runtime of this method exceeds the method call
# threshold. # threshold.
def above_threshold? def above_threshold?
real_time_milliseconds >= Metrics.method_call_threshold real_time.in_milliseconds >= Metrics.method_call_threshold
end end
def call_measurement_enabled? def call_measurement_enabled?
......
...@@ -35,19 +35,19 @@ module Gitlab ...@@ -35,19 +35,19 @@ module Gitlab
if Process.const_defined?(:CLOCK_THREAD_CPUTIME_ID) if Process.const_defined?(:CLOCK_THREAD_CPUTIME_ID)
def self.cpu_time def self.cpu_time
Process Process
.clock_gettime(Process::CLOCK_THREAD_CPUTIME_ID, :millisecond) .clock_gettime(Process::CLOCK_THREAD_CPUTIME_ID, :float_second)
end end
else else
def self.cpu_time def self.cpu_time
Process Process
.clock_gettime(Process::CLOCK_PROCESS_CPUTIME_ID, :millisecond) .clock_gettime(Process::CLOCK_PROCESS_CPUTIME_ID, :float_second)
end end
end end
# Returns the current real time in a given precision. # Returns the current real time in a given precision.
# #
# Returns the time as a Fixnum. # Returns the time as a Float for precision = :float_second.
def self.real_time(precision = :millisecond) def self.real_time(precision = :float_second)
Process.clock_gettime(Process::CLOCK_REALTIME, precision) Process.clock_gettime(Process::CLOCK_REALTIME, precision)
end end
......
...@@ -8,8 +8,7 @@ describe Gitlab::Metrics::MethodCall do ...@@ -8,8 +8,7 @@ describe Gitlab::Metrics::MethodCall do
it 'measures the performance of the supplied block' do it 'measures the performance of the supplied block' do
method_call.measure { 'foo' } method_call.measure { 'foo' }
expect(method_call.real_time_seconds).to be_a_kind_of(Numeric) expect(method_call.real_time).to be_a_kind_of(Numeric)
expect(method_call.real_time_milliseconds).to be_a_kind_of(Numeric)
expect(method_call.cpu_time).to be_a_kind_of(Numeric) expect(method_call.cpu_time).to be_a_kind_of(Numeric)
expect(method_call.call_count).to eq(1) expect(method_call.call_count).to eq(1)
end end
...@@ -65,14 +64,17 @@ describe Gitlab::Metrics::MethodCall do ...@@ -65,14 +64,17 @@ describe Gitlab::Metrics::MethodCall do
describe '#to_metric' do describe '#to_metric' do
it 'returns a Metric instance' do it 'returns a Metric instance' do
expect(method_call).to receive(:real_time).and_return(4.0001)
expect(method_call).to receive(:cpu_time).and_return(3.0001)
method_call.measure { 'foo' } method_call.measure { 'foo' }
metric = method_call.to_metric metric = method_call.to_metric
expect(metric).to be_an_instance_of(Gitlab::Metrics::Metric) expect(metric).to be_an_instance_of(Gitlab::Metrics::Metric)
expect(metric.series).to eq('rails_method_calls') expect(metric.series).to eq('rails_method_calls')
expect(metric.values[:duration]).to be_a_kind_of(Numeric) expect(metric.values[:duration]).to eq(4000)
expect(metric.values[:cpu_duration]).to be_a_kind_of(Numeric) expect(metric.values[:cpu_duration]).to eq(3000)
expect(metric.values[:call_count]).to be_an(Integer) expect(metric.values[:call_count]).to be_an(Integer)
expect(metric.tags).to eq({ method: 'Foo#bar' }) expect(metric.tags).to eq({ method: 'Foo#bar' })
...@@ -85,13 +87,13 @@ describe Gitlab::Metrics::MethodCall do ...@@ -85,13 +87,13 @@ describe Gitlab::Metrics::MethodCall do
end end
it 'returns false when the total call time is not above the threshold' do it 'returns false when the total call time is not above the threshold' do
expect(method_call).to receive(:real_time_seconds).and_return(0.009) expect(method_call).to receive(:real_time).and_return(0.009)
expect(method_call.above_threshold?).to eq(false) expect(method_call.above_threshold?).to eq(false)
end end
it 'returns true when the total call time is above the threshold' do it 'returns true when the total call time is above the threshold' do
expect(method_call).to receive(:real_time_seconds).and_return(9) expect(method_call).to receive(:real_time).and_return(9)
expect(method_call.above_threshold?).to eq(true) expect(method_call.above_threshold?).to eq(true)
end end
...@@ -132,7 +134,7 @@ describe Gitlab::Metrics::MethodCall do ...@@ -132,7 +134,7 @@ describe Gitlab::Metrics::MethodCall do
describe '#real_time' do describe '#real_time' do
context 'without timings' do context 'without timings' do
it 'returns 0.0' do it 'returns 0.0' do
expect(method_call.real_time_seconds).to eq(0.0) expect(method_call.real_time).to eq(0.0)
end end
end end
...@@ -140,7 +142,7 @@ describe Gitlab::Metrics::MethodCall do ...@@ -140,7 +142,7 @@ describe Gitlab::Metrics::MethodCall do
it 'returns the total real time' do it 'returns the total real time' do
method_call.measure { 'foo' } method_call.measure { 'foo' }
expect(method_call.real_time_seconds >= 0.0).to be(true) expect(method_call.real_time >= 0.0).to be(true)
end end
end end
end end
......
...@@ -29,13 +29,13 @@ describe Gitlab::Metrics::System do ...@@ -29,13 +29,13 @@ describe Gitlab::Metrics::System do
describe '.cpu_time' do describe '.cpu_time' do
it 'returns a Fixnum' do it 'returns a Fixnum' do
expect(described_class.cpu_time).to be_an(Integer) expect(described_class.cpu_time).to be_an(Float)
end end
end end
describe '.real_time' do describe '.real_time' do
it 'returns a Fixnum' do it 'returns a Fixnum' do
expect(described_class.real_time).to be_an(Integer) expect(described_class.real_time).to be_an(Float)
end end
end end
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment