diff options
author | Yorick Peterse <yorickpeterse@gmail.com> | 2016-04-11 13:16:58 +0000 |
---|---|---|
committer | Yorick Peterse <yorickpeterse@gmail.com> | 2016-04-11 13:16:58 +0000 |
commit | 15cbbd09fbd05cfd2447dfb43d66d7a96a708f82 (patch) | |
tree | 57709a15309392056e5c232d76efc749a5805c5e | |
parent | 5999fec7a3aa7f663d0ade254e37fda3391fa17a (diff) | |
parent | 7eed4608fe5adf65d6a29ef50c93485ca2e6806f (diff) | |
download | gitlab-ce-15cbbd09fbd05cfd2447dfb43d66d7a96a708f82.tar.gz |
Merge branch 'metrics-measure-block-transaction' into 'master'
Store block timings as transaction values
See merge request !3649
-rw-r--r-- | doc/development/instrumentation.md | 37 | ||||
-rw-r--r-- | lib/gitlab/metrics.rb | 34 | ||||
-rw-r--r-- | lib/gitlab/metrics/system.rb | 11 | ||||
-rw-r--r-- | spec/lib/gitlab/metrics/system_spec.rb | 6 | ||||
-rw-r--r-- | spec/lib/gitlab/metrics_spec.rb | 19 |
5 files changed, 67 insertions, 40 deletions
diff --git a/doc/development/instrumentation.md b/doc/development/instrumentation.md index c0192bd6709..c1cf2e77c26 100644 --- a/doc/development/instrumentation.md +++ b/doc/development/instrumentation.md @@ -2,36 +2,35 @@ 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: +3 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. +3. The call count, stored in NAME_call_count. -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..2a0a5629be5 100644 --- a/lib/gitlab/metrics.rb +++ b/lib/gitlab/metrics.rb @@ -74,24 +74,32 @@ 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 = {}) - return yield unless Transaction.current + def self.measure(name) + trans = current_transaction + + return yield unless trans + + real_start = Time.now.to_f + cpu_start = System.cpu_time - start = Time.now.to_f 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 + + trans.increment("#{name}_real_time", real_time) + trans.increment("#{name}_cpu_time", cpu_time) + trans.increment("#{name}_call_count", 1) retval end @@ -107,5 +115,11 @@ module Gitlab new(udp: { host: host, port: port }) end end + + private + + def self.current_transaction + Transaction.current + end end 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/system_spec.rb b/spec/lib/gitlab/metrics/system_spec.rb index f8c1d956ca1..d6ae54e25e8 100644 --- a/spec/lib/gitlab/metrics/system_spec.rb +++ b/spec/lib/gitlab/metrics/system_spec.rb @@ -26,4 +26,10 @@ describe Gitlab::Metrics::System do end end end + + describe '.cpu_time' do + it 'returns a Fixnum' do + expect(described_class.cpu_time).to be_an_instance_of(Fixnum) + end + end end diff --git a/spec/lib/gitlab/metrics_spec.rb b/spec/lib/gitlab/metrics_spec.rb index 8f63a5f2043..3dee13e27f4 100644 --- a/spec/lib/gitlab/metrics_spec.rb +++ b/spec/lib/gitlab/metrics_spec.rb @@ -74,24 +74,21 @@ describe Gitlab::Metrics do let(:transaction) { Gitlab::Metrics::Transaction.new } before do - allow(Gitlab::Metrics::Transaction).to receive(:current). + allow(Gitlab::Metrics).to receive(:current_transaction). and_return(transaction) 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(:increment). + with('foo_cpu_time', a_kind_of(Numeric)) - expect(transaction).to receive(:add_metric). - with(:foo, values, { tag: 'value' }) + expect(transaction).to receive(:increment). + with('foo_call_count', 1) - Gitlab::Metrics.measure(:foo, { number: 10 }, tag: 'value') { 10 } + Gitlab::Metrics.measure(:foo) { 10 } end it 'returns the return value of the block' do |