Commit 8f73ddd8 authored by Grzegorz Bizon's avatar Grzegorz Bizon

Merge branch '43805-list-gitaly-calls-and-arguments-in-the-performance-bar' into 'master'

Resolve "List Gitaly calls and arguments in the performance bar"

Closes #43805

See merge request gitlab-org/gitlab-ce!17564
parents dfed7b45 582447d9
...@@ -14,8 +14,6 @@ export default class PerformanceBar { ...@@ -14,8 +14,6 @@ export default class PerformanceBar {
init(opts) { init(opts) {
const $container = $(opts.container); const $container = $(opts.container);
this.$sqlProfileLink = $container.find('.js-toggle-modal-peek-sql');
this.$sqlProfileModal = $container.find('#modal-peek-pg-queries');
this.$lineProfileLink = $container.find('.js-toggle-modal-peek-line-profile'); this.$lineProfileLink = $container.find('.js-toggle-modal-peek-line-profile');
this.$lineProfileModal = $('#modal-peek-line-profile'); this.$lineProfileModal = $('#modal-peek-line-profile');
this.initEventListeners(); this.initEventListeners();
...@@ -23,7 +21,6 @@ export default class PerformanceBar { ...@@ -23,7 +21,6 @@ export default class PerformanceBar {
} }
initEventListeners() { initEventListeners() {
this.$sqlProfileLink.on('click', () => this.handleSQLProfileLink());
this.$lineProfileLink.on('click', e => this.handleLineProfileLink(e)); this.$lineProfileLink.on('click', e => this.handleLineProfileLink(e));
$(document).on('click', '.js-lineprof-file', PerformanceBar.toggleLineProfileFile); $(document).on('click', '.js-lineprof-file', PerformanceBar.toggleLineProfileFile);
} }
...@@ -36,10 +33,6 @@ export default class PerformanceBar { ...@@ -36,10 +33,6 @@ export default class PerformanceBar {
} }
} }
handleSQLProfileLink() {
PerformanceBar.toggleModal(this.$sqlProfileModal);
}
handleLineProfileLink(e) { handleLineProfileLink(e) {
const lineProfilerParameter = getParameterValues('lineprofiler'); const lineProfilerParameter = getParameterValues('lineprofiler');
const lineProfilerParameterRegex = new RegExp(`lineprofiler=${lineProfilerParameter[0]}`); const lineProfilerParameterRegex = new RegExp(`lineprofiler=${lineProfilerParameter[0]}`);
......
- local_assigns.fetch(:view)
%span.bold
%span{ title: 'Invoke Time', data: { defer_to: "#{view.defer_key}-gc_time" } }...
\/
%span{ title: 'Invoke Count', data: { defer_to: "#{view.defer_key}-invokes" } }...
gc
- local_assigns.fetch(:view) - local_assigns.fetch(:view)
%strong %button.btn-blank.btn-link.bold{ type: 'button', data: { toggle: 'modal', target: '#modal-peek-gitaly-details' } }
%span{ data: { defer_to: "#{view.defer_key}-duration" } } ... %span{ data: { defer_to: "#{view.defer_key}-duration" } }...
\/ \/
%span{ data: { defer_to: "#{view.defer_key}-calls" } } ... %span{ data: { defer_to: "#{view.defer_key}-calls" } }...
Gitaly #modal-peek-gitaly-details.modal{ tabindex: -1, role: 'dialog' }
.modal-dialog.modal-full
.modal-content
.modal-header
%button.close{ type: 'button', data: { dismiss: 'modal' }, 'aria-label' => 'Close' }
%span{ 'aria-hidden' => 'true' }
×
%h4
Gitaly requests
.modal-body{ data: { defer_to: "#{view.defer_key}-details" } }...
gitaly
- local_assigns.fetch(:view)
%span.bold
%span{ data: { defer_to: "#{view.defer_key}-duration" } }...
\/
%span{ data: { defer_to: "#{view.defer_key}-calls" } }...
redis
- local_assigns.fetch(:view)
%span.bold
%span{ data: { defer_to: "#{view.defer_key}-duration" } }...
\/
%span{ data: { defer_to: "#{view.defer_key}-calls" } }...
sidekiq
%strong %button.btn-blank.btn-link.bold{ type: 'button', data: { toggle: 'modal', target: '#modal-peek-pg-queries' } }
%a.js-toggle-modal-peek-sql
%span{ data: { defer_to: "#{view.defer_key}-duration" } }... %span{ data: { defer_to: "#{view.defer_key}-duration" } }...
\/ \/
%span{ data: { defer_to: "#{view.defer_key}-calls" } }... %span{ data: { defer_to: "#{view.defer_key}-calls" } }...
...@@ -7,7 +6,9 @@ ...@@ -7,7 +6,9 @@
.modal-dialog.modal-full .modal-dialog.modal-full
.modal-content .modal-content
.modal-header .modal-header
%button.close.btn.btn-link.btn-sm{ type: 'button', data: { dismiss: 'modal' } } X %button.close{ type: 'button', data: { dismiss: 'modal' }, 'aria-label' => 'Close' }
%span{ 'aria-hidden' => 'true' }
×
%h4 %h4
SQL queries SQL queries
.modal-body{ data: { defer_to: "#{view.defer_key}-queries" } }... .modal-body{ data: { defer_to: "#{view.defer_key}-queries" } }...
---
title: Add Gitaly call details to performance bar
merge_request:
author:
type: added
...@@ -16,11 +16,11 @@ else ...@@ -16,11 +16,11 @@ else
end end
Peek.into PEEK_DB_VIEW Peek.into PEEK_DB_VIEW
Peek.into Peek::Views::Gitaly
Peek.into Peek::Views::Rblineprof
Peek.into Peek::Views::Redis Peek.into Peek::Views::Redis
Peek.into Peek::Views::Sidekiq Peek.into Peek::Views::Sidekiq
Peek.into Peek::Views::Rblineprof
Peek.into Peek::Views::GC Peek.into Peek::Views::GC
Peek.into Peek::Views::Gitaly
# rubocop:disable Naming/ClassAndModuleCamelCase # rubocop:disable Naming/ClassAndModuleCamelCase
class PEEK_DB_CLIENT class PEEK_DB_CLIENT
......
...@@ -11,10 +11,12 @@ It allows you to see (from left to right): ...@@ -11,10 +11,12 @@ It allows you to see (from left to right):
- the timing of the page (backend, frontend) - the timing of the page (backend, frontend)
- time taken and number of DB queries, click through for details of these queries - time taken and number of DB queries, click through for details of these queries
![SQL profiling using the Performance Bar](img/performance_bar_sql_queries.png) ![SQL profiling using the Performance Bar](img/performance_bar_sql_queries.png)
- time taken and number of calls to Redis - time taken and number of [Gitaly] calls, click through for details of these calls
- time taken and number of background jobs created by Sidekiq ![Gitaly profiling using the Performance Bar](img/performance_bar_gitaly_calls.png)
- profile of the code used to generate the page, line by line for either _all_, _app & lib_ , or _views_. In the profile view, the numbers in the left panel represent wall time, cpu time, and number of calls (based on [rblineprof](https://github.com/tmm1/rblineprof)). - profile of the code used to generate the page, line by line for either _all_, _app & lib_ , or _views_. In the profile view, the numbers in the left panel represent wall time, cpu time, and number of calls (based on [rblineprof](https://github.com/tmm1/rblineprof)).
![Line profiling using the Performance Bar](img/performance_bar_line_profiling.png) ![Line profiling using the Performance Bar](img/performance_bar_line_profiling.png)
- time taken and number of calls to Redis
- time taken and number of background jobs created by Sidekiq
- time taken and number of Ruby GC calls - time taken and number of Ruby GC calls
## Enable the Performance Bar via the Admin panel ## Enable the Performance Bar via the Admin panel
...@@ -39,3 +41,5 @@ You can toggle the Bar using the same shortcut. ...@@ -39,3 +41,5 @@ You can toggle the Bar using the same shortcut.
![GitLab Performance Bar Admin Settings](img/performance_bar_configuration_settings.png) ![GitLab Performance Bar Admin Settings](img/performance_bar_configuration_settings.png)
--- ---
[Gitaly]: ../../gitaly/index.md
...@@ -119,6 +119,9 @@ module Gitlab ...@@ -119,6 +119,9 @@ module Gitlab
# #
def self.call(storage, service, rpc, request, remote_storage: nil, timeout: nil) def self.call(storage, service, rpc, request, remote_storage: nil, timeout: nil)
start = Gitlab::Metrics::System.monotonic_time start = Gitlab::Metrics::System.monotonic_time
request_hash = request.is_a?(Google::Protobuf::MessageExts) ? request.to_h : {}
@current_call_id ||= SecureRandom.uuid
enforce_gitaly_request_limits(:call) enforce_gitaly_request_limits(:call)
kwargs = request_kwargs(storage, timeout, remote_storage: remote_storage) kwargs = request_kwargs(storage, timeout, remote_storage: remote_storage)
...@@ -135,6 +138,10 @@ module Gitlab ...@@ -135,6 +138,10 @@ module Gitlab
gitaly_controller_action_duration_seconds.observe( gitaly_controller_action_duration_seconds.observe(
current_transaction_labels.merge(gitaly_service: service.to_s, rpc: rpc.to_s), current_transaction_labels.merge(gitaly_service: service.to_s, rpc: rpc.to_s),
duration) duration)
add_call_details(id: @current_call_id, feature: service, duration: duration, request: request_hash)
@current_call_id = nil
end end
def self.handle_grpc_unavailable!(ex) def self.handle_grpc_unavailable!(ex)
...@@ -252,12 +259,16 @@ module Gitlab ...@@ -252,12 +259,16 @@ module Gitlab
feature_stack.unshift(feature) feature_stack.unshift(feature)
begin begin
start = Gitlab::Metrics::System.monotonic_time start = Gitlab::Metrics::System.monotonic_time
@current_call_id = SecureRandom.uuid
call_details = { id: @current_call_id }
yield is_enabled yield is_enabled
ensure ensure
total_time = Gitlab::Metrics::System.monotonic_time - start total_time = Gitlab::Metrics::System.monotonic_time - start
gitaly_migrate_call_duration_seconds.observe({ gitaly_enabled: is_enabled, feature: feature }, total_time) gitaly_migrate_call_duration_seconds.observe({ gitaly_enabled: is_enabled, feature: feature }, total_time)
feature_stack.shift feature_stack.shift
Thread.current[:gitaly_feature_stack] = nil if feature_stack.empty? Thread.current[:gitaly_feature_stack] = nil if feature_stack.empty?
add_call_details(call_details.merge(feature: feature, duration: total_time))
end end
end end
end end
...@@ -344,6 +355,22 @@ module Gitlab ...@@ -344,6 +355,22 @@ module Gitlab
end end
end end
def self.add_call_details(details)
id = details.delete(:id)
return unless id && RequestStore.active? && RequestStore.store[:peek_enabled]
RequestStore.store['gitaly_call_details'] ||= {}
RequestStore.store['gitaly_call_details'][id] ||= {}
RequestStore.store['gitaly_call_details'][id].merge!(details)
end
def self.list_call_details
return {} unless RequestStore.active? && RequestStore.store[:peek_enabled]
RequestStore.store['gitaly_call_details'] || {}
end
def self.expected_server_version def self.expected_server_version
path = Rails.root.join(SERVER_VERSION_FILE) path = Rails.root.join(SERVER_VERSION_FILE)
path.read.chomp path.read.chomp
......
...@@ -10,11 +10,29 @@ module Peek ...@@ -10,11 +10,29 @@ module Peek
end end
def results def results
{ duration: formatted_duration, calls: calls } {
duration: formatted_duration,
calls: calls,
details: details
}
end end
private private
def details
::Gitlab::GitalyClient.list_call_details
.values
.sort { |a, b| b[:duration] <=> a[:duration] }
.map(&method(:format_call_details))
end
def format_call_details(call)
pretty_request = call[:request]&.reject { |k, v| v.blank? }.to_h.pretty_inspect
call.merge(duration: (call[:duration] * 1000).round(3),
request: pretty_request || {})
end
def formatted_duration def formatted_duration
ms = duration * 1000 ms = duration * 1000
if ms >= 1000 if ms >= 1000
......
/* /*
* This is a modified version of https://github.com/peek/peek/blob/master/app/assets/javascripts/peek.js * this is a modified version of https://github.com/peek/peek/blob/master/app/assets/javascripts/peek.js
* *
* - Removed the dependency on jquery.tipsy * - Removed the dependency on jquery.tipsy
* - Removed the initializeTipsy and toggleBar functions * - Removed the initializeTipsy and toggleBar functions
* - Customized updatePerformanceBar to handle SQL queries report specificities * - Customized updatePerformanceBar to handle SQL query and Gitaly call lists
* - Changed /peek/results to /-/peek/results * - Changed /peek/results to /-/peek/results
* - Removed the keypress, pjax:end, page:change, and turbolinks:load handlers * - Removed the keypress, pjax:end, page:change, and turbolinks:load handlers
*/ */
(function($) { (function($) {
var fetchRequestResults, getRequestId, peekEnabled, updatePerformanceBar; var fetchRequestResults, getRequestId, peekEnabled, updatePerformanceBar, createTable, createTableRow;
getRequestId = function() { getRequestId = function() {
return $('#peek').data('requestId'); return $('#peek').data('requestId');
}; };
...@@ -16,39 +16,55 @@ ...@@ -16,39 +16,55 @@
return $('#peek').length; return $('#peek').length;
}; };
updatePerformanceBar = function(results) { updatePerformanceBar = function(results) {
var key, label, data, table, html, tr, duration_td, sql_td, strong;
Object.keys(results.data).forEach(function(key) { Object.keys(results.data).forEach(function(key) {
Object.keys(results.data[key]).forEach(function(label) { Object.keys(results.data[key]).forEach(function(label) {
data = results.data[key][label]; var data = results.data[key][label];
var table = createTable(key, label, data);
var target = $('[data-defer-to="' + key + '-' + label + '"]');
if (label == 'queries') { if (table) {
table = document.createElement('table'); target.html(table);
} else {
target.text(data);
}
});
});
return $(document).trigger('peek:render', [getRequestId(), results]);
};
createTable = function(key, label, data) {
if (label !== 'queries' && label !== 'details') {
return;
}
var table = document.createElement('table');
for (var i = 0; i < data.length; i += 1) { for (var i = 0; i < data.length; i += 1) {
tr = document.createElement('tr'); table.appendChild(createTableRow(data[i]));
duration_td = document.createElement('td'); }
sql_td = document.createElement('td');
strong = document.createElement('strong');
strong.append(data[i]['duration'] + 'ms'); table.className = 'table';
duration_td.appendChild(strong);
tr.appendChild(duration_td);
sql_td.appendChild(document.createTextNode(data[i]['sql'])); return table;
tr.appendChild(sql_td); };
createTableRow = function(row) {
var tr = document.createElement('tr');
var durationTd = document.createElement('td');
var strong = document.createElement('strong');
table.appendChild(tr); strong.append(row['duration'] + 'ms');
} durationTd.appendChild(strong);
tr.appendChild(durationTd);
table.className = 'table'; ['sql', 'feature', 'enabled', 'request'].forEach(function(key) {
$("[data-defer-to=" + key + "-" + label + "]").html(table); if (!row[key]) { return; }
} else {
$("[data-defer-to=" + key + "-" + label + "]").text(results.data[key][label]); var td = document.createElement('td');
}
}); td.appendChild(document.createTextNode(row[key]));
tr.appendChild(td);
}); });
return $(document).trigger('peek:render', [getRequestId(), results]);
return tr;
}; };
fetchRequestResults = function() { fetchRequestResults = function() {
return $.ajax('/-/peek/results', { return $.ajax('/-/peek/results', {
......
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment