Skip to content

Commit

Permalink
Write warnings to file instead of STDOUT
Browse files Browse the repository at this point in the history
  • Loading branch information
ChrisBr committed Dec 21, 2023
1 parent 2fe3034 commit 4e22386
Show file tree
Hide file tree
Showing 4 changed files with 71 additions and 37 deletions.
5 changes: 3 additions & 2 deletions ruby/lib/ci/queue/configuration.rb
Original file line number Diff line number Diff line change
Expand Up @@ -5,7 +5,7 @@ class Configuration
attr_accessor :timeout, :worker_id, :max_requeues, :grind_count, :failure_file, :export_flaky_tests_file
attr_accessor :requeue_tolerance, :namespace, :failing_test, :statsd_endpoint
attr_accessor :max_test_duration, :max_test_duration_percentile, :track_test_duration
attr_accessor :max_test_failed, :redis_ttl
attr_accessor :max_test_failed, :redis_ttl, :warnings_file
attr_reader :circuit_breakers
attr_writer :seed, :build_id
attr_writer :queue_init_timeout, :report_timeout, :inactive_workers_timeout
Expand Down Expand Up @@ -36,7 +36,7 @@ def initialize(
grind_count: nil, max_duration: nil, failure_file: nil, max_test_duration: nil,
max_test_duration_percentile: 0.5, track_test_duration: false, max_test_failed: nil,
queue_init_timeout: nil, redis_ttl: 8 * 60 * 60, report_timeout: nil, inactive_workers_timeout: nil,
export_flaky_tests_file: nil
export_flaky_tests_file: nil, warnings_file: nil
)
@build_id = build_id
@circuit_breakers = [CircuitBreaker::Disabled]
Expand All @@ -61,6 +61,7 @@ def initialize(
@report_timeout = report_timeout
@inactive_workers_timeout = inactive_workers_timeout
@export_flaky_tests_file = export_flaky_tests_file
@warnings_file = warnings_file
end

def queue_init_timeout
Expand Down
3 changes: 2 additions & 1 deletion ruby/lib/ci/queue/redis/build_record.rb
Original file line number Diff line number Diff line change
Expand Up @@ -21,8 +21,9 @@ def failed_tests
redis.hkeys(key('error-reports'))
end

TOTAL_KEY = "___total___"
def requeued_tests
redis.hgetall(key('requeues-count'))
redis.hgetall(key('requeues-count')).except(TOTAL_KEY)
end

def pop_warnings
Expand Down
25 changes: 17 additions & 8 deletions ruby/lib/minitest/queue/runner.rb
Original file line number Diff line number Diff line change
Expand Up @@ -298,17 +298,17 @@ def require_worker_id!
end

def display_warnings(build)
build.pop_warnings.each do |type, attributes|
return unless queue_config.warnings_file

warnings = build.pop_warnings.map do |type, attributes|
case type
when CI::Queue::Warnings::RESERVED_LOST_TEST
puts reopen_previous_step
puts yellow(
"[WARNING] #{attributes[:test]} was picked up by another worker because it didn't complete in the allocated #{attributes[:timeout]} seconds.\n" \
"You may want to either optimize this test or bump ci-queue timeout.\n" \
"It's also possible that the worker that was processing it was terminated without being able to report back.\n"
)
"[WARNING] #{attributes[:test]} was picked up by another worker because it didn't complete in the allocated #{attributes[:timeout]} seconds.\n" \
"You may want to either optimize this test or bump ci-queue timeout.\n" \
"It's also possible that the worker that was processing it was terminated without being able to report back.\n"
end
end
end.compact
File.write(queue_config.warnings_file, warnings.join("\n"))
end

def run_tests_in_fork(queue)
Expand Down Expand Up @@ -528,6 +528,15 @@ def parser
queue_config.export_flaky_tests_file = file
end

help = <<~EOS
Defines a file where warnings during the execution are written to.
Defaults to disabled.
EOS
opts.separator ""
opts.on('--warnings-file FILE', help) do |file|
queue_config.warnings_file = file
end

help = <<~EOS
Defines after how many consecutive failures the worker will be considered unhealthy and terminate itself.
Defaults to disabled.
Expand Down
75 changes: 49 additions & 26 deletions ruby/test/integration/minitest_redis_test.rb
Original file line number Diff line number Diff line change
Expand Up @@ -731,37 +731,60 @@ def test_redis_reporter
output = normalize(out.lines.last.strip)
assert_equal 'Ran 11 tests, 8 assertions, 2 failures, 1 errors, 1 skips, 4 requeues in X.XXs', output

out, err = capture_subprocess_io do
system(
@exe, 'report',
'--queue', @redis_url,
'--build', '1',
'--timeout', '1',
chdir: 'test/fixtures/',
)
end
assert_empty err
output = normalize(out)
expected_output = <<~END
Waiting for workers to complete
Tempfile.open('warnings') do |warnings_file|
out, err = capture_subprocess_io do
system(
@exe, 'report',
'--queue', @redis_url,
'--build', '1',
'--timeout', '1',
'--warnings-file', warnings_file.path,
chdir: 'test/fixtures/',
)
end

[WARNING] Atest#test_bar was picked up by another worker because it didn't complete in the allocated 2 seconds.
You may want to either optimize this test or bump ci-queue timeout.
It's also possible that the worker that was processing it was terminated without being able to report back.
warning = <<~END
[WARNING] Atest#test_bar was picked up by another worker because it didn't complete in the allocated 2 seconds.
You may want to either optimize this test or bump ci-queue timeout.
It's also possible that the worker that was processing it was terminated without being able to report back.
END

Ran 7 tests, 8 assertions, 2 failures, 1 errors, 1 skips, 4 requeues in X.XXs (aggregated)
warnings_file.rewind
assert_equal warning, warnings_file.read

FAIL ATest#test_bar
Expected false to be truthy.
test/dummy_test.rb:10:in `test_bar'
assert_empty err
output = normalize(out)
expected_output = <<~END
Waiting for workers to complete
Ran 7 tests, 8 assertions, 2 failures, 1 errors, 1 skips, 4 requeues in X.XXs (aggregated)
FAIL ATest#test_flaky_fails_retry
Expected false to be truthy.
test/dummy_test.rb:23:in `test_flaky_fails_retry'
FAIL ATest#test_bar
Expected false to be truthy.
test/dummy_test.rb:10:in `test_bar'
ERROR BTest#test_bar
END
assert_includes output, expected_output
FAIL ATest#test_flaky_fails_retry
Expected false to be truthy.
test/dummy_test.rb:23:in `test_flaky_fails_retry'
ERROR BTest#test_bar
END
assert_includes output, expected_output

expected_output = <<~END
REQUEUE
ATest#test_bar (requeued 1 times)
REQUEUE
ATest#test_flaky (requeued 1 times)
REQUEUE
ATest#test_flaky_fails_retry (requeued 1 times)
REQUEUE
BTest#test_bar (requeued 1 times)
END
assert_includes output, expected_output
end
end

def test_utf8_tests_and_marshal
Expand Down

0 comments on commit 4e22386

Please sign in to comment.