diff options
| -rw-r--r-- | doc/development/instrumentation.md | 36 | ||||
| -rw-r--r-- | lib/gitlab/metrics.rb | 23 | ||||
| -rw-r--r-- | lib/gitlab/metrics/system.rb | 11 | ||||
| -rw-r--r-- | spec/lib/gitlab/metrics_spec.rb | 16 |
4 files changed, 47 insertions, 39 deletions
diff --git a/doc/development/instrumentation.md b/doc/development/instrumentation.md index c0192bd6709..f7e148fb3e4 100644 --- a/doc/development/instrumentation.md +++ b/doc/development/instrumentation.md @@ -2,36 +2,34 @@ GitLab Performance Monitoring allows instrumenting of custom blocks of Ruby code. This can be used to measure the time spent in a specific part of a larger -chunk of code. The resulting data is written to a separate series. +chunk of code. The resulting data is stored as a field in the transaction that +executed the block. -To start measuring a block of Ruby code you should use -`Gitlab::Metrics.measure` and give it a name for the series to store the data -in: +To start measuring a block of Ruby code you should use `Gitlab::Metrics.measure` +and give it a name: ```ruby -Gitlab::Metrics.measure(:user_logins) do +Gitlab::Metrics.measure(:foo) do ... end ``` -The first argument of this method is the series name and should be plural. This -name will be prefixed with `rails_` or `sidekiq_` depending on whether the code -was run in the Rails application or one of the Sidekiq workers. In the -above example the final series names would be as follows: +Two values are measured for a block: -- rails_user_logins -- sidekiq_user_logins +1. The real time elapsed, stored in NAME_real_time +2. The CPU time elapsed, stored in NAME_cpu_time -Series names should be plural as this keeps the naming style in line with the -other series names. +Both the real and CPU timings are measured in milliseconds. -By default metrics measured using a block contain a single value, "duration", -which contains the number of milliseconds it took to execute the block. Custom -values can be added by passing a Hash as the 2nd argument. Custom tags can be -added by passing a Hash as the 3rd argument. A simple example is as follows: +Multiple calls to the same block will result in the final values being the sum +of all individual values. Take this code for example: ```ruby -Gitlab::Metrics.measure(:example_series, { number: 10 }, { class: self.class.to_s }) do - ... +3.times do + Gitlab::Metrics.measure(:sleep) do + sleep 1 + end end ``` + +Here the final value of `sleep_real_time` will be `3`, _not_ `1`. diff --git a/lib/gitlab/metrics.rb b/lib/gitlab/metrics.rb index 4a3f47b5a95..4d64555027e 100644 --- a/lib/gitlab/metrics.rb +++ b/lib/gitlab/metrics.rb @@ -74,24 +74,29 @@ module Gitlab # # Example: # - # Gitlab::Metrics.measure(:find_by_username_timings) do + # Gitlab::Metrics.measure(:find_by_username_duration) do # User.find_by_username(some_username) # end # - # series - The name of the series to store the data in. - # values - A Hash containing extra values to add to the metric. - # tags - A Hash containing extra tags to add to the metric. + # name - The name of the field to store the execution time in. # # Returns the value yielded by the supplied block. - def self.measure(series, values = {}, tags = {}) + def self.measure(name) return yield unless Transaction.current - start = Time.now.to_f + real_start = Time.now.to_f + cpu_start = System.cpu_time + retval = yield - duration = (Time.now.to_f - start) * 1000.0 - values = values.merge(duration: duration) - Transaction.current.add_metric(series, values, tags) + cpu_stop = System.cpu_time + real_stop = Time.now.to_f + + real_time = (real_stop - real_start) * 1000.0 + cpu_time = cpu_stop - cpu_start + + Transaction.current.increment("#{name}_real_time", real_time) + Transaction.current.increment("#{name}_cpu_time", cpu_time) retval end diff --git a/lib/gitlab/metrics/system.rb b/lib/gitlab/metrics/system.rb index 83371265278..a7d183b2f94 100644 --- a/lib/gitlab/metrics/system.rb +++ b/lib/gitlab/metrics/system.rb @@ -30,6 +30,17 @@ module Gitlab 0 end end + + # 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) + end + else + def self.cpu_time + Process.clock_gettime(Process::CLOCK_PROCESS_CPUTIME_ID, :millisecond) + end + end end end end diff --git a/spec/lib/gitlab/metrics_spec.rb b/spec/lib/gitlab/metrics_spec.rb index 8f63a5f2043..edefec909c9 100644 --- a/spec/lib/gitlab/metrics_spec.rb +++ b/spec/lib/gitlab/metrics_spec.rb @@ -79,19 +79,13 @@ describe Gitlab::Metrics do end it 'adds a metric to the current transaction' do - expect(transaction).to receive(:add_metric). - with(:foo, { duration: a_kind_of(Numeric) }, { tag: 'value' }) + expect(transaction).to receive(:increment). + with('foo_real_time', a_kind_of(Numeric)) - Gitlab::Metrics.measure(:foo, {}, tag: 'value') { 10 } - end - - it 'supports adding of custom values' do - values = { duration: a_kind_of(Numeric), number: 10 } - - expect(transaction).to receive(:add_metric). - with(:foo, values, { tag: 'value' }) + expect(transaction).to receive(:increment). + with('foo_cpu_time', a_kind_of(Numeric)) - Gitlab::Metrics.measure(:foo, { number: 10 }, tag: 'value') { 10 } + Gitlab::Metrics.measure(:foo) { 10 } end it 'returns the return value of the block' do |