summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
authorYorick Peterse <yorickpeterse@gmail.com>2016-06-24 13:44:50 +0200
committerYorick Peterse <yorickpeterse@gmail.com>2016-06-28 17:51:25 +0200
commitd7b4f36a3cc691ba5684c1bbc48cc22c59228ca8 (patch)
treeacedc8752ec4c14ab2054fd410785bdd35f69088
parent7a94432e18f5210abda85721810ca2a4e573de5d (diff)
downloadgitlab-ce-d7b4f36a3cc691ba5684c1bbc48cc22c59228ca8.tar.gz
Use clock_gettime for all performance timestampsperformance-clock-adjustments
Process.clock_gettime allows getting the real time in nanoseconds as well as allowing one to get a monotonic timestamp. This offers greater accuracy without the overhead of having to allocate a Time instance. In general using Time.now/Time.new is about 2x slower than using Process.clock_gettime(). For example: require 'benchmark/ips' Benchmark.ips do |bench| bench.report 'Time.now' do Time.now.to_f end bench.report 'clock_gettime' do Process.clock_gettime(Process::CLOCK_MONOTONIC, :millisecond) end bench.compare! end Running this benchmark gives: Calculating ------------------------------------- Time.now 108.052k i/100ms clock_gettime 125.984k i/100ms ------------------------------------------------- Time.now 2.343M (± 7.1%) i/s - 11.670M clock_gettime 4.979M (± 0.8%) i/s - 24.945M Comparison: clock_gettime: 4979393.8 i/s Time.now: 2342986.8 i/s - 2.13x slower Another benefit of using Process.clock_gettime() is that we can simplify the code a bit since it can give timestamps in nanoseconds out of the box.
-rw-r--r--lib/gitlab/metrics/method_call.rb6
-rw-r--r--lib/gitlab/metrics/metric.rb21
-rw-r--r--lib/gitlab/metrics/system.rb20
-rw-r--r--lib/gitlab/metrics/transaction.rb6
-rw-r--r--spec/lib/gitlab/metrics/system_spec.rb16
5 files changed, 48 insertions, 21 deletions
diff --git a/lib/gitlab/metrics/method_call.rb b/lib/gitlab/metrics/method_call.rb
index faf0d9b6318..c048fe20ba7 100644
--- a/lib/gitlab/metrics/method_call.rb
+++ b/lib/gitlab/metrics/method_call.rb
@@ -18,12 +18,12 @@ module Gitlab
# Measures the real and CPU execution time of the supplied block.
def measure
- start_real = Time.now
+ start_real = System.monotonic_time
start_cpu = System.cpu_time
retval = yield
- @real_time += (Time.now - start_real) * 1000.0
- @cpu_time += System.cpu_time.to_f - start_cpu
+ @real_time += System.monotonic_time - start_real
+ @cpu_time += System.cpu_time - start_cpu
@call_count += 1
retval
diff --git a/lib/gitlab/metrics/metric.rb b/lib/gitlab/metrics/metric.rb
index 1cd1ca30f70..f23d67e1e38 100644
--- a/lib/gitlab/metrics/metric.rb
+++ b/lib/gitlab/metrics/metric.rb
@@ -4,16 +4,15 @@ module Gitlab
class Metric
JITTER_RANGE = 0.000001..0.001
- attr_reader :series, :values, :tags, :created_at
+ attr_reader :series, :values, :tags
# series - The name of the series (as a String) to store the metric in.
# values - A Hash containing the values to store.
# tags - A Hash containing extra tags to add to the metrics.
def initialize(series, values, tags = {})
- @values = values
- @series = series
- @tags = tags
- @created_at = Time.now.utc
+ @values = values
+ @series = series
+ @tags = tags
end
# Returns a Hash in a format that can be directly written to InfluxDB.
@@ -27,20 +26,20 @@ module Gitlab
#
# Due to the way InfluxDB is set up there's no solution to this problem,
# all we can do is lower the amount of collisions. We do this by using
- # Time#to_f which returns the seconds as a Float providing greater
- # accuracy. We then add a small random value that is large enough to
- # distinguish most timestamps but small enough to not alter the amount
- # of seconds.
+ # System.real_time which returns the nanoseconds as a Float providing
+ # greater accuracy. We then add a small random value that is large
+ # enough to distinguish most timestamps but small enough to not alter
+ # the timestamp significantly.
#
# See https://gitlab.com/gitlab-com/operations/issues/175 for more
# information.
- time = @created_at.to_f + rand(JITTER_RANGE)
+ time = System.real_time(:nanosecond) + rand(JITTER_RANGE)
{
series: @series,
tags: @tags,
values: @values,
- timestamp: (time * 1_000_000_000).to_i
+ timestamp: time.to_i
}
end
end
diff --git a/lib/gitlab/metrics/system.rb b/lib/gitlab/metrics/system.rb
index a7d183b2f94..82c18bb108b 100644
--- a/lib/gitlab/metrics/system.rb
+++ b/lib/gitlab/metrics/system.rb
@@ -34,13 +34,29 @@ module Gitlab
# THREAD_CPUTIME is not supported on OS X
if Process.const_defined?(:CLOCK_THREAD_CPUTIME_ID)
def self.cpu_time
- Process.clock_gettime(Process::CLOCK_THREAD_CPUTIME_ID, :millisecond)
+ Process.
+ clock_gettime(Process::CLOCK_THREAD_CPUTIME_ID, :millisecond).to_f
end
else
def self.cpu_time
- Process.clock_gettime(Process::CLOCK_PROCESS_CPUTIME_ID, :millisecond)
+ Process.
+ clock_gettime(Process::CLOCK_PROCESS_CPUTIME_ID, :millisecond).to_f
end
end
+
+ # Returns the current real time in a given precision.
+ #
+ # Returns the time as a Float.
+ def self.real_time(precision = :millisecond)
+ Process.clock_gettime(Process::CLOCK_REALTIME, precision).to_f
+ 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
+ end
end
end
end
diff --git a/lib/gitlab/metrics/transaction.rb b/lib/gitlab/metrics/transaction.rb
index 4bc5081aa03..bded245da43 100644
--- a/lib/gitlab/metrics/transaction.rb
+++ b/lib/gitlab/metrics/transaction.rb
@@ -30,7 +30,7 @@ module Gitlab
end
def duration
- @finished_at ? (@finished_at - @started_at) * 1000.0 : 0.0
+ @finished_at ? (@finished_at - @started_at) : 0.0
end
def allocated_memory
@@ -41,12 +41,12 @@ module Gitlab
Thread.current[THREAD_KEY] = self
@memory_before = System.memory_usage
- @started_at = Time.now
+ @started_at = System.monotonic_time
yield
ensure
@memory_after = System.memory_usage
- @finished_at = Time.now
+ @finished_at = System.monotonic_time
Thread.current[THREAD_KEY] = nil
end
diff --git a/spec/lib/gitlab/metrics/system_spec.rb b/spec/lib/gitlab/metrics/system_spec.rb
index d6ae54e25e8..cf0e282c2fb 100644
--- a/spec/lib/gitlab/metrics/system_spec.rb
+++ b/spec/lib/gitlab/metrics/system_spec.rb
@@ -28,8 +28,20 @@ describe Gitlab::Metrics::System do
end
describe '.cpu_time' do
- it 'returns a Fixnum' do
- expect(described_class.cpu_time).to be_an_instance_of(Fixnum)
+ it 'returns a Float' do
+ expect(described_class.cpu_time).to be_an_instance_of(Float)
+ end
+ end
+
+ describe '.real_time' do
+ it 'returns a Float' do
+ expect(described_class.real_time).to be_an_instance_of(Float)
+ end
+ end
+
+ describe '.monotonic_time' do
+ it 'returns a Float' do
+ expect(described_class.monotonic_time).to be_an_instance_of(Float)
end
end
end