diff options
author | Stan Hu <stanhu@gmail.com> | 2019-07-21 08:34:46 +0300 |
---|---|---|
committer | Stan Hu <stanhu@gmail.com> | 2019-07-24 07:38:05 +0300 |
commit | 291df05e434f5678c47bce9521ff15748d6c767f (patch) | |
tree | a9ebe8e457d875b18998ac1a997c2faa0b1889f8 | |
parent | 4482b82687e5b647459946338686eca0b53b7ce4 (diff) |
Add Rugged calls to performance bar
This will help diagnose the source of excessive I/O from Rugged
calls. To implement this, we need to obtain the full list of arguments
sent to each request method.
-rw-r--r-- | app/assets/javascripts/performance_bar/components/performance_bar_app.vue | 6 | ||||
-rw-r--r-- | changelogs/unreleased/sh-add-rugged-to-peek.yml | 5 | ||||
-rw-r--r-- | config/initializers/peek.rb | 1 | ||||
-rw-r--r-- | lib/gitlab/git/repository.rb | 4 | ||||
-rw-r--r-- | lib/gitlab/git/rugged_impl/blob.rb | 2 | ||||
-rw-r--r-- | lib/gitlab/git/rugged_impl/commit.rb | 6 | ||||
-rw-r--r-- | lib/gitlab/git/rugged_impl/repository.rb | 2 | ||||
-rw-r--r-- | lib/gitlab/git/rugged_impl/tree.rb | 2 | ||||
-rw-r--r-- | lib/gitlab/git/rugged_impl/use_rugged.rb | 10 | ||||
-rw-r--r-- | lib/gitlab/rugged_instrumentation.rb | 19 | ||||
-rw-r--r-- | lib/peek/views/rugged.rb | 56 | ||||
-rwxr-xr-x | scripts/lint-rugged | 4 | ||||
-rw-r--r-- | spec/lib/gitlab/git/repository_spec.rb | 6 | ||||
-rw-r--r-- | spec/lib/gitlab/git/rugged_impl/use_rugged_spec.rb | 25 | ||||
-rw-r--r-- | spec/lib/peek/views/rugged_spec.rb | 37 |
15 files changed, 174 insertions, 11 deletions
diff --git a/app/assets/javascripts/performance_bar/components/performance_bar_app.vue b/app/assets/javascripts/performance_bar/components/performance_bar_app.vue index 015c1527500..f05db8376a4 100644 --- a/app/assets/javascripts/performance_bar/components/performance_bar_app.vue +++ b/app/assets/javascripts/performance_bar/components/performance_bar_app.vue @@ -42,6 +42,12 @@ export default { keys: ['feature', 'request'], }, { + metric: 'rugged', + header: 'Rugged calls', + details: 'details', + keys: ['feature', 'args'], + }, + { metric: 'redis', header: 'Redis calls', details: 'details', diff --git a/changelogs/unreleased/sh-add-rugged-to-peek.yml b/changelogs/unreleased/sh-add-rugged-to-peek.yml new file mode 100644 index 00000000000..8a030f3daf2 --- /dev/null +++ b/changelogs/unreleased/sh-add-rugged-to-peek.yml @@ -0,0 +1,5 @@ +--- +title: Add Rugged calls to performance bar +merge_request: 30983 +author: +type: other diff --git a/config/initializers/peek.rb b/config/initializers/peek.rb index 1ffd133239d..8416ae430c7 100644 --- a/config/initializers/peek.rb +++ b/config/initializers/peek.rb @@ -26,6 +26,7 @@ Peek.into PEEK_DB_VIEW Peek.into Peek::Views::Gitaly Peek.into Peek::Views::Rblineprof Peek.into Peek::Views::RedisDetailed +Peek.into Peek::Views::Rugged Peek.into Peek::Views::GC Peek.into Peek::Views::Tracing if Labkit::Tracing.tracing_url_enabled? diff --git a/lib/gitlab/git/repository.rb b/lib/gitlab/git/repository.rb index 6e8aa5d578e..27032602828 100644 --- a/lib/gitlab/git/repository.rb +++ b/lib/gitlab/git/repository.rb @@ -55,6 +55,10 @@ module Gitlab @name = @relative_path.split("/").last end + def to_s + "<#{self.class.name}: #{self.gl_project_path}>" + end + def ==(other) other.is_a?(self.class) && [storage, relative_path] == [other.storage, other.relative_path] end diff --git a/lib/gitlab/git/rugged_impl/blob.rb b/lib/gitlab/git/rugged_impl/blob.rb index 9aea736527b..5c73c0c66a9 100644 --- a/lib/gitlab/git/rugged_impl/blob.rb +++ b/lib/gitlab/git/rugged_impl/blob.rb @@ -16,7 +16,7 @@ module Gitlab override :tree_entry def tree_entry(repository, sha, path, limit) if use_rugged?(repository, :rugged_tree_entry) - wrap_rugged_call { rugged_tree_entry(repository, sha, path, limit) } + execute_rugged_call(:rugged_tree_entry, repository, sha, path, limit) else super end diff --git a/lib/gitlab/git/rugged_impl/commit.rb b/lib/gitlab/git/rugged_impl/commit.rb index 29ae9bdd851..0eff35ab1c4 100644 --- a/lib/gitlab/git/rugged_impl/commit.rb +++ b/lib/gitlab/git/rugged_impl/commit.rb @@ -36,7 +36,7 @@ module Gitlab override :find_commit def find_commit(repo, commit_id) if use_rugged?(repo, :rugged_find_commit) - wrap_rugged_call { rugged_find(repo, commit_id) } + execute_rugged_call(:rugged_find, repo, commit_id) else super end @@ -45,7 +45,7 @@ module Gitlab override :batch_by_oid def batch_by_oid(repo, oids) if use_rugged?(repo, :rugged_list_commits_by_oid) - wrap_rugged_call { rugged_batch_by_oid(repo, oids) } + execute_rugged_call(:rugged_batch_by_oid, repo, oids) else super end @@ -68,7 +68,7 @@ module Gitlab override :commit_tree_entry def commit_tree_entry(path) if use_rugged?(@repository, :rugged_commit_tree_entry) - wrap_rugged_call { rugged_tree_entry(path) } + execute_rugged_call(:rugged_tree_entry, path) else super end diff --git a/lib/gitlab/git/rugged_impl/repository.rb b/lib/gitlab/git/rugged_impl/repository.rb index 7bed553393c..8fde93e71e2 100644 --- a/lib/gitlab/git/rugged_impl/repository.rb +++ b/lib/gitlab/git/rugged_impl/repository.rb @@ -48,7 +48,7 @@ module Gitlab override :ancestor? def ancestor?(from, to) if use_rugged?(self, :rugged_commit_is_ancestor) - wrap_rugged_call { rugged_is_ancestor?(from, to) } + execute_rugged_call(:rugged_is_ancestor?, from, to) else super end diff --git a/lib/gitlab/git/rugged_impl/tree.rb b/lib/gitlab/git/rugged_impl/tree.rb index 479c5f9d8b7..389c9d32ccb 100644 --- a/lib/gitlab/git/rugged_impl/tree.rb +++ b/lib/gitlab/git/rugged_impl/tree.rb @@ -16,7 +16,7 @@ module Gitlab override :tree_entries def tree_entries(repository, sha, path, recursive) if use_rugged?(repository, :rugged_tree_entries) - wrap_rugged_call { tree_entries_with_flat_path_from_rugged(repository, sha, path, recursive) } + execute_rugged_call(:tree_entries_with_flat_path_from_rugged, repository, sha, path, recursive) else super end diff --git a/lib/gitlab/git/rugged_impl/use_rugged.rb b/lib/gitlab/git/rugged_impl/use_rugged.rb index badf943e39c..80b75689334 100644 --- a/lib/gitlab/git/rugged_impl/use_rugged.rb +++ b/lib/gitlab/git/rugged_impl/use_rugged.rb @@ -11,17 +11,23 @@ module Gitlab Gitlab::GitalyClient.can_use_disk?(repo.storage) end - def wrap_rugged_call(&block) + def execute_rugged_call(method_name, *args) Gitlab::GitalyClient::StorageSettings.allow_disk_access do start = Gitlab::Metrics::System.monotonic_time - result = yield + result = send(method_name, *args) # rubocop:disable GitlabSecurity/PublicSend duration = Gitlab::Metrics::System.monotonic_time - start if Gitlab::RuggedInstrumentation.active? Gitlab::RuggedInstrumentation.increment_query_count Gitlab::RuggedInstrumentation.query_time += duration + + Gitlab::RuggedInstrumentation.add_call_details( + feature: method_name, + args: args, + duration: duration, + backtrace: Gitlab::Profiler.clean_backtrace(caller)) end result diff --git a/lib/gitlab/rugged_instrumentation.rb b/lib/gitlab/rugged_instrumentation.rb index 70c06e8b308..8bb8c547ae1 100644 --- a/lib/gitlab/rugged_instrumentation.rb +++ b/lib/gitlab/rugged_instrumentation.rb @@ -24,7 +24,24 @@ module Gitlab end def self.active? - Gitlab::SafeRequestStore.active? + SafeRequestStore.active? + end + + def self.peek_enabled? + SafeRequestStore[:peek_enabled] + end + + def self.add_call_details(details) + return unless peek_enabled? + + Gitlab::SafeRequestStore[:rugged_call_details] ||= [] + Gitlab::SafeRequestStore[:rugged_call_details] << details + end + + def self.list_call_details + return [] unless peek_enabled? + + Gitlab::SafeRequestStore[:rugged_call_details] || [] end end end diff --git a/lib/peek/views/rugged.rb b/lib/peek/views/rugged.rb new file mode 100644 index 00000000000..7e2730e2ae4 --- /dev/null +++ b/lib/peek/views/rugged.rb @@ -0,0 +1,56 @@ +# frozen_string_literal: true + +module Peek + module Views + class Rugged < View + def duration + ::Gitlab::RuggedInstrumentation.query_time + end + + def calls + ::Gitlab::RuggedInstrumentation.query_count + end + + def results + { + duration: formatted_duration, + calls: calls, + details: details + } + end + + private + + def details + ::Gitlab::RuggedInstrumentation.list_call_details + .sort { |a, b| b[:duration] <=> a[:duration] } + .map(&method(:format_call_details)) + end + + def format_call_details(call) + call.merge(duration: (call[:duration] * 1000).round(3), + args: format_args(call[:args])) + end + + def format_args(args) + args.map do |arg| + # Needed to avoid infinite as_json calls + if arg.is_a?(Gitlab::Git::Repository) + arg.to_s + else + arg + end + end + end + + def formatted_duration + ms = duration * 1000 + if ms >= 1000 + "%.2fms" % ms + else + "%.0fms" % ms + end + end + end + end +end diff --git a/scripts/lint-rugged b/scripts/lint-rugged index e1605b4501b..f40f0489c1a 100755 --- a/scripts/lint-rugged +++ b/scripts/lint-rugged @@ -13,9 +13,11 @@ ALLOWED = [ 'lib/gitlab/gitaly_client/storage_settings.rb', # Needed for logging + 'config/initializers/peek.rb', 'config/initializers/lograge.rb', 'lib/gitlab/grape_logging/loggers/perf_logger.rb', - 'lib/gitlab/rugged_instrumentation.rb' + 'lib/gitlab/rugged_instrumentation.rb', + 'lib/peek/views/rugged.rb' ].freeze rugged_lines = IO.popen(%w[git grep -i -n rugged -- app config lib], &:read).lines diff --git a/spec/lib/gitlab/git/repository_spec.rb b/spec/lib/gitlab/git/repository_spec.rb index 41b898df112..dccd50bc472 100644 --- a/spec/lib/gitlab/git/repository_spec.rb +++ b/spec/lib/gitlab/git/repository_spec.rb @@ -186,6 +186,12 @@ describe Gitlab::Git::Repository, :seed_helper do it { is_expected.to be < 2 } end + describe '#to_s' do + subject { repository.to_s } + + it { is_expected.to eq("<Gitlab::Git::Repository: group/project>") } + end + describe '#object_directory_size' do before do allow(repository.gitaly_repository_client) diff --git a/spec/lib/gitlab/git/rugged_impl/use_rugged_spec.rb b/spec/lib/gitlab/git/rugged_impl/use_rugged_spec.rb index e437647c258..1a4168f7317 100644 --- a/spec/lib/gitlab/git/rugged_impl/use_rugged_spec.rb +++ b/spec/lib/gitlab/git/rugged_impl/use_rugged_spec.rb @@ -16,7 +16,13 @@ describe Gitlab::Git::RuggedImpl::UseRugged, :seed_helper do end subject(:wrapper) do - klazz = Class.new { include Gitlab::Git::RuggedImpl::UseRugged } + klazz = Class.new do + include Gitlab::Git::RuggedImpl::UseRugged + + def rugged_test(ref, test_number) + end + end + klazz.new end @@ -25,6 +31,23 @@ describe Gitlab::Git::RuggedImpl::UseRugged, :seed_helper do Gitlab::GitalyClient.instance_variable_set(:@can_use_disk, {}) end + context '#execute_rugged_call', :request_store do + let(:args) { ['refs/heads/master', 1] } + + before do + allow(Gitlab::RuggedInstrumentation).to receive(:peek_enabled?).and_return(true) + end + + it 'instruments Rugged call' do + expect(subject).to receive(:rugged_test).with(args) + + subject.execute_rugged_call(:rugged_test, args) + + expect(Gitlab::RuggedInstrumentation.query_count).to eq(1) + expect(Gitlab::RuggedInstrumentation.list_call_details.count).to eq(1) + end + end + context 'when feature flag is not persisted' do before do allow(Feature).to receive(:persisted?).with(feature_flag).and_return(false) diff --git a/spec/lib/peek/views/rugged_spec.rb b/spec/lib/peek/views/rugged_spec.rb new file mode 100644 index 00000000000..0fc75043df8 --- /dev/null +++ b/spec/lib/peek/views/rugged_spec.rb @@ -0,0 +1,37 @@ +# frozen_string_literal: true + +require 'spec_helper' + +describe Peek::Views::Rugged, :request_store do + subject { described_class.new } + + let(:project) { create(:project) } + + before do + allow(Gitlab::RuggedInstrumentation).to receive(:peek_enabled?).and_return(true) + end + + it 'returns aggregated results' do + ::Gitlab::RuggedInstrumentation.query_time += 1.234 + ::Gitlab::RuggedInstrumentation.increment_query_count + ::Gitlab::RuggedInstrumentation.increment_query_count + + ::Gitlab::RuggedInstrumentation.add_call_details(feature: :rugged_test, + args: [project.repository.raw, 'HEAD'], + duration: 0.123) + ::Gitlab::RuggedInstrumentation.add_call_details(feature: :rugged_test2, + args: [project.repository.raw, 'refs/heads/master'], + duration: 0.456) + + expect(subject.duration).to be_within(0.00001).of(1.234) + expect(subject.calls).to eq(2) + + results = subject.results + expect(results[:calls]).to eq(2) + expect(results[:duration]).to eq('1234.00ms') + expect(results[:details].count).to eq(2) + + expect(results[:details][0][:args]).to eq([project.repository.raw.to_s, "refs/heads/master"]) + expect(results[:details][1][:args]).to eq([project.repository.raw.to_s, "HEAD"]) + end +end |