Commit 7e23bd63 authored by Thong Kuah's avatar Thong Kuah

Merge branch 'move_lb_related_specs' into 'master'

Move LB-related specs to Core

See merge request gitlab-org/gitlab!63269
parents 9ead4da9 4e937960
# 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
......@@ -8,42 +8,6 @@ RSpec.describe Gitlab::InstrumentationHelper do
subject { described_class.add_instrumentation_data(payload) }
context 'when load balancing is enabled' do
include_context 'clear DB Load Balancing configuration'
before do
allow(Gitlab::Database::LoadBalancing).to receive(:enable?).and_return(true)
end
it 'includes DB counts' do
subject
expect(payload).to include(db_replica_count: 0,
db_replica_cached_count: 0,
db_primary_count: 0,
db_primary_cached_count: 0,
db_primary_wal_count: 0,
db_replica_wal_count: 0)
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 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_wal_count: 0,
db_replica_wal_count: 0)
end
end
# We don't want to interact with Elasticsearch in GitLab FOSS so we test
# this in ee/ only. The code exists in FOSS and won't do anything.
context 'when Elasticsearch calls are made', :elastic do
......
# frozen_string_literal: true
require 'spec_helper'
RSpec.describe Gitlab::SidekiqLogging::StructuredLogger do
before do
# We disable a memory instrumentation feature
# as this requires a special patched Ruby
allow(Gitlab::Memory::Instrumentation).to receive(:available?) { false }
end
describe '#call', :request_store do
include_context 'structured_logger'
RSpec.shared_examples 'performs database queries' do |load_balancing|
include_context 'clear DB Load Balancing configuration'
before do
allow(Time).to receive(:now).and_return(timestamp)
allow(Process).to receive(:clock_gettime).and_call_original
allow(Gitlab::Database::LoadBalancing).to receive(:enable?).and_return(load_balancing)
end
let(:expected_start_payload) { start_payload }
let(:expected_end_payload) do
end_payload.merge('cpu_s' => a_value >= 0)
end
it 'logs the database time', :aggregate_errors do
expect(logger).to receive(:info).with(expected_start_payload).ordered
expect(logger).to receive(:info).with(expected_end_payload_with_db).ordered
call_subject(job, 'test_queue') do
ActiveRecord::Base.connection.execute('SELECT pg_sleep(0.1);')
end
end
it 'prevents database time from leaking to the next job', :aggregate_errors do
expect(logger).to receive(:info).with(expected_start_payload).ordered
expect(logger).to receive(:info).with(expected_end_payload_with_db).ordered
expect(logger).to receive(:info).with(expected_start_payload).ordered
expect(logger).to receive(:info).with(expected_end_payload).ordered
call_subject(job.dup, 'test_queue') do
ActiveRecord::Base.connection.execute('SELECT pg_sleep(0.1);')
end
Gitlab::SafeRequestStore.clear!
call_subject(job.dup, 'test_queue') { }
end
end
context 'when the job performs database queries' do
context 'when load balancing is disabled' do
let(:expected_end_payload_with_db) do
expected_end_payload.merge(
'db_duration_s' => a_value >= 0.1,
'db_count' => a_value >= 1,
'db_cached_count' => 0,
'db_write_count' => 0
)
end
include_examples 'performs database queries', false
end
context 'when load balancing is enabled' do
let(:expected_end_payload_with_db) do
expected_end_payload.merge(
'db_duration_s' => a_value >= 0.1,
'db_count' => a_value >= 1,
'db_cached_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_primary_count' => a_value >= 1,
'db_primary_cached_count' => 0,
'db_primary_wal_count' => 0,
'db_primary_duration_s' => a_value > 0
)
end
let(:end_payload) do
start_payload.merge(
'message' => 'TestWorker JID-da883554ee4fe414012f5f42: done: 0.0 sec',
'job_status' => 'done',
'duration_s' => 0.0,
'completed_at' => timestamp.to_f,
'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_duration_s' => 0
)
end
include_examples 'performs database queries', true
end
end
context 'when the job uses load balancing capabilities' do
let(:expected_payload) { { 'database_chosen' => 'retry' } }
before do
allow(Time).to receive(:now).and_return(timestamp)
allow(Process).to receive(:clock_gettime).and_call_original
end
it 'logs the database chosen' do
expect(logger).to receive(:info).with(start_payload).ordered
expect(logger).to receive(:info).with(include(expected_payload)).ordered
call_subject(job, 'test_queue') do
job[:database_chosen] = 'retry'
end
end
end
def call_subject(job, queue)
# This structured logger strongly depends on execution of `InstrumentationLogger`
subject.call(job, queue) do
::Gitlab::SidekiqMiddleware::InstrumentationLogger.new.call('worker', job, queue) do
yield
end
end
end
end
end
......@@ -120,6 +120,7 @@ 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 }
......@@ -195,9 +196,25 @@ RSpec.describe 'lograge', type: :request do
end
context 'with db payload' do
let(:db_load_balancing_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
before do
ActiveRecord::Base.connection.execute('SELECT pg_sleep(0.1);')
end
context 'when RequestStore is enabled', :request_store do
it 'includes db counters' do
ActiveRecord::Base.connection.execute('SELECT pg_sleep(0.1);')
subscriber.process_action(event)
expect(log_data).to include("db_count" => a_value >= 1, "db_write_count" => 0, "db_cached_count" => 0)
......@@ -206,12 +223,47 @@ RSpec.describe 'lograge', type: :request do
context 'when RequestStore is disabled' do
it 'does not include db counters' do
ActiveRecord::Base.connection.execute('SELECT pg_sleep(0.1);')
subscriber.process_action(event)
expect(log_data).not_to include("db_count", "db_write_count", "db_cached_count")
end
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 for load balancing' do
subscriber.process_action(event)
expect(log_data).to include(*db_load_balancing_logging_keys)
end
end
context 'when RequestStore is disabled' do
it 'does not include db counters for load balancing' do
subscriber.process_action(event)
expect(log_data).not_to include(*db_load_balancing_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 for load balancing' do
subscriber.process_action(event)
expect(log_data).not_to include(*db_load_balancing_logging_keys)
end
end
end
end
end
......@@ -117,6 +117,42 @@ RSpec.describe Gitlab::InstrumentationHelper do
end
end
end
context 'when load balancing is enabled' do
include_context 'clear DB Load Balancing configuration'
before do
allow(Gitlab::Database::LoadBalancing).to receive(:enable?).and_return(true)
end
it 'includes DB counts' do
subject
expect(payload).to include(db_replica_count: 0,
db_replica_cached_count: 0,
db_primary_count: 0,
db_primary_cached_count: 0,
db_primary_wal_count: 0,
db_replica_wal_count: 0)
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 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_wal_count: 0,
db_replica_wal_count: 0)
end
end
end
describe '.queue_duration_for_job' do
......
......@@ -228,6 +228,8 @@ RSpec.describe Gitlab::SidekiqLogging::StructuredLogger do
end
context 'when the job performs database queries' do
include_context 'clear DB Load Balancing configuration'
before do
allow(Time).to receive(:now).and_return(timestamp)
allow(Process).to receive(:clock_gettime).and_call_original
......@@ -248,28 +250,112 @@ RSpec.describe Gitlab::SidekiqLogging::StructuredLogger do
)
end
it 'logs the database time' do
expect(logger).to receive(:info).with(expected_start_payload).ordered
expect(logger).to receive(:info).with(expected_end_payload_with_db).ordered
shared_examples 'performs database queries' do
it 'logs the database time', :aggregate_errors do
expect(logger).to receive(:info).with(expected_start_payload).ordered
expect(logger).to receive(:info).with(expected_end_payload_with_db).ordered
call_subject(job, 'test_queue') do
ActiveRecord::Base.connection.execute('SELECT pg_sleep(0.1);')
call_subject(job, 'test_queue') do
ActiveRecord::Base.connection.execute('SELECT pg_sleep(0.1);')
end
end
it 'prevents database time from leaking to the next job', :aggregate_errors do
expect(logger).to receive(:info).with(expected_start_payload).ordered
expect(logger).to receive(:info).with(expected_end_payload_with_db).ordered
expect(logger).to receive(:info).with(expected_start_payload).ordered
expect(logger).to receive(:info).with(expected_end_payload).ordered
call_subject(job.dup, 'test_queue') do
ActiveRecord::Base.connection.execute('SELECT pg_sleep(0.1);')
end
Gitlab::SafeRequestStore.clear!
call_subject(job.dup, 'test_queue') { }
end
end
it 'prevents database time from leaking to the next job' do
expect(logger).to receive(:info).with(expected_start_payload).ordered
expect(logger).to receive(:info).with(expected_end_payload_with_db).ordered
expect(logger).to receive(:info).with(expected_start_payload).ordered
expect(logger).to receive(:info).with(expected_end_payload).ordered
context 'when load balancing is disabled' do
before do
allow(Gitlab::Database::LoadBalancing).to receive(:enable?).and_return(false)
end
call_subject(job.dup, 'test_queue') do
ActiveRecord::Base.connection.execute('SELECT pg_sleep(0.1);')
let(:expected_end_payload_with_db) do
expected_end_payload.merge(
'db_duration_s' => a_value >= 0.1,
'db_count' => a_value >= 1,
'db_cached_count' => 0,
'db_write_count' => 0
)
end
Gitlab::SafeRequestStore.clear!
include_examples 'performs database queries'
end
context 'when load balancing is enabled' do
before do
allow(Gitlab::Database::LoadBalancing).to receive(:enable?).and_return(true)
end
call_subject(job.dup, 'test_queue') { }
let(:expected_end_payload_with_db) do
expected_end_payload.merge(
'db_duration_s' => a_value >= 0.1,
'db_count' => a_value >= 1,
'db_cached_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_primary_count' => a_value >= 1,
'db_primary_cached_count' => 0,
'db_primary_wal_count' => 0,
'db_primary_duration_s' => a_value > 0
)
end
let(:end_payload) do
start_payload.merge(
'message' => 'TestWorker JID-da883554ee4fe414012f5f42: done: 0.0 sec',
'job_status' => 'done',
'duration_s' => 0.0,
'completed_at' => timestamp.to_f,
'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_duration_s' => 0
)
end
include_examples 'performs database queries'
end
end
context 'when the job uses load balancing capabilities' do
let(:expected_payload) { { 'database_chosen' => 'retry' } }
before do
allow(Time).to receive(:now).and_return(timestamp)
allow(Process).to receive(:clock_gettime).and_call_original
end
it 'logs the database chosen' do
expect(logger).to receive(:info).with(start_payload).ordered
expect(logger).to receive(:info).with(include(expected_payload)).ordered
call_subject(job, 'test_queue') do
job[:database_chosen] = 'retry'
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