Commit a8ebed60 authored by Pawel Chojnacki's avatar Pawel Chojnacki

Make `System.monotonic_time` retun seconds represented by float with microsecond precision

parent b02db1f4
...@@ -132,7 +132,7 @@ module Gitlab ...@@ -132,7 +132,7 @@ module Gitlab
self.query_time += duration self.query_time += duration
gitaly_call_histogram.observe( gitaly_call_histogram.observe(
current_transaction_labels.merge(gitaly_service: service.to_s, rpc: rpc.to_s), current_transaction_labels.merge(gitaly_service: service.to_s, rpc: rpc.to_s),
duration / 1000.0) duration)
end end
def self.current_transaction_labels def self.current_transaction_labels
......
...@@ -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, :cpu_time, :call_count, :labels attr_reader :real_time_seconds, :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,37 +27,41 @@ module Gitlab ...@@ -27,37 +27,41 @@ 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 = 0 @real_time_seconds = 0
@cpu_time = 0 @cpu_time = 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 = System.monotonic_time start_real_seconds = System.monotonic_time
start_cpu = System.cpu_time start_cpu = System.cpu_time
retval = yield retval = yield
real_time = System.monotonic_time - start_real real_time_seconds = System.monotonic_time - start_real_seconds
cpu_time = System.cpu_time - start_cpu cpu_time = System.cpu_time - start_cpu
@real_time += real_time @real_time_seconds += real_time_seconds
@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 / 1000.0) self.class.call_duration_histogram.observe(@transaction.labels.merge(labels), real_time_seconds)
end end
retval retval
end end
def real_time_milliseconds
(real_time_seconds * 1000.0).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, duration: real_time_milliseconds,
cpu_duration: cpu_time, cpu_duration: cpu_time,
call_count: call_count call_count: call_count
}, },
......
...@@ -52,7 +52,7 @@ module Gitlab ...@@ -52,7 +52,7 @@ module Gitlab
metrics[:memory_usage].set(labels, System.memory_usage) metrics[:memory_usage].set(labels, System.memory_usage)
metrics[:file_descriptors].set(labels, System.file_descriptor_count) metrics[:file_descriptors].set(labels, System.file_descriptor_count)
metrics[:sampler_duration].observe(labels.merge(worker_label), (System.monotonic_time - start_time) / 1000.0) metrics[:sampler_duration].observe(labels.merge(worker_label), System.monotonic_time - start_time)
ensure ensure
GC::Profiler.clear GC::Profiler.clear
end end
......
...@@ -51,11 +51,12 @@ module Gitlab ...@@ -51,11 +51,12 @@ module Gitlab
Process.clock_gettime(Process::CLOCK_REALTIME, precision) Process.clock_gettime(Process::CLOCK_REALTIME, precision)
end end
# Returns the current monotonic clock time in a given precision. # Returns the current monotonic clock time as seconds with microseconds precision.
# #
# Returns the time as a Fixnum. # Returns the time as a Float.
def self.monotonic_time(precision = :millisecond) def self.monotonic_time
Process.clock_gettime(Process::CLOCK_MONOTONIC, precision)
Process.clock_gettime(Process::CLOCK_MONOTONIC, :float_second)
end end
end end
end end
......
...@@ -35,6 +35,10 @@ module Gitlab ...@@ -35,6 +35,10 @@ module Gitlab
@finished_at ? (@finished_at - @started_at) : 0.0 @finished_at ? (@finished_at - @started_at) : 0.0
end end
def duration_milliseconds
(duration * 1000).to_i
end
def allocated_memory def allocated_memory
@memory_after - @memory_before @memory_after - @memory_before
end end
...@@ -50,7 +54,7 @@ module Gitlab ...@@ -50,7 +54,7 @@ module Gitlab
@memory_after = System.memory_usage @memory_after = System.memory_usage
@finished_at = System.monotonic_time @finished_at = System.monotonic_time
self.class.metric_transaction_duration_seconds.observe(labels, duration * 1000) self.class.metric_transaction_duration_seconds.observe(labels, duration)
self.class.metric_transaction_allocated_memory_bytes.observe(labels, allocated_memory * 1024.0) self.class.metric_transaction_allocated_memory_bytes.observe(labels, allocated_memory * 1024.0)
Thread.current[THREAD_KEY] = nil Thread.current[THREAD_KEY] = nil
...@@ -97,7 +101,7 @@ module Gitlab ...@@ -97,7 +101,7 @@ module Gitlab
end end
def track_self def track_self
values = { duration: duration, allocated_memory: allocated_memory } values = { duration: duration_milliseconds, allocated_memory: allocated_memory }
@values.each do |name, value| @values.each do |name, value|
values[name] = value values[name] = value
......
...@@ -40,8 +40,8 @@ describe Gitlab::Metrics::System do ...@@ -40,8 +40,8 @@ describe Gitlab::Metrics::System do
end end
describe '.monotonic_time' do describe '.monotonic_time' do
it 'returns a Fixnum' do it 'returns a Float' do
expect(described_class.monotonic_time).to be_an(Integer) expect(described_class.monotonic_time).to be_an(Float)
end end
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