diff --git a/ee/changelogs/unreleased/326225-add-load-balancing-metrics-on-request-level.yml b/ee/changelogs/unreleased/326225-add-load-balancing-metrics-on-request-level.yml new file mode 100644 index 0000000000000000000000000000000000000000..6324a789f6bea817d360c205bc53377a55703087 --- /dev/null +++ b/ee/changelogs/unreleased/326225-add-load-balancing-metrics-on-request-level.yml @@ -0,0 +1,5 @@ +--- +title: Add metric to track querying write ahead log on Request level +merge_request: 58673 +author: +type: other diff --git a/ee/lib/ee/gitlab/metrics/subscribers/active_record.rb b/ee/lib/ee/gitlab/metrics/subscribers/active_record.rb index c856221c48a744cc992f4bb34fd1ebde66c081dd..529323ab30c5367e720dff86f40c4937fd881016 100644 --- a/ee/lib/ee/gitlab/metrics/subscribers/active_record.rb +++ b/ee/lib/ee/gitlab/metrics/subscribers/active_record.rb @@ -9,11 +9,13 @@ module ActiveRecord extend ::Gitlab::Utils::Override DB_LOAD_BALANCING_COUNTERS = %i{ - db_replica_count db_replica_cached_count - db_primary_count db_primary_cached_count + db_replica_count db_replica_cached_count db_replica_wal_count + db_primary_count db_primary_cached_count db_primary_wal_count }.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 + class_methods do extend ::Gitlab::Utils::Override @@ -55,9 +57,14 @@ def sql(event) private + def wal_command?(payload) + payload[:sql].match(SQL_WAL_LOCATION_REGEX) + end + def increment_db_role_counters(db_role, payload) increment("db_#{db_role}_count".to_sym) increment("db_#{db_role}_cached_count".to_sym) if cached_query?(payload) + increment("db_#{db_role}_wal_count".to_sym) if !cached_query?(payload) && wal_command?(payload) end def observe_db_role_duration(db_role, event) diff --git a/ee/spec/initializers/lograge_spec.rb b/ee/spec/initializers/lograge_spec.rb new file mode 100644 index 0000000000000000000000000000000000000000..7bbbdb184297f5707c7a57b328fbb906acbc0aac --- /dev/null +++ b/ee/spec/initializers/lograge_spec.rb @@ -0,0 +1,76 @@ +# frozen_string_literal: true + +require 'spec_helper' + +RSpec.describe 'lograge', type: :request do + context 'with a log subscriber' do + include_context 'parsed logs' + include_context 'clear DB Load Balancing configuration' + + let(:subscriber) { Lograge::LogSubscribers::ActionController.new } + + let(:event) do + ActiveSupport::Notifications::Event.new( + 'process_action.action_controller', + Time.now, + Time.now, + 2, + status: 200, + controller: 'HomeController', + action: 'index', + format: 'application/json', + method: 'GET', + path: '/home?foo=bar', + params: {}, + db_runtime: 0.02, + view_runtime: 0.01 + ) + end + + let(:logging_keys) do + %w[db_primary_wal_count + db_replica_wal_count + db_replica_count + db_replica_cached_count + db_primary_count + db_primary_cached_count + db_primary_duration_s + db_replica_duration_s] + end + + context 'when load balancing is enabled' do + before do + allow(Gitlab::Database::LoadBalancing).to receive(:enable?).and_return(true) + end + + context 'with db payload' do + context 'when RequestStore is enabled', :request_store do + it 'includes db counters' do + subscriber.process_action(event) + expect(log_data).to include(*logging_keys) + end + end + + context 'when RequestStore is disabled' do + it 'does not include db counters' do + subscriber.process_action(event) + + expect(log_data).not_to include(*logging_keys) + end + end + end + end + + context 'when load balancing is disabled' do + before do + allow(Gitlab::Database::LoadBalancing).to receive(:enable?).and_return(false) + end + + it 'does not include db counters' do + subscriber.process_action(event) + + expect(log_data).not_to include(*logging_keys) + end + end + end +end diff --git a/ee/spec/lib/gitlab/instrumentation_helper_spec.rb b/ee/spec/lib/gitlab/instrumentation_helper_spec.rb index 6b61425b0615b23cfef5750d38b0edfec1201135..6b096d9ec5b8124a85e27d56029303dac81fffe6 100644 --- a/ee/spec/lib/gitlab/instrumentation_helper_spec.rb +++ b/ee/spec/lib/gitlab/instrumentation_helper_spec.rb @@ -21,7 +21,9 @@ expect(payload).to include(db_replica_count: 0, db_replica_cached_count: 0, db_primary_count: 0, - db_primary_cached_count: 0) + db_primary_cached_count: 0, + db_primary_wal_count: 0, + db_replica_wal_count: 0) end end @@ -30,13 +32,15 @@ allow(Gitlab::Database::LoadBalancing).to receive(:enable?).and_return(false) end - it 'includes DB counts' do + it 'does not include DB counts' do subject expect(payload).not_to include(db_replica_count: 0, db_replica_cached_count: 0, db_primary_count: 0, - db_primary_cached_count: 0) + db_primary_cached_count: 0, + db_primary_wal_count: 0, + db_replica_wal_count: 0) end end diff --git a/ee/spec/lib/gitlab/metrics/subscribers/active_record_spec.rb b/ee/spec/lib/gitlab/metrics/subscribers/active_record_spec.rb index d83ddc96d1d52609ef32736b732338e822b866ab..e74f56aad00f81cce2d3d3cdf14f1564b4b2a065 100644 --- a/ee/spec/lib/gitlab/metrics/subscribers/active_record_spec.rb +++ b/ee/spec/lib/gitlab/metrics/subscribers/active_record_spec.rb @@ -29,18 +29,20 @@ def sql(query, comments: true) end shared_examples 'track sql events for each role' do - where(:name, :sql_query, :record_query, :record_write_query, :record_cached_query) do - 'SQL' | 'SELECT * FROM users WHERE id = 10' | true | false | false - 'SQL' | 'WITH active_milestones AS (SELECT COUNT(*), state FROM milestones GROUP BY state) SELECT * FROM active_milestones' | true | false | false - 'SQL' | 'SELECT * FROM users WHERE id = 10 FOR UPDATE' | true | true | false - 'SQL' | 'WITH archived_rows AS (SELECT * FROM users WHERE archived = true) INSERT INTO products_log SELECT * FROM archived_rows' | true | true | false - 'SQL' | 'DELETE FROM users where id = 10' | true | true | false - 'SQL' | 'INSERT INTO project_ci_cd_settings (project_id) SELECT id FROM projects' | true | true | false - 'SQL' | 'UPDATE users SET admin = true WHERE id = 10' | true | true | false - 'CACHE' | 'SELECT * FROM users WHERE id = 10' | true | false | true - 'SCHEMA' | "SELECT attr.attname FROM pg_attribute attr INNER JOIN pg_constraint cons ON attr.attrelid = cons.conrelid AND attr.attnum = any(cons.conkey) WHERE cons.contype = 'p' AND cons.conrelid = '\"projects\"'::regclass" | false | false | false - nil | 'BEGIN' | false | false | false - nil | 'COMMIT' | false | false | false + where(:name, :sql_query, :record_query, :record_write_query, :record_cached_query, :record_wal_query) do + 'SQL' | 'SELECT * FROM users WHERE id = 10' | true | false | false | false + 'SQL' | 'WITH active_milestones AS (SELECT COUNT(*), state FROM milestones GROUP BY state) SELECT * FROM active_milestones' | true | false | false | false + 'SQL' | 'SELECT * FROM users WHERE id = 10 FOR UPDATE' | true | true | false | false + 'SQL' | 'WITH archived_rows AS (SELECT * FROM users WHERE archived = true) INSERT INTO products_log SELECT * FROM archived_rows' | true | true | false | false + 'SQL' | 'DELETE FROM users where id = 10' | true | true | false | false + 'SQL' | 'INSERT INTO project_ci_cd_settings (project_id) SELECT id FROM projects' | true | true | false | false + 'SQL' | 'UPDATE users SET admin = true WHERE id = 10' | true | true | false | false + 'SQL' | 'SELECT pg_current_wal_insert_lsn()::text AS location' | true | false | false | true + 'SQL' | 'SELECT pg_last_wal_replay_lsn()::text AS location' | true | false | false | true + 'CACHE' | 'SELECT * FROM users WHERE id = 10' | true | false | true | false + 'SCHEMA' | "SELECT attr.attname FROM pg_attribute attr INNER JOIN pg_constraint cons ON attr.attrelid = cons.conrelid AND attr.attnum = any(cons.conkey) WHERE cons.contype = 'p' AND cons.conrelid = '\"projects\"'::regclass" | false | false | false | false + nil | 'BEGIN' | false | false | false | false + nil | 'COMMIT' | false | false | false | false end with_them do diff --git a/ee/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb b/ee/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb index 791b1ebedc0d4354661b8094c1200111e4e27d02..d94d70641560c971fc43f97dd9c71e844a2b06fa 100644 --- a/ee/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb +++ b/ee/spec/lib/gitlab/sidekiq_logging/structured_logger_spec.rb @@ -76,7 +76,9 @@ 'db_replica_count' => 0, 'db_replica_cached_count' => 0, 'db_primary_count' => a_value >= 1, - 'db_primary_cached_count' => 0 + 'db_primary_cached_count' => 0, + 'db_primary_wal_count' => 0, + 'db_replica_wal_count' => 0 ) end @@ -94,7 +96,9 @@ 'db_replica_count' => 0, 'db_replica_cached_count' => 0, 'db_primary_count' => 0, - 'db_primary_cached_count' => 0 + 'db_primary_cached_count' => 0, + 'db_primary_wal_count' => 0, + 'db_replica_wal_count' => 0 ) end diff --git a/ee/spec/lib/gitlab/sidekiq_middleware/instrumentation_logger_spec.rb b/ee/spec/lib/gitlab/sidekiq_middleware/instrumentation_logger_spec.rb index daead45ade74ca00d83c6e3d184e296f35d605c0..9832e9eceea71f412f510d6b22b42fcec135bc37 100644 --- a/ee/spec/lib/gitlab/sidekiq_middleware/instrumentation_logger_spec.rb +++ b/ee/spec/lib/gitlab/sidekiq_middleware/instrumentation_logger_spec.rb @@ -9,7 +9,9 @@ :db_replica_count, :db_replica_cached_count, :db_primary_count, - :db_primary_cached_count + :db_primary_cached_count, + :db_primary_wal_count, + :db_replica_wal_count ] expect(described_class.keys).to include(*expected_keys) diff --git a/spec/lib/gitlab/metrics/subscribers/active_record_spec.rb b/spec/lib/gitlab/metrics/subscribers/active_record_spec.rb index 9939e680fa982242836060cb1938d16c381fbc46..6bfcfa2128956563400ab35b23905bb6c840d196 100644 --- a/spec/lib/gitlab/metrics/subscribers/active_record_spec.rb +++ b/spec/lib/gitlab/metrics/subscribers/active_record_spec.rb @@ -124,6 +124,7 @@ def sql(query, comments: true) with_them do let(:payload) { { name: name, sql: sql(sql_query, comments: comments), connection: connection } } + let(:record_wal_query) { false } it 'marks the current thread as using the database' do # since it would already have been toggled by other specs diff --git a/spec/support/shared_examples/metrics/active_record_subscriber_shared_examples.rb b/spec/support/shared_examples/metrics/active_record_subscriber_shared_examples.rb index 7bf2456c5480202fe35f47b2dba82e03663a7666..1b110ab02b58a190aa072f8bdced96840e246466 100644 --- a/spec/support/shared_examples/metrics/active_record_subscriber_shared_examples.rb +++ b/spec/support/shared_examples/metrics/active_record_subscriber_shared_examples.rb @@ -16,7 +16,9 @@ db_primary_duration_s: record_query ? 0.002 : 0, db_replica_cached_count: 0, db_replica_count: 0, - db_replica_duration_s: 0.0 + db_replica_duration_s: 0.0, + db_primary_wal_count: record_wal_query ? 1 : 0, + db_replica_wal_count: 0 ) elsif db_role == :replica expect(described_class.db_counter_payload).to eq( @@ -28,7 +30,9 @@ db_primary_duration_s: 0.0, db_replica_cached_count: record_cached_query ? 1 : 0, db_replica_count: record_query ? 1 : 0, - db_replica_duration_s: record_query ? 0.002 : 0 + db_replica_duration_s: record_query ? 0.002 : 0, + db_replica_wal_count: record_wal_query ? 1 : 0, + db_primary_wal_count: 0 ) else expect(described_class.db_counter_payload).to eq( @@ -66,6 +70,12 @@ expect(transaction).not_to receive(:increment).with("gitlab_transaction_db_#{db_role}_cached_count_total".to_sym, 1) if db_role end + if record_wal_query + expect(transaction).to receive(:increment).with("gitlab_transaction_db_#{db_role}_wal_count_total".to_sym, 1) if db_role + else + expect(transaction).not_to receive(:increment).with("gitlab_transaction_db_#{db_role}_wal_count_total".to_sym, 1) if db_role + end + subscriber.sql(event) end