Commit c44d337b authored by Sean McGivern's avatar Sean McGivern

Merge branch '336838-log-db-config-name-for-db-count' into 'master'

Add per DB counters to logs and refactor

See merge request gitlab-org/gitlab!66885
parents 7f6290f0 ebbdd30d
---
name: multiple_database_metrics
introduced_by_url: https://gitlab.com/gitlab-org/gitlab/-/merge_requests/63490
rollout_issue_url: https://gitlab.com/gitlab-org/gitlab/-/issues/333227
milestone: '14.1'
type: development
group: group::sharding
default_enabled: false
...@@ -31,9 +31,9 @@ From left to right, the performance bar displays: ...@@ -31,9 +31,9 @@ From left to right, the performance bar displays:
was sent to the read/write primary server. "Replica" means it was sent was sent to the read/write primary server. "Replica" means it was sent
to a read-only replica. to a read-only replica.
- **Config name**: shows up only when the - **Config name**: shows up only when the
`multiple_database_metrics` feature flag is enabled. This is used to `GITLAB_MULTIPLE_DATABASE_METRICS` environment variable is set. This is
distinguish between different databases configured for different GitLab used to distinguish between different databases configured for different
features. The name shown is the same name used to configure database GitLab features. The name shown is the same name used to configure database
connections in GitLab. connections in GitLab.
- **Gitaly calls**: the time taken (in milliseconds) and the total number of - **Gitaly calls**: the time taken (in milliseconds) and the total number of
[Gitaly](../../gitaly/index.md) calls. Click to display a modal window with more [Gitaly](../../gitaly/index.md) calls. Click to display a modal window with more
......
...@@ -163,6 +163,10 @@ module Gitlab ...@@ -163,6 +163,10 @@ module Gitlab
end end
end end
def self.db_config_names
::ActiveRecord::Base.configurations.configs_for(env_name: Rails.env).map(&:name)
end
def self.db_config_name(ar_connection) def self.db_config_name(ar_connection)
if ar_connection.respond_to?(:pool) && if ar_connection.respond_to?(:pool) &&
ar_connection.pool.respond_to?(:db_config) && ar_connection.pool.respond_to?(:db_config) &&
......
...@@ -8,17 +8,15 @@ module Gitlab ...@@ -8,17 +8,15 @@ module Gitlab
attach_to :active_record attach_to :active_record
IGNORABLE_SQL = %w{BEGIN COMMIT}.freeze IGNORABLE_SQL = %w{BEGIN COMMIT}.freeze
DB_COUNTERS = %i{db_count db_write_count db_cached_count}.freeze DB_COUNTERS = %i{count write_count cached_count}.freeze
SQL_COMMANDS_WITH_COMMENTS_REGEX = %r{\A(/\*.*\*/\s)?((?!(.*[^\w'"](DELETE|UPDATE|INSERT INTO)[^\w'"])))(WITH.*)?(SELECT)((?!(FOR UPDATE|FOR SHARE)).)*$}i.freeze SQL_COMMANDS_WITH_COMMENTS_REGEX = %r{\A(/\*.*\*/\s)?((?!(.*[^\w'"](DELETE|UPDATE|INSERT INTO)[^\w'"])))(WITH.*)?(SELECT)((?!(FOR UPDATE|FOR SHARE)).)*$}i.freeze
SQL_DURATION_BUCKET = [0.05, 0.1, 0.25].freeze SQL_DURATION_BUCKET = [0.05, 0.1, 0.25].freeze
TRANSACTION_DURATION_BUCKET = [0.1, 0.25, 1].freeze TRANSACTION_DURATION_BUCKET = [0.1, 0.25, 1].freeze
DB_LOAD_BALANCING_COUNTERS = %i{ DB_LOAD_BALANCING_ROLES = %i{replica primary}.freeze
db_replica_count db_replica_cached_count db_replica_wal_count db_replica_wal_cached_count DB_LOAD_BALANCING_COUNTERS = %i{count cached_count wal_count wal_cached_count}.freeze
db_primary_count db_primary_cached_count db_primary_wal_count db_primary_wal_cached_count DB_LOAD_BALANCING_DURATIONS = %i{duration_s}.freeze
}.freeze
DB_LOAD_BALANCING_DURATIONS = %i{db_primary_duration_s db_replica_duration_s}.freeze
SQL_WAL_LOCATION_REGEX = /(pg_current_wal_insert_lsn\(\)::text|pg_last_wal_replay_lsn\(\)::text)/.freeze SQL_WAL_LOCATION_REGEX = /(pg_current_wal_insert_lsn\(\)::text|pg_last_wal_replay_lsn\(\)::text)/.freeze
...@@ -40,9 +38,10 @@ module Gitlab ...@@ -40,9 +38,10 @@ module Gitlab
payload = event.payload payload = event.payload
return if ignored_query?(payload) return if ignored_query?(payload)
increment(:db_count) db_config_name = db_config_name(event.payload)
increment(:db_cached_count) if cached_query?(payload) increment(:count, db_config_name: db_config_name)
increment(:db_write_count) unless select_sql_command?(payload) increment(:cached_count, db_config_name: db_config_name) if cached_query?(payload)
increment(:write_count, db_config_name: db_config_name) unless select_sql_command?(payload)
observe(:gitlab_sql_duration_seconds, event) do observe(:gitlab_sql_duration_seconds, event) do
buckets SQL_DURATION_BUCKET buckets SQL_DURATION_BUCKET
...@@ -61,24 +60,17 @@ module Gitlab ...@@ -61,24 +60,17 @@ module Gitlab
return {} unless Gitlab::SafeRequestStore.active? return {} unless Gitlab::SafeRequestStore.active?
{}.tap do |payload| {}.tap do |payload|
DB_COUNTERS.each do |counter| db_counter_keys.each do |key|
payload[counter] = Gitlab::SafeRequestStore[counter].to_i payload[key] = Gitlab::SafeRequestStore[key].to_i
end end
if ::Gitlab::SafeRequestStore.active? && ::Gitlab::Database::LoadBalancing.enable? if ::Gitlab::SafeRequestStore.active? && ::Gitlab::Database::LoadBalancing.enable?
DB_LOAD_BALANCING_COUNTERS.each do |counter| load_balancing_metric_counter_keys.each do |counter|
payload[counter] = ::Gitlab::SafeRequestStore[counter].to_i payload[counter] = ::Gitlab::SafeRequestStore[counter].to_i
end end
DB_LOAD_BALANCING_DURATIONS.each do |duration|
payload[duration] = ::Gitlab::SafeRequestStore[duration].to_f.round(3)
end
if Feature.enabled?(:multiple_database_metrics, default_enabled: :yaml) load_balancing_metric_duration_keys.each do |duration|
::Gitlab::SafeRequestStore[:duration_by_database]&.each do |name, duration_by_role| payload[duration] = ::Gitlab::SafeRequestStore[duration].to_f.round(3)
duration_by_role.each do |db_role, duration|
payload[:"db_#{db_role}_#{name}_duration_s"] = duration.to_f.round(3)
end
end
end end
end end
end end
...@@ -92,12 +84,15 @@ module Gitlab ...@@ -92,12 +84,15 @@ module Gitlab
def increment_db_role_counters(db_role, payload) def increment_db_role_counters(db_role, payload)
cached = cached_query?(payload) cached = cached_query?(payload)
increment("db_#{db_role}_count".to_sym)
increment("db_#{db_role}_cached_count".to_sym) if cached db_config_name = db_config_name(payload)
increment(:count, db_role: db_role, db_config_name: db_config_name)
increment(:cached_count, db_role: db_role, db_config_name: db_config_name) if cached
if wal_command?(payload) if wal_command?(payload)
increment("db_#{db_role}_wal_count".to_sym) increment(:wal_count, db_role: db_role, db_config_name: db_config_name)
increment("db_#{db_role}_wal_cached_count".to_sym) if cached increment(:wal_cached_count, db_role: db_role, db_config_name: db_config_name) if cached
end end
end end
...@@ -109,15 +104,13 @@ module Gitlab ...@@ -109,15 +104,13 @@ module Gitlab
return unless ::Gitlab::SafeRequestStore.active? return unless ::Gitlab::SafeRequestStore.active?
duration = event.duration / 1000.0 duration = event.duration / 1000.0
duration_key = "db_#{db_role}_duration_s".to_sym duration_key = compose_metric_key(:duration_s, db_role)
::Gitlab::SafeRequestStore[duration_key] = (::Gitlab::SafeRequestStore[duration_key].presence || 0) + duration ::Gitlab::SafeRequestStore[duration_key] = (::Gitlab::SafeRequestStore[duration_key].presence || 0) + duration
# Per database metrics # Per database metrics
name = ::Gitlab::Database.db_config_name(event.payload[:connection]) db_config_name = db_config_name(event.payload)
::Gitlab::SafeRequestStore[:duration_by_database] ||= {} duration_key = compose_metric_key(:duration_s, db_role, db_config_name)
::Gitlab::SafeRequestStore[:duration_by_database][name] ||= {} ::Gitlab::SafeRequestStore[duration_key] = (::Gitlab::SafeRequestStore[duration_key].presence || 0) + duration
::Gitlab::SafeRequestStore[:duration_by_database][name][db_role] ||= 0
::Gitlab::SafeRequestStore[:duration_by_database][name][db_role] += duration
end end
def ignored_query?(payload) def ignored_query?(payload)
...@@ -132,10 +125,25 @@ module Gitlab ...@@ -132,10 +125,25 @@ module Gitlab
payload[:sql].match(SQL_COMMANDS_WITH_COMMENTS_REGEX) payload[:sql].match(SQL_COMMANDS_WITH_COMMENTS_REGEX)
end end
def increment(counter) def increment(counter, db_config_name:, db_role: nil)
current_transaction&.increment("gitlab_transaction_#{counter}_total".to_sym, 1) log_key = compose_metric_key(counter, db_role)
prometheus_key = if db_role
:"gitlab_transaction_db_#{db_role}_#{counter}_total"
else
:"gitlab_transaction_db_#{counter}_total"
end
Gitlab::SafeRequestStore[counter] = Gitlab::SafeRequestStore[counter].to_i + 1 current_transaction&.increment(prometheus_key, 1)
Gitlab::SafeRequestStore[log_key] = Gitlab::SafeRequestStore[log_key].to_i + 1
# To avoid confusing log keys we only log the db_config_name metrics
# when we are also logging the db_role. Otherwise it will be hard to
# tell if the log key is referring to a db_role OR a db_config_name.
if db_role.present? && db_config_name.present?
log_key = compose_metric_key(counter, db_role, db_config_name)
Gitlab::SafeRequestStore[log_key] = Gitlab::SafeRequestStore[log_key].to_i + 1
end
end end
def observe(histogram, event, &block) def observe(histogram, event, &block)
...@@ -145,6 +153,45 @@ module Gitlab ...@@ -145,6 +153,45 @@ module Gitlab
def current_transaction def current_transaction
::Gitlab::Metrics::WebTransaction.current || ::Gitlab::Metrics::BackgroundTransaction.current ::Gitlab::Metrics::WebTransaction.current || ::Gitlab::Metrics::BackgroundTransaction.current
end end
def db_config_name(payload)
::Gitlab::Database.db_config_name(payload[:connection])
end
def self.db_counter_keys
DB_COUNTERS.map { |c| compose_metric_key(c) }
end
def self.load_balancing_metric_counter_keys
load_balancing_metric_keys(DB_LOAD_BALANCING_COUNTERS)
end
def self.load_balancing_metric_duration_keys
load_balancing_metric_keys(DB_LOAD_BALANCING_DURATIONS)
end
def self.load_balancing_metric_keys(metrics)
[].tap do |counters|
DB_LOAD_BALANCING_ROLES.each do |role|
metrics.each do |metric|
counters << compose_metric_key(metric, role)
next unless ENV['GITLAB_MULTIPLE_DATABASE_METRICS']
::Gitlab::Database.db_config_names.each do |config_name|
counters << compose_metric_key(metric, role, config_name)
end
end
end
end
end
def compose_metric_key(metric, db_role = nil, db_config_name = nil)
self.class.compose_metric_key(metric, db_role, db_config_name)
end
def self.compose_metric_key(metric, db_role = nil, db_config_name = nil)
[:db, db_role, db_config_name, metric].compact.join("_").to_sym
end
end end
end end
end end
......
...@@ -81,7 +81,7 @@ module Peek ...@@ -81,7 +81,7 @@ module Peek
end end
def format_call_details(call) def format_call_details(call)
if Feature.enabled?(:multiple_database_metrics, default_enabled: :yaml) if ENV['GITLAB_MULTIPLE_DATABASE_METRICS']
super super
else else
super.except(:db_config_name) super.except(:db_config_name)
......
...@@ -294,47 +294,38 @@ RSpec.describe Gitlab::SidekiqLogging::StructuredLogger do ...@@ -294,47 +294,38 @@ RSpec.describe Gitlab::SidekiqLogging::StructuredLogger do
context 'when load balancing is enabled', :db_load_balancing do context 'when load balancing is enabled', :db_load_balancing do
let(:db_config_name) { ::Gitlab::Database.db_config_name(ApplicationRecord.connection) } let(:db_config_name) { ::Gitlab::Database.db_config_name(ApplicationRecord.connection) }
let(:expected_db_payload_defaults) do
metrics =
::Gitlab::Metrics::Subscribers::ActiveRecord.load_balancing_metric_counter_keys +
::Gitlab::Metrics::Subscribers::ActiveRecord.load_balancing_metric_duration_keys +
::Gitlab::Metrics::Subscribers::ActiveRecord.db_counter_keys +
[:db_duration_s]
metrics.each_with_object({}) do |key, result|
result[key.to_s] = 0
end
end
let(:expected_end_payload_with_db) do let(:expected_end_payload_with_db) do
expected_end_payload.merge( expected_end_payload.merge(expected_db_payload_defaults).merge(
'db_duration_s' => a_value >= 0.1, 'db_duration_s' => a_value >= 0.1,
'db_count' => a_value >= 1, 'db_count' => a_value >= 1,
'db_cached_count' => 0, "db_replica_#{db_config_name}_count" => 0,
'db_write_count' => 0,
'db_replica_count' => 0,
'db_replica_cached_count' => 0,
'db_replica_wal_count' => 0,
'db_replica_duration_s' => a_value >= 0, 'db_replica_duration_s' => a_value >= 0,
'db_primary_count' => a_value >= 1, 'db_primary_count' => a_value >= 1,
'db_primary_cached_count' => 0, "db_primary_#{db_config_name}_count" => a_value >= 1,
'db_primary_wal_count' => 0,
'db_primary_duration_s' => a_value > 0, 'db_primary_duration_s' => a_value > 0,
"db_primary_#{db_config_name}_duration_s" => a_value > 0, "db_primary_#{db_config_name}_duration_s" => a_value > 0
'db_primary_wal_cached_count' => 0,
'db_replica_wal_cached_count' => 0
) )
end end
let(:end_payload) do let(:end_payload) do
start_payload.merge( start_payload.merge(expected_db_payload_defaults).merge(
'message' => 'TestWorker JID-da883554ee4fe414012f5f42: done: 0.0 sec', 'message' => 'TestWorker JID-da883554ee4fe414012f5f42: done: 0.0 sec',
'job_status' => 'done', 'job_status' => 'done',
'duration_s' => 0.0, 'duration_s' => 0.0,
'completed_at' => timestamp.to_f, 'completed_at' => timestamp.to_f,
'cpu_s' => 1.111112, 'cpu_s' => 1.111112
'db_duration_s' => 0.0,
'db_cached_count' => 0,
'db_count' => 0,
'db_write_count' => 0,
'db_replica_count' => 0,
'db_replica_cached_count' => 0,
'db_replica_wal_count' => 0,
'db_replica_duration_s' => 0,
'db_primary_count' => 0,
'db_primary_cached_count' => 0,
'db_primary_wal_count' => 0,
'db_primary_wal_cached_count' => 0,
'db_replica_wal_cached_count' => 0,
'db_primary_duration_s' => 0
) )
end end
......
...@@ -109,9 +109,9 @@ RSpec.describe Peek::Views::ActiveRecord, :request_store do ...@@ -109,9 +109,9 @@ RSpec.describe Peek::Views::ActiveRecord, :request_store do
) )
end end
context 'when the multiple_database_metrics feature flag is disabled' do context 'when the GITLAB_MULTIPLE_DATABASE_METRICS env var is disabled' do
before do before do
stub_feature_flags(multiple_database_metrics: false) stub_env('GITLAB_MULTIPLE_DATABASE_METRICS', nil)
end end
it 'does not include db_config_name field' do it 'does not include db_config_name field' do
...@@ -191,9 +191,9 @@ RSpec.describe Peek::Views::ActiveRecord, :request_store do ...@@ -191,9 +191,9 @@ RSpec.describe Peek::Views::ActiveRecord, :request_store do
) )
end end
context 'when the multiple_database_metrics feature flag is disabled' do context 'when the GITLAB_MULTIPLE_DATABASE_METRICS env var is disabled' do
before do before do
stub_feature_flags(multiple_database_metrics: false) stub_env('GITLAB_MULTIPLE_DATABASE_METRICS', nil)
end end
it 'does not include db_config_name field' do it 'does not include db_config_name field' do
......
# frozen_string_literal: true
RSpec.configure do |config|
config.before do
# Enable this by default in all tests so it behaves like a FF
stub_env('GITLAB_MULTIPLE_DATABASE_METRICS', '1')
end
end
# frozen_string_literal: true # frozen_string_literal: true
RSpec.shared_examples 'store ActiveRecord info in RequestStore' do |db_role| RSpec.shared_examples 'store ActiveRecord info in RequestStore' do |db_role|
let(:db_config_name) { ::Gitlab::Database.db_config_name(ApplicationRecord.connection) }
let(:expected_payload_defaults) do
metrics =
::Gitlab::Metrics::Subscribers::ActiveRecord.load_balancing_metric_counter_keys +
::Gitlab::Metrics::Subscribers::ActiveRecord.load_balancing_metric_duration_keys +
::Gitlab::Metrics::Subscribers::ActiveRecord.db_counter_keys
metrics.each_with_object({}) do |key, result|
result[key] = 0
end
end
it 'prevents db counters from leaking to the next transaction' do it 'prevents db counters from leaking to the next transaction' do
2.times do 2.times do
Gitlab::WithRequestStore.with_request_store do Gitlab::WithRequestStore.with_request_store do
subscriber.sql(event) subscriber.sql(event)
connection = event.payload[:connection]
expected = if db_role == :primary
if db_role == :primary expected_payload_defaults.merge({
expected = { db_count: record_query ? 1 : 0,
db_count: record_query ? 1 : 0, db_write_count: record_write_query ? 1 : 0,
db_write_count: record_write_query ? 1 : 0, db_cached_count: record_cached_query ? 1 : 0,
db_cached_count: record_cached_query ? 1 : 0, db_primary_cached_count: record_cached_query ? 1 : 0,
db_primary_cached_count: record_cached_query ? 1 : 0, "db_primary_#{db_config_name}_cached_count": record_cached_query ? 1 : 0,
db_primary_count: record_query ? 1 : 0, db_primary_count: record_query ? 1 : 0,
db_primary_duration_s: record_query ? 0.002 : 0, "db_primary_#{db_config_name}_count": record_query ? 1 : 0,
db_replica_cached_count: 0, db_primary_duration_s: record_query ? 0.002 : 0,
db_replica_count: 0, "db_primary_#{db_config_name}_duration_s": record_query ? 0.002 : 0,
db_replica_duration_s: 0.0, db_primary_wal_count: record_wal_query ? 1 : 0,
db_primary_wal_count: record_wal_query ? 1 : 0, "db_primary_#{db_config_name}_wal_count": record_wal_query ? 1 : 0,
db_primary_wal_cached_count: record_wal_query && record_cached_query ? 1 : 0, db_primary_wal_cached_count: record_wal_query && record_cached_query ? 1 : 0,
db_replica_wal_cached_count: 0, "db_primary_#{db_config_name}_wal_cached_count": record_wal_query && record_cached_query ? 1 : 0
db_replica_wal_count: 0 })
} elsif db_role == :replica
expected[:"db_primary_#{::Gitlab::Database.db_config_name(connection)}_duration_s"] = 0.002 if record_query expected_payload_defaults.merge({
elsif db_role == :replica db_count: record_query ? 1 : 0,
expected = { db_write_count: record_write_query ? 1 : 0,
db_count: record_query ? 1 : 0, db_cached_count: record_cached_query ? 1 : 0,
db_write_count: record_write_query ? 1 : 0, db_replica_cached_count: record_cached_query ? 1 : 0,
db_cached_count: record_cached_query ? 1 : 0, "db_replica_#{db_config_name}_cached_count": record_cached_query ? 1 : 0,
db_primary_cached_count: 0, db_replica_count: record_query ? 1 : 0,
db_primary_count: 0, "db_replica_#{db_config_name}_count": record_query ? 1 : 0,
db_primary_duration_s: 0.0, db_replica_duration_s: record_query ? 0.002 : 0,
db_replica_cached_count: record_cached_query ? 1 : 0, "db_replica_#{db_config_name}_duration_s": record_query ? 0.002 : 0,
db_replica_count: record_query ? 1 : 0, db_replica_wal_count: record_wal_query ? 1 : 0,
db_replica_duration_s: record_query ? 0.002 : 0, "db_replica_#{db_config_name}_wal_count": record_wal_query ? 1 : 0,
db_replica_wal_count: record_wal_query ? 1 : 0, db_replica_wal_cached_count: record_wal_query && record_cached_query ? 1 : 0,
db_replica_wal_cached_count: record_wal_query && record_cached_query ? 1 : 0, "db_replica_#{db_config_name}_wal_cached_count": record_wal_query && record_cached_query ? 1 : 0
db_primary_wal_cached_count: 0, })
db_primary_wal_count: 0 else
} {
expected[:"db_replica_#{::Gitlab::Database.db_config_name(connection)}_duration_s"] = 0.002 if record_query db_count: record_query ? 1 : 0,
else db_write_count: record_write_query ? 1 : 0,
expected = { db_cached_count: record_cached_query ? 1 : 0
db_count: record_query ? 1 : 0, }
db_write_count: record_write_query ? 1 : 0, end
db_cached_count: record_cached_query ? 1 : 0
}
end
expect(described_class.db_counter_payload).to eq(expected) expect(described_class.db_counter_payload).to eq(expected)
end end
end end
end end
context 'when multiple_database_metrics is disabled' do context 'when the GITLAB_MULTIPLE_DATABASE_METRICS env var is disabled' do
before do before do
stub_feature_flags(multiple_database_metrics: false) stub_env('GITLAB_MULTIPLE_DATABASE_METRICS', nil)
end end
it 'does not include per database metrics' do it 'does not include per database metrics' do
Gitlab::WithRequestStore.with_request_store do Gitlab::WithRequestStore.with_request_store do
subscriber.sql(event) subscriber.sql(event)
connection = event.payload[:connection]
expect(described_class.db_counter_payload).not_to include(:"db_replica_#{::Gitlab::Database.db_config_name(connection)}_duration_s") expect(described_class.db_counter_payload).not_to include(:"db_replica_#{db_config_name}_duration_s")
expect(described_class.db_counter_payload).not_to include(:"db_replica_#{db_config_name}_count")
end end
end end
end end
......
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