Commit 4529a320 authored by Marius Bobin's avatar Marius Bobin

Log SQL counts from save pipeline step

parent c55c7142
---
name: ci_pipeline_logger_sql
introduced_by_url: https://gitlab.com/gitlab-org/gitlab/-/merge_requests/77117
rollout_issue_url: https://gitlab.com/gitlab-org/gitlab/-/issues/346246
milestone: '14.7'
type: development
group: group::pipeline execution
default_enabled: false
......@@ -9,7 +9,7 @@ module Gitlab
include Gitlab::Utils::StrongMemoize
def perform!
logger.instrument(:pipeline_save) do
logger.instrument(:pipeline_save, sql: true) do
BulkInsertableAssociations.with_bulk_insert do
tags = extract_tag_list_by_status
......
......@@ -23,16 +23,18 @@ module Gitlab
log_conditions.push(block)
end
def instrument(operation)
def instrument(operation, sql: false)
return yield unless enabled?
raise ArgumentError, 'block not given' unless block_given?
op_start_db_counters = current_db_counter_payload if sql && sql_logging_enabled?
op_started_at = current_monotonic_time
result = yield
observe("#{operation}_duration_s", current_monotonic_time - op_started_at)
observe_sql(operation, op_start_db_counters) if sql && sql_logging_enabled?
result
end
......@@ -97,6 +99,25 @@ module Gitlab
def observations
@observations ||= Hash.new { |hash, key| hash[key] = [] }
end
def observe_sql(operation, start_db_counters)
current_db_counter_payload.each do |key, value|
result = value - start_db_counters.fetch(key, 0)
next if result == 0
observe("#{operation}_#{key}", result)
end
end
def current_db_counter_payload
::Gitlab::Metrics::Subscribers::ActiveRecord.db_counter_payload
end
def sql_logging_enabled?
strong_memoize(:sql_logging_enabled) do
::Feature.enabled?(:ci_pipeline_logger_sql, project, default_enabled: :yaml)
end
end
end
end
end
......
......@@ -39,6 +39,38 @@ RSpec.describe ::Gitlab::Ci::Pipeline::Logger do
expect { logger.instrument(:expensive_operation) }
.to raise_error(ArgumentError, 'block not given')
end
context 'with SQL instrumentation', :request_store do
it "returns the block's value" do
expect(logger.instrument(:expensive_operation, sql: true) { Project.count }).to eq(Project.count)
end
it 'includes SQL metrics' do
loggable_data = %w[
expensive_operation_duration_s
expensive_operation_db_count
expensive_operation_db_primary_count
expensive_operation_db_primary_duration_s
expensive_operation_db_main_count
expensive_operation_db_main_duration_s
].each.with_object({}) do |key, accumulator|
accumulator[key] = {
'count' => 1,
'avg' => a_kind_of(Numeric),
'max' => a_kind_of(Numeric),
'min' => a_kind_of(Numeric)
}
end
logger.instrument(:expensive_operation, sql: true) { Project.count }
expect(logger.observations_hash).to match(a_hash_including(loggable_data))
end
it 'does not include SQL metrics when there is no SQL operation' do
logger.instrument(:expensive_operation, sql: true) { 123 }
expect(logger.observations_hash.keys).to match_array(['expensive_operation_duration_s'])
end
end
end
describe '#observe' do
......
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