diff --git a/ruby/lib/ci/queue/redis/build_record.rb b/ruby/lib/ci/queue/redis/build_record.rb index cb45a755..ffe612df 100644 --- a/ruby/lib/ci/queue/redis/build_record.rb +++ b/ruby/lib/ci/queue/redis/build_record.rb @@ -57,22 +57,32 @@ def record_warning(type, attributes) end def record_error(id, payload, stats: nil) - acknowledged, _ = redis.pipelined do |pipeline| - @queue.acknowledge(id, error: payload, pipeline: pipeline) - record_stats(stats, pipeline: pipeline) + acknowledged = @queue.acknowledge(id, error: payload) + + if acknowledged + # if another worker already acknowledged the test, we don't need to update the global stats or increment the test failed count + record_stats(stats) + @queue.increment_test_failed + else + record_stats({"ignored" => 1}) end - - @queue.increment_test_failed if acknowledged == 1 nil end def record_success(id, stats: nil, skip_flaky_record: false) - _, error_reports_deleted_count, requeued_count, _ = redis.multi do |transaction| + acknowledged, error_reports_deleted_count, requeued_count, _ = redis.multi do |transaction| @queue.acknowledge(id, pipeline: transaction) transaction.hdel(key('error-reports'), id) transaction.hget(key('requeues-count'), id) - record_stats(stats, pipeline: transaction) end + + # if another worker already acknowledged the test, we don't need to update the global stats or increment the test failed count + if acknowledged + record_stats(stats) + else + record_stats({"ignored" => 1}) + end + record_flaky(id) if !skip_flaky_record && (error_reports_deleted_count.to_i > 0 || requeued_count.to_i > 0) nil end diff --git a/ruby/lib/minitest/queue/build_status_recorder.rb b/ruby/lib/minitest/queue/build_status_recorder.rb index bf50b1f5..4462a194 100644 --- a/ruby/lib/minitest/queue/build_status_recorder.rb +++ b/ruby/lib/minitest/queue/build_status_recorder.rb @@ -10,6 +10,7 @@ class BuildStatusRecorder < Minitest::Reporters::BaseReporter failures skips requeues + ignored total_time ).freeze @@ -18,7 +19,7 @@ class << self end self.failure_formatter = FailureFormatter - attr_accessor :requeues + attr_accessor :requeues, :ignored def initialize(build:, **options) super(options) @@ -28,6 +29,7 @@ def initialize(build:, **options) self.errors = 0 self.skips = 0 self.requeues = 0 + self.ignored = 0 end def report diff --git a/ruby/lib/minitest/queue/build_status_reporter.rb b/ruby/lib/minitest/queue/build_status_reporter.rb index 43b5c3f7..5cc9bd7f 100644 --- a/ruby/lib/minitest/queue/build_status_reporter.rb +++ b/ruby/lib/minitest/queue/build_status_reporter.rb @@ -201,6 +201,10 @@ def requeues fetch_summary['requeues'].to_i end + def ignored + fetch_summary['ignored'].to_i + end + def total_time fetch_summary['total_time'].to_f end @@ -273,7 +277,7 @@ def aggregates step([ 'Ran %d tests, %d assertions,' % [progress, assertions], success ? green(failures_count) : red(failures_count), - yellow("#{skips} skips, #{requeues} requeues"), + yellow("#{skips} skips, #{requeues} requeues, #{ignored} ignored"), 'in %.2fs (aggregated)' % total_time, ].join(' '), collapsed: success) end diff --git a/ruby/lib/minitest/queue/local_requeue_reporter.rb b/ruby/lib/minitest/queue/local_requeue_reporter.rb index ea8b5add..e6d93033 100644 --- a/ruby/lib/minitest/queue/local_requeue_reporter.rb +++ b/ruby/lib/minitest/queue/local_requeue_reporter.rb @@ -6,15 +6,17 @@ module Minitest module Queue class LocalRequeueReporter < Minitest::Reporters::DefaultReporter include ::CI::Queue::OutputHelpers - attr_accessor :requeues + attr_accessor :requeues, :ignored def initialize(*) self.requeues = 0 + self.ignored = 0 super end def report self.requeues = results.count(&:requeued?) + self.ignored = 0 super print_report end @@ -28,7 +30,7 @@ def print_report step [ 'Ran %d tests, %d assertions,' % [count, assertions], success ? green(failures_count) : red(failures_count), - yellow("#{skips} skips, #{requeues} requeues"), + yellow("#{skips} skips, #{requeues} requeues, #{ignored} ignored"), 'in %.2fs' % total_time, ].join(' ') end diff --git a/ruby/test/integration/minitest_redis_test.rb b/ruby/test/integration/minitest_redis_test.rb index dbb74d9f..db6989ad 100644 --- a/ruby/test/integration/minitest_redis_test.rb +++ b/ruby/test/integration/minitest_redis_test.rb @@ -45,7 +45,7 @@ def test_default_reporter assert_empty err assert_match(/Expected false to be truthy/, normalize(out)) # failure output result = normalize(out.lines.last.strip) - assert_equal '--- Ran 11 tests, 8 assertions, 2 failures, 1 errors, 1 skips, 4 requeues in X.XXs', result + assert_equal '--- Ran 11 tests, 8 assertions, 2 failures, 1 errors, 1 skips, 4 requeues, 0 ignored in X.XXs', result end def test_lost_test_with_heartbeat_monitor @@ -88,7 +88,7 @@ def test_lost_test_with_heartbeat_monitor assert_empty err result = normalize(out.lines[1].strip) - assert_equal "Ran 1 tests, 0 assertions, 0 failures, 0 errors, 0 skips, 0 requeues in X.XXs (aggregated)", result + assert_equal "Ran 1 tests, 0 assertions, 0 failures, 0 errors, 0 skips, 0 requeues, 1 ignored in X.XXs (aggregated)", result warnings = JSON.parse(warnings_file.read) assert_equal 1, warnings.size end @@ -116,7 +116,7 @@ def test_verbose_reporter assert_empty err assert_match(/ATest#test_foo \d+\.\d+ = S/, normalize(out)) # verbose test ouptut result = normalize(out.lines.last.strip) - assert_equal '--- Ran 11 tests, 8 assertions, 2 failures, 1 errors, 1 skips, 4 requeues in X.XXs', result + assert_equal '--- Ran 11 tests, 8 assertions, 2 failures, 1 errors, 1 skips, 4 requeues, 0 ignored in X.XXs', result end def test_debug_log @@ -142,7 +142,7 @@ def test_debug_log assert_includes File.read(log_file.path), 'INFO -- : Finished \'["exists", "b:c4ca4238:w:1:q"]\': 0' assert_empty err result = normalize(out.lines.last.strip) - assert_equal '--- Ran 11 tests, 8 assertions, 2 failures, 1 errors, 1 skips, 4 requeues in X.XXs', result + assert_equal '--- Ran 11 tests, 8 assertions, 2 failures, 1 errors, 1 skips, 4 requeues, 0 ignored in X.XXs', result end end @@ -167,7 +167,7 @@ def test_buildkite_output assert_empty err assert_match(/^\^{3} \+{3}$/m, normalize(out)) # reopen failed step 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 + assert_equal '--- Ran 11 tests, 8 assertions, 2 failures, 1 errors, 1 skips, 4 requeues, 0 ignored in X.XXs', output end def test_custom_requeue @@ -190,7 +190,7 @@ def test_custom_requeue assert_empty err output = normalize(out.lines.last.strip) - assert_equal '--- Ran 3 tests, 0 assertions, 0 failures, 2 errors, 0 skips, 1 requeues in X.XXs', output + assert_equal '--- Ran 3 tests, 0 assertions, 0 failures, 2 errors, 0 skips, 1 requeues, 0 ignored in X.XXs', output end def test_max_test_failed @@ -216,7 +216,7 @@ def test_max_test_failed assert_equal 1, $?.exitstatus assert_equal 'This worker is exiting early because too many failed tests were encountered.', err.chomp output = normalize(out.lines.last.strip) - assert_equal 'Ran 47 tests, 47 assertions, 3 failures, 0 errors, 0 skips, 44 requeues in X.XXs', output + assert_equal 'Ran 47 tests, 47 assertions, 3 failures, 0 errors, 0 skips, 44 requeues, 0 ignored in X.XXs', output # Run the reporter out, err = capture_subprocess_io do @@ -240,7 +240,7 @@ def test_max_test_failed EXPECTED assert_equal expected.strip, normalize(out.lines[0..1].join.strip) expected = <<~EXPECTED - Ran 3 tests, 47 assertions, 3 failures, 0 errors, 0 skips, 44 requeues in X.XXs (aggregated) + Ran 3 tests, 47 assertions, 3 failures, 0 errors, 0 skips, 44 requeues, 0 ignored in X.XXs (aggregated) EXPECTED assert_equal expected.strip, normalize(out.lines[134].strip) expected = <<~EXPECTED @@ -297,7 +297,7 @@ def test_circuit_breaker assert_equal "This worker is exiting early because it encountered too many consecutive test failures, probably because of some corrupted state.\n", err output = normalize(out.lines.last.strip) - assert_equal 'Ran 3 tests, 3 assertions, 0 failures, 0 errors, 0 skips, 3 requeues in X.XXs', output + assert_equal 'Ran 3 tests, 3 assertions, 0 failures, 0 errors, 0 skips, 3 requeues, 0 ignored in X.XXs', output end def test_redis_runner @@ -319,7 +319,7 @@ def test_redis_runner assert_empty err 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 + assert_equal 'Ran 11 tests, 8 assertions, 2 failures, 1 errors, 1 skips, 4 requeues, 0 ignored in X.XXs', output out, err = capture_subprocess_io do system( @@ -339,7 +339,7 @@ def test_redis_runner assert_empty err output = normalize(out.lines.last.strip) - assert_equal 'Ran 6 tests, 4 assertions, 2 failures, 1 errors, 0 skips, 3 requeues in X.XXs', output + assert_equal 'Ran 6 tests, 4 assertions, 2 failures, 1 errors, 0 skips, 3 requeues, 0 ignored in X.XXs', output end def test_retry_success @@ -360,7 +360,7 @@ def test_retry_success end assert_empty err output = normalize(out.lines.last.strip) - assert_equal 'Ran 100 tests, 100 assertions, 0 failures, 0 errors, 0 skips, 0 requeues in X.XXs', output + assert_equal 'Ran 100 tests, 100 assertions, 0 failures, 0 errors, 0 skips, 0 requeues, 0 ignored in X.XXs', output out, err = capture_subprocess_io do system( @@ -400,7 +400,7 @@ def test_automatic_retry end assert_empty err output = normalize(out.lines.last.strip) - assert_equal 'Ran 200 tests, 200 assertions, 100 failures, 0 errors, 0 skips, 100 requeues in X.XXs', output + assert_equal 'Ran 200 tests, 200 assertions, 100 failures, 0 errors, 0 skips, 100 requeues, 0 ignored in X.XXs', output out, err = capture_subprocess_io do system( @@ -441,7 +441,7 @@ def test_retry_fails_when_test_run_is_expired end assert_empty err output = normalize(out.lines.last.strip) - assert_equal 'Ran 100 tests, 100 assertions, 0 failures, 0 errors, 0 skips, 0 requeues in X.XXs', output + assert_equal 'Ran 100 tests, 100 assertions, 0 failures, 0 errors, 0 skips, 0 requeues, 0 ignored in X.XXs', output one_day = 60 * 60 * 24 key = CI::Queue::Redis::KeyShortener.key("1", "created-at") @@ -484,7 +484,7 @@ def test_retry_report end assert_empty err output = normalize(out.lines.last.strip) - assert_equal 'Ran 100 tests, 100 assertions, 100 failures, 0 errors, 0 skips, 0 requeues in X.XXs', output + assert_equal 'Ran 100 tests, 100 assertions, 100 failures, 0 errors, 0 skips, 0 requeues, 0 ignored in X.XXs', output # Run the reporter out, err = capture_subprocess_io do @@ -498,7 +498,7 @@ def test_retry_report ) end assert_empty err - expect = 'Ran 100 tests, 100 assertions, 100 failures, 0 errors, 0 skips, 0 requeues in X.XXs (aggregated)' + expect = 'Ran 100 tests, 100 assertions, 100 failures, 0 errors, 0 skips, 0 requeues, 0 ignored in X.XXs (aggregated)' assert_equal expect, normalize(out.strip.lines[1].strip) # Simulate another worker successfuly retrying all errors (very hard to reproduce properly) @@ -519,6 +519,7 @@ def test_retry_report 'failures' => 0, 'skips' => 0, 'requeues' => 0, + 'ignored' => 0, 'total_time' => index + 1, }) end @@ -553,7 +554,7 @@ def test_retry_report ) end assert_empty err - expect = 'Ran 100 tests, 100 assertions, 0 failures, 0 errors, 0 skips, 0 requeues in X.XXs (aggregated)' + expect = 'Ran 100 tests, 0 assertions, 0 failures, 0 errors, 0 skips, 0 requeues, 1 ignored in X.XXs (aggregated)' assert_equal expect, normalize(out.strip.lines[1].strip) end @@ -576,7 +577,7 @@ def test_down_redis end assert_empty err output = normalize(out.lines.last.strip) - assert_equal 'Ran 0 tests, 0 assertions, 0 failures, 0 errors, 0 skips, 0 requeues in X.XXs', output + assert_equal 'Ran 0 tests, 0 assertions, 0 failures, 0 errors, 0 skips, 0 requeues, 0 ignored in X.XXs', output end def test_test_data_reporter @@ -599,7 +600,7 @@ def test_test_data_reporter end assert_empty err output = normalize(out.lines.last.strip) - assert_equal 'Ran 9 tests, 6 assertions, 1 failures, 1 errors, 1 skips, 2 requeues in X.XXs', output + assert_equal 'Ran 9 tests, 6 assertions, 1 failures, 1 errors, 1 skips, 2 requeues, 0 ignored in X.XXs', output content = File.read(@test_data_path) failures = JSON.parse(content, symbolize_names: true) @@ -701,7 +702,7 @@ def test_junit_reporter end assert_empty err output = normalize(out.lines.last.strip) - assert_equal 'Ran 9 tests, 6 assertions, 1 failures, 1 errors, 1 skips, 2 requeues in X.XXs', output + assert_equal 'Ran 9 tests, 6 assertions, 1 failures, 1 errors, 1 skips, 2 requeues, 0 ignored in X.XXs', output # NOTE: To filter the TypeError backtrace below see test/fixtures/test/backtrace_filters.rb @@ -912,7 +913,7 @@ def test_redis_reporter end assert_empty err 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 + assert_equal 'Ran 11 tests, 8 assertions, 2 failures, 1 errors, 1 skips, 4 requeues, 0 ignored in X.XXs', output Tempfile.open('warnings') do |warnings_file| out, err = capture_subprocess_io do @@ -951,7 +952,7 @@ def test_redis_reporter REQUEUE BTest#test_bar (requeued 1 times) - Ran 7 tests, 8 assertions, 2 failures, 1 errors, 1 skips, 4 requeues in X.XXs (aggregated) + Ran 7 tests, 8 assertions, 2 failures, 1 errors, 1 skips, 4 requeues, 0 ignored in X.XXs (aggregated) @@ -1012,7 +1013,7 @@ def test_utf8_tests_and_marshal assert_empty err output = normalize(out.lines.last) assert_equal <<~END, output - Ran 1 tests, 1 assertions, 1 failures, 0 errors, 0 skips, 0 requeues in X.XXs + Ran 1 tests, 1 assertions, 1 failures, 0 errors, 0 skips, 0 requeues, 0 ignored in X.XXs END end diff --git a/ruby/test/minitest/queue/build_status_recorder_test.rb b/ruby/test/minitest/queue/build_status_recorder_test.rb index c78833a8..e5de8034 100644 --- a/ruby/test/minitest/queue/build_status_recorder_test.rb +++ b/ruby/test/minitest/queue/build_status_recorder_test.rb @@ -40,11 +40,12 @@ def test_aggregation reserve(second_queue, "h") second_reporter.record(result('h', skipped: true, requeued: true)) - assert_equal 9, summary.assertions + assert_equal 8, summary.assertions assert_equal 3, summary.failures assert_equal 3, summary.errors - assert_equal 2, summary.skips + assert_equal 1, summary.skips assert_equal 1, summary.requeues + assert_equal 1, summary.ignored assert_equal 5, summary.error_reports.size assert_equal 0, summary.flaky_reports.size end @@ -105,6 +106,7 @@ def test_retrying_test_reverse second_reporter.record(result("a", failure: "Something went wrong")) assert_equal 0, summary.error_reports.size assert_equal 0, @queue.test_failed + assert_equal 1, summary.ignored end def test_static_queue_record_success