From 23c1cfcc110b52c1060f35a4a4a7816fb38adc6c Mon Sep 17 00:00:00 2001 From: Sean McGivern Date: Tue, 6 Aug 2019 16:04:43 +0100 Subject: [PATCH 1/2] Return warnings for performance bar from backend For each DetailedView subclass, we add a `warnings` array to: 1. The top-level response. 2. Each individual call under the `details` key. We use the `.thresholds` hash on the DetailedView to determine what's a warning. If that hash is empty (the default), then the warnings array will always be empty. --- lib/peek/views/active_record.rb | 18 +++++ lib/peek/views/detailed_view.rb | 49 +++++++++---- lib/peek/views/gitaly.rb | 18 +++++ lib/peek/views/rugged.rb | 2 +- spec/lib/peek/views/detailed_view_spec.rb | 81 ++++++++++++++++++++++ spec/lib/peek/views/redis_detailed_spec.rb | 8 +-- 6 files changed, 158 insertions(+), 18 deletions(-) create mode 100644 spec/lib/peek/views/detailed_view_spec.rb diff --git a/lib/peek/views/active_record.rb b/lib/peek/views/active_record.rb index 2d78818630d..a35783c1971 100644 --- a/lib/peek/views/active_record.rb +++ b/lib/peek/views/active_record.rb @@ -3,6 +3,24 @@ module Peek module Views class ActiveRecord < DetailedView + DEFAULT_THRESHOLDS = { + calls: 100, + duration: 3, + individual_call: 1 + }.freeze + + THRESHOLDS = { + production: { + calls: 100, + duration: 15, + individual_call: 5 + } + }.freeze + + def self.thresholds + @thresholds ||= THRESHOLDS.fetch(Rails.env.to_sym, DEFAULT_THRESHOLDS) + end + private def setup_subscribers diff --git a/lib/peek/views/detailed_view.rb b/lib/peek/views/detailed_view.rb index f4ca1cb5075..4f3eddaf11b 100644 --- a/lib/peek/views/detailed_view.rb +++ b/lib/peek/views/detailed_view.rb @@ -3,11 +3,16 @@ module Peek module Views class DetailedView < View + def self.thresholds + {} + end + def results { - duration: formatted_duration, + duration: format_duration(duration), calls: calls, - details: details + details: details, + warnings: warnings } end @@ -18,30 +23,48 @@ module Peek private def duration - detail_store.map { |entry| entry[:duration] }.sum # rubocop:disable CodeReuse/ActiveRecord + detail_store.map { |entry| entry[:duration] }.sum * 1000 # rubocop:disable CodeReuse/ActiveRecord end def calls detail_store.count end - def call_details - detail_store - end - - def format_call_details(call) - call.merge(duration: (call[:duration] * 1000).round(3)) - end - def details call_details .sort { |a, b| b[:duration] <=> a[:duration] } .map(&method(:format_call_details)) end - def formatted_duration - ms = duration * 1000 + def warnings + [ + warning_for(calls, self.class.thresholds[:calls], label: "#{key} calls"), + warning_for(duration, self.class.thresholds[:duration], label: "#{key} duration") + ].flatten.compact + end + def call_details + detail_store + end + + def format_call_details(call) + duration = (call[:duration] * 1000).round(3) + + call.merge(duration: duration, + warnings: warning_for(duration, self.class.thresholds[:individual_call])) + end + + def warning_for(actual, threshold, label: nil) + if threshold && actual > threshold + prefix = "#{label}: " if label + + ["#{prefix}#{actual} over #{threshold}"] + else + [] + end + end + + def format_duration(ms) if ms >= 1000 "%.2fms" % ms else diff --git a/lib/peek/views/gitaly.rb b/lib/peek/views/gitaly.rb index 6ad6ddfd89d..f669feae254 100644 --- a/lib/peek/views/gitaly.rb +++ b/lib/peek/views/gitaly.rb @@ -3,6 +3,24 @@ module Peek module Views class Gitaly < DetailedView + DEFAULT_THRESHOLDS = { + calls: 30, + duration: 1, + individual_call: 0.5 + }.freeze + + THRESHOLDS = { + production: { + calls: 30, + duration: 1, + individual_call: 0.5 + } + }.freeze + + def self.thresholds + @thresholds ||= THRESHOLDS.fetch(Rails.env.to_sym, DEFAULT_THRESHOLDS) + end + private def duration diff --git a/lib/peek/views/rugged.rb b/lib/peek/views/rugged.rb index 18b3f422852..3ed54a010f8 100644 --- a/lib/peek/views/rugged.rb +++ b/lib/peek/views/rugged.rb @@ -12,7 +12,7 @@ module Peek private def duration - ::Gitlab::RuggedInstrumentation.query_time + ::Gitlab::RuggedInstrumentation.query_time_ms end def calls diff --git a/spec/lib/peek/views/detailed_view_spec.rb b/spec/lib/peek/views/detailed_view_spec.rb new file mode 100644 index 00000000000..d8660a55ea9 --- /dev/null +++ b/spec/lib/peek/views/detailed_view_spec.rb @@ -0,0 +1,81 @@ +# frozen_string_literal: true + +require 'fast_spec_helper' + +describe Peek::Views::DetailedView, :request_store do + context 'when a class defines thresholds' do + let(:threshold_view) do + Class.new(described_class) do + def self.thresholds + { + calls: 1, + duration: 10, + individual_call: 5 + } + end + + def key + 'threshold-view' + end + end.new + end + + context 'when the results exceed the calls threshold' do + before do + allow(threshold_view) + .to receive(:detail_store).and_return([{ duration: 0.001 }, { duration: 0.001 }]) + end + + it 'adds a warning to the results key' do + expect(threshold_view.results).to include(warnings: [a_string_matching('threshold-view calls')]) + end + end + + context 'when the results exceed the duration threshold' do + before do + allow(threshold_view) + .to receive(:detail_store).and_return([{ duration: 0.011 }]) + end + + it 'adds a warning to the results key' do + expect(threshold_view.results).to include(warnings: [a_string_matching('threshold-view duration')]) + end + end + + context 'when a single call exceeds the duration threshold' do + before do + allow(threshold_view) + .to receive(:detail_store).and_return([{ duration: 0.001 }, { duration: 0.006 }]) + end + + it 'adds a warning to that call detail entry' do + expect(threshold_view.results) + .to include(details: a_collection_containing_exactly( + { duration: 1.0, warnings: [] }, + { duration: 6.0, warnings: ['6.0 over 5'] } + )) + end + end + end + + context 'when a view does not define thresholds' do + let(:no_threshold_view) { Class.new(described_class).new } + + before do + allow(no_threshold_view) + .to receive(:detail_store).and_return([{ duration: 100 }, { duration: 100 }]) + end + + it 'does not add warnings to the top level' do + expect(no_threshold_view.results).to include(warnings: []) + end + + it 'does not add warnings to call details entries' do + expect(no_threshold_view.results) + .to include(details: a_collection_containing_exactly( + { duration: 100000, warnings: [] }, + { duration: 100000, warnings: [] } + )) + end + end +end diff --git a/spec/lib/peek/views/redis_detailed_spec.rb b/spec/lib/peek/views/redis_detailed_spec.rb index 61096e6c69e..fa9532226f2 100644 --- a/spec/lib/peek/views/redis_detailed_spec.rb +++ b/spec/lib/peek/views/redis_detailed_spec.rb @@ -21,10 +21,10 @@ describe Peek::Views::RedisDetailed, :request_store do expect(subject.results[:details].count).to eq(1) expect(subject.results[:details].first) - .to eq({ - cmd: expected, - duration: 1000 - }) + .to include({ + cmd: expected, + duration: 1000 + }) end end From 9bfb012a56918e3412ce767c19f5f9ca2329a78c Mon Sep 17 00:00:00 2001 From: Sean McGivern Date: Fri, 23 Aug 2019 13:05:38 +0100 Subject: [PATCH 2/2] Add top-level warnings key to performance bar response This key is useful to reduce the amount of logic needed on the frontend: if `has_warnings` is true, then the frontend knows that the request in question has warnings for some metric. --- config/initializers/peek.rb | 1 + .../with_top_level_warnings.rb | 19 ++++++++++++ .../with_top_level_warnings_spec.rb | 29 +++++++++++++++++++ 3 files changed, 49 insertions(+) create mode 100644 lib/gitlab/performance_bar/with_top_level_warnings.rb create mode 100644 spec/lib/gitlab/performance_bar/with_top_level_warnings_spec.rb diff --git a/config/initializers/peek.rb b/config/initializers/peek.rb index f9055285e5c..a3810be70b2 100644 --- a/config/initializers/peek.rb +++ b/config/initializers/peek.rb @@ -1,6 +1,7 @@ require 'peek/adapters/redis' Peek::Adapters::Redis.prepend ::Gitlab::PerformanceBar::RedisAdapterWhenPeekEnabled +Peek.singleton_class.prepend ::Gitlab::PerformanceBar::WithTopLevelWarnings Rails.application.config.peek.adapter = :redis, { client: ::Redis.new(Gitlab::Redis::Cache.params) } diff --git a/lib/gitlab/performance_bar/with_top_level_warnings.rb b/lib/gitlab/performance_bar/with_top_level_warnings.rb new file mode 100644 index 00000000000..fb5c5c5959d --- /dev/null +++ b/lib/gitlab/performance_bar/with_top_level_warnings.rb @@ -0,0 +1,19 @@ +# frozen_string_literal: true + +module Gitlab + module PerformanceBar + module WithTopLevelWarnings + def results + results = super + + results.merge(has_warnings: has_warnings?(results)) + end + + def has_warnings?(results) + results[:data].any? do |_, value| + value[:warnings].present? + end + end + end + end +end diff --git a/spec/lib/gitlab/performance_bar/with_top_level_warnings_spec.rb b/spec/lib/gitlab/performance_bar/with_top_level_warnings_spec.rb new file mode 100644 index 00000000000..3b92261f0fe --- /dev/null +++ b/spec/lib/gitlab/performance_bar/with_top_level_warnings_spec.rb @@ -0,0 +1,29 @@ +# frozen_string_literal: true + +require 'fast_spec_helper' +require 'rspec-parameterized' + +describe Gitlab::PerformanceBar::WithTopLevelWarnings do + using RSpec::Parameterized::TableSyntax + + subject { Module.new } + + before do + subject.singleton_class.prepend(described_class) + end + + describe '#has_warnings?' do + where(:has_warnings, :results) do + false | { data: {} } + false | { data: { gitaly: { warnings: [] } } } + true | { data: { gitaly: { warnings: [1] } } } + true | { data: { gitaly: { warnings: [] }, redis: { warnings: [1] } } } + end + + with_them do + it do + expect(subject.has_warnings?(results)).to eq(has_warnings) + end + end + end +end