Skip to content

G
gitlab-ce
Commit 05f9a5e7 authored by Andrejs Cunskis's avatar Andrejs Cunskis Committed by Mark Lapierre
Browse files
Options

E2E: Reduce repeater log verbosity if first attempt is successfull

parent ee988aaa
Hide whitespace changes
Inline Side-by-side
Showing with 112 additions and 154 deletions
qa/qa/support/matchers/eventually_matcher.rb
View file @ 05f9a5e7
......@@ -59,8 +59,10 @@ module QA
def wait_and_check(actual, expectation_name)
attempt = 0
QA::Runtime::Logger.debug("Running eventually matcher with '#{operator_msg}' operator")
QA::Support::Retrier.retry_until(**@retry_args) do
QA::Runtime::Logger.debug(
"Running eventually matcher with '#{operator_msg}' operator with: #{@retry_args}"
)
QA::Support::Retrier.retry_until(**@retry_args, log: false) do
QA::Runtime::Logger.debug("evaluating expectation, attempt: #{attempt += 1}")
public_send(expectation_name, actual)
......
qa/qa/support/repeater.rb
View file @ 05f9a5e7
......@@ -25,10 +25,26 @@ module QA
begin
while remaining_attempts?(attempts, max_attempts) && remaining_time?(start, max_duration)
QA::Runtime::Logger.debug("Attempt number #{attempts + 1}") if max_attempts && log
# start logging from the second attempt
if log && attempts == 1
msg = ["Retrying action with:"]
msg << "max_attempts: #{max_attempts};" if max_attempts
msg << "max_duration: #{max_duration};" if max_duration
msg << "reload_page: #{reload_page};" if reload_page
msg << "sleep_interval: #{sleep_interval};"
msg << "raise_on_failure: #{raise_on_failure};"
msg << "retry_on_exception: #{retry_on_exception}"
QA::Runtime::Logger.debug(msg.join(' '))
end
QA::Runtime::Logger.debug("Attempt number #{attempts + 1}") if log && max_attempts && attempts > 0
result = yield
return result if result
if result
log_completion(log, attempts)
return result
end
sleep_and_reload_if_needed(sleep_interval, reload_page)
attempts += 1
......@@ -54,6 +70,8 @@ module QA
raise WaitExceededError, "Wait condition not met after #{max_duration} #{'second'.pluralize(max_duration)}"
end
log_completion(log, attempts)
false
end
......@@ -71,6 +89,17 @@ module QA
def remaining_time?(start, max_duration)
max_duration ? Time.now - start < max_duration : true
end
# Log completion if more than one attempt performed
#
# @param [Boolean] log
# @param [Integer] attempts
# @return [void]
def log_completion(log, attempts)
return unless log && attempts > 0
QA::Runtime::Logger.debug('ended retry')
end
end
end
end
qa/qa/support/retrier.rb
View file @ 05f9a5e7
......@@ -8,13 +8,6 @@ module QA
module_function
def retry_on_exception(max_attempts: 3, reload_page: nil, sleep_interval: 0.5, log: true)
if log
msg = ["with retry_on_exception: max_attempts: #{max_attempts}"]
msg << "reload_page: #{reload_page}" if reload_page
msg << "sleep_interval: #{sleep_interval}"
QA::Runtime::Logger.debug(msg.join('; '))
end
result = nil
repeat_until(
max_attempts: max_attempts,
......@@ -29,7 +22,6 @@ module QA
# We set it to `true` so that it doesn't repeat if there's no exception
true
end
QA::Runtime::Logger.debug("ended retry_on_exception") if log
result
end
......@@ -46,20 +38,6 @@ module QA
# For backwards-compatibility
max_attempts = 3 if max_attempts.nil? && max_duration.nil?
if log
start_msg = ["with retry_until:"]
start_msg << "max_attempts: #{max_attempts};" if max_attempts
start_msg << "max_duration: #{max_duration};" if max_duration
start_msg.push(*[
"reload_page: #{reload_page};",
"sleep_interval: #{sleep_interval};",
"raise_on_failure: #{raise_on_failure};",
"retry_on_exception: #{retry_on_exception}"
])
QA::Runtime::Logger.debug(start_msg.join(' '))
end
result = nil
repeat_until(
max_attempts: max_attempts,
......@@ -72,7 +50,6 @@ module QA
) do
result = yield
end
QA::Runtime::Logger.debug("ended retry_until") if log
result
end
......
qa/qa/support/waiter.rb
View file @ 05f9a5e7
......@@ -7,20 +7,16 @@ module QA
module_function
def wait_until(max_duration: singleton_class::DEFAULT_MAX_WAIT_TIME, reload_page: nil, sleep_interval: 0.1, raise_on_failure: true, retry_on_exception: false, log: true)
if log
QA::Runtime::Logger.debug(
<<~MSG.tr("\n", ' ')
with wait_until: max_duration: #{max_duration};
reload_page: #{reload_page};
sleep_interval: #{sleep_interval};
raise_on_failure: #{raise_on_failure}
MSG
)
end
def wait_until(
max_duration: singleton_class::DEFAULT_MAX_WAIT_TIME,
reload_page: nil,
sleep_interval: 0.1,
raise_on_failure: true,
retry_on_exception: false,
log: true
)
result = nil
self.repeat_until(
repeat_until(
max_duration: max_duration,
reload_page: reload_page,
sleep_interval: sleep_interval,
......@@ -30,7 +26,6 @@ module QA
) do
result = yield
end
QA::Runtime::Logger.debug("ended wait_until") if log
result
end
......
qa/spec/support/repeater_spec.rb
View file @ 05f9a5e7
......@@ -380,34 +380,67 @@ RSpec.describe QA::Support::Repeater do
end
end
it 'logs attempts' do
attempted = false
expect do
subject.repeat_until(max_attempts: 1) do
unless attempted
attempted = true
break false
end
context 'with logging' do
before do
allow(QA::Runtime::Logger).to receive(:debug)
end
it 'skips logging single attempt with max_attempts' do
subject.repeat_until(max_attempts: 3) do
true
end
end.to output(/Attempt number/).to_stdout_from_any_process
end
it 'allows logging to be silenced' do
attempted = false
expect do
subject.repeat_until(max_attempts: 1, log: false) do
unless attempted
attempted = true
break false
end
expect(QA::Runtime::Logger).not_to have_received(:debug)
end
it 'skips logging single attempt with max_duration' do
subject.repeat_until(max_duration: 3) do
true
end
end.not_to output.to_stdout_from_any_process
expect(QA::Runtime::Logger).not_to have_received(:debug)
end
it 'allows logging to be silenced' do
subject.repeat_until(max_attempts: 3, log: false, raise_on_failure: false) do
false
end
expect(QA::Runtime::Logger).not_to have_received(:debug)
end
it 'starts logging on subsequent attempts for max_duration' do
subject.repeat_until(max_duration: 0.3, sleep_interval: 0.1, raise_on_failure: false) do
false
end
aggregate_failures do
expect(QA::Runtime::Logger).to have_received(:debug).with(<<~MSG.strip).ordered.once
Retrying action with: max_duration: 0.3; sleep_interval: 0.1; raise_on_failure: false; retry_on_exception: false
MSG
expect(QA::Runtime::Logger).to have_received(:debug).with('ended retry').ordered.once
expect(QA::Runtime::Logger).not_to have_received(:debug).with(/Attempt number/)
end
end
it 'starts logging subsequent attempts for max_attempts' do
attempts = 0
subject.repeat_until(max_attempts: 4, raise_on_failure: false) do
next true if attempts == 2
attempts += 1
false
end
aggregate_failures do
expect(QA::Runtime::Logger).to have_received(:debug).with(<<~MSG.strip).ordered.once
Retrying action with: max_attempts: 4; sleep_interval: 0; raise_on_failure: false; retry_on_exception: false
MSG
expect(QA::Runtime::Logger).to have_received(:debug).with('Attempt number 2').ordered.once
expect(QA::Runtime::Logger).to have_received(:debug).with('Attempt number 3').ordered.once
expect(QA::Runtime::Logger).to have_received(:debug).with('ended retry').ordered.once
end
end
end
end
end
qa/spec/support/retrier_spec.rb
View file @ 05f9a5e7
# frozen_string_literal: true
RSpec.describe QA::Support::Retrier do
before do
logger = ::Logger.new $stdout
logger.level = ::Logger::DEBUG
QA::Runtime::Logger.logger = logger
end
describe '.retry_until' do
context 'when the condition is true' do
it 'logs max attempts (3 by default)' do
expect { subject.retry_until { true } }
.to output(/with retry_until: max_attempts: 3; reload_page: ; sleep_interval: 0; raise_on_failure: true; retry_on_exception: false/).to_stdout_from_any_process
end
it 'logs max duration' do
expect { subject.retry_until(max_duration: 1) { true } }
.to output(/with retry_until: max_duration: 1; reload_page: ; sleep_interval: 0; raise_on_failure: true; retry_on_exception: false/).to_stdout_from_any_process
end
it 'logs the end' do
expect { subject.retry_until { true } }
.to output(/ended retry_until$/).to_stdout_from_any_process
end
end
context 'when the condition is false' do
it 'logs the start' do
expect { subject.retry_until(max_duration: 0, raise_on_failure: false) { false } }
.to output(/with retry_until: max_duration: 0; reload_page: ; sleep_interval: 0; raise_on_failure: false; retry_on_exception: false/).to_stdout_from_any_process
end
it 'logs the end' do
expect { subject.retry_until(max_duration: 0, raise_on_failure: false) { false } }
.to output(/ended retry_until$/).to_stdout_from_any_process
end
end
context 'when max_duration and max_attempts are nil' do
it 'sets max attempts to 3 by default' do
expect(subject).to receive(:repeat_until).with(hash_including(max_attempts: 3))
......@@ -62,35 +27,15 @@ RSpec.describe QA::Support::Retrier do
subject.retry_until
end
end
describe '.retry_on_exception' do
context 'when the condition is true' do
it 'logs max_attempts, reload_page, and sleep_interval parameters' do
message = /with retry_on_exception: max_attempts: 1; reload_page: true; sleep_interval: 0/
expect { subject.retry_on_exception(max_attempts: 1, reload_page: true, sleep_interval: 0) { true } }
.to output(message).to_stdout_from_any_process
end
it 'logs the end' do
expect { subject.retry_on_exception(max_attempts: 1, reload_page: nil, sleep_interval: 0) { true } }
.to output(/ended retry_on_exception$/).to_stdout_from_any_process
end
end
context 'when the condition is false' do
it 'logs the start' do
message = /with retry_on_exception: max_attempts: 1; reload_page: true; sleep_interval: 0/
expect { subject.retry_on_exception(max_attempts: 1, reload_page: true, sleep_interval: 0) { false } }
.to output(message).to_stdout_from_any_process
end
it 'allows logs to be silenced' do
expect(subject).to receive(:repeat_until).with(hash_including(log: false))
it 'logs the end' do
expect { subject.retry_on_exception(max_attempts: 1, reload_page: nil, sleep_interval: 0) { false } }
.to output(/ended retry_on_exception$/).to_stdout_from_any_process
end
subject.retry_until(log: false)
end
end
describe '.retry_on_exception' do
it 'does not repeat if no exception is raised' do
loop_counter = 0
return_value = "test passed"
......@@ -121,5 +66,11 @@ RSpec.describe QA::Support::Retrier do
subject.retry_on_exception
end
it 'allows logs to be silenced' do
expect(subject).to receive(:repeat_until).with(hash_including(log: false))
subject.retry_on_exception(log: false)
end
end
end
qa/spec/support/waiter_spec.rb
View file @ 05f9a5e7
# frozen_string_literal: true
RSpec.describe QA::Support::Waiter do
before do
logger = ::Logger.new $stdout
logger.level = ::Logger::DEBUG
QA::Runtime::Logger.logger = logger
end
describe '.wait_until' do
context 'when the condition is true' do
it 'logs the start' do
expect { subject.wait_until(max_duration: 0, raise_on_failure: false) { true } }
.to output(/with wait_until: max_duration: 0; reload_page: ; sleep_interval: 0.1/).to_stdout_from_any_process
end
it 'logs the end' do
expect { subject.wait_until(max_duration: 0, raise_on_failure: false) { true } }
.to output(/ended wait_until$/).to_stdout_from_any_process
end
end
context 'when the condition is false' do
it 'logs the start' do
expect { subject.wait_until(max_duration: 0, raise_on_failure: false) { false } }
.to output(/with wait_until: max_duration: 0; reload_page: ; sleep_interval: 0.1/).to_stdout_from_any_process
end
it 'logs the end' do
expect { subject.wait_until(max_duration: 0, raise_on_failure: false) { false } }
.to output(/ended wait_until$/).to_stdout_from_any_process
end
end
it 'allows logs to be silenced' do
expect { subject.wait_until(max_duration: 0, raise_on_failure: false, log: false) { false } }
.not_to output.to_stdout_from_any_process
expect(subject).to receive(:repeat_until).with(hash_including(log: false))
subject.wait_until(log: false)
end
it 'sets max_duration to 60 by default' 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
GitLab Nexedi Edition | About GitLab | About Nexedi | 沪ICP备2021021310号-2 | 沪ICP备2021021310号-7