Skip to content

Only increment counts when we acknowledge #372

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Open
ChrisBr wants to merge 2 commits into
base: main
Choose a base branch
from
Open

Only increment counts when we acknowledge #372

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
928f0b2
Only increment counts when we acknowledge
ChrisBr Feb 6, 2026
9a8e1c8
Display ignore count
ChrisBr Feb 6, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
24 changes: 17 additions & 7 deletions ruby/lib/ci/queue/redis/build_record.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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)
Copy link

@thadcraft-shopify thadcraft-shopify Feb 6, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

@ChrisBr Do we still need to move the counting to after recording?

if test.requeued?
          self.requeues += 1
        elsif test.skipped?
          self.skips += 1
        elsif test.error?
          self.errors += 1
        elsif test.failure
          self.failures += 1
        end

Copy link
Contributor Author

@ChrisBr ChrisBr Feb 6, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

No because we only count on acknowledge. Counting / success requeue always is fine, errors are problematic.


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)
Copy link
Contributor Author

@ChrisBr ChrisBr Feb 6, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Only record stats on failure if this worker actually acknowledged

@queue.increment_test_failed
else
record_stats({"ignored" => 1})
Copy link
Contributor Author

@ChrisBr ChrisBr Feb 6, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't love just updating ignored but it should be fine.

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})
Copy link
Contributor Author

@ChrisBr ChrisBr Feb 6, 2026

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I don't love just updating ignored but it should be fine.

end

record_flaky(id) if !skip_flaky_record && (error_reports_deleted_count.to_i > 0 || requeued_count.to_i > 0)
nil
end
Expand Down
4 changes: 3 additions & 1 deletion ruby/lib/minitest/queue/build_status_recorder.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -10,6 +10,7 @@ class BuildStatusRecorder < Minitest::Reporters::BaseReporter
failures
skips
requeues
ignored
total_time
).freeze

Expand All @@ -18,7 +19,7 @@ class << self
end
self.failure_formatter = FailureFormatter

attr_accessor :requeues
attr_accessor :requeues, :ignored

def initialize(build:, **options)
super(options)
Expand All @@ -28,6 +29,7 @@ def initialize(build:, **options)
self.errors = 0
self.skips = 0
self.requeues = 0
self.ignored = 0
end

def report
Expand Down
6 changes: 5 additions & 1 deletion ruby/lib/minitest/queue/build_status_reporter.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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
Expand Down
6 changes: 4 additions & 2 deletions ruby/lib/minitest/queue/local_requeue_reporter.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand All @@ -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
Expand Down
47 changes: 24 additions & 23 deletions ruby/test/integration/minitest_redis_test.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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
Expand All @@ -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

Expand All @@ -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
Expand All @@ -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
Expand All @@ -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
Expand All @@ -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
Expand Down Expand Up @@ -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
Expand All @@ -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(
Expand All @@ -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
Expand All @@ -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(
Expand Down Expand Up @@ -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(
Expand Down Expand Up @@ -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")
Expand Down Expand Up @@ -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
Expand All @@ -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)
Expand All @@ -519,6 +519,7 @@ def test_retry_report
'failures' => 0,
'skips' => 0,
'requeues' => 0,
'ignored' => 0,
'total_time' => index + 1,
})
end
Expand Down Expand Up @@ -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

Expand All @@ -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
Expand All @@ -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)
Expand Down Expand Up @@ -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

Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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)
Expand Down Expand Up @@ -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

Expand Down
6 changes: 4 additions & 2 deletions ruby/test/minitest/queue/build_status_recorder_test.rb
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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
Expand Down
Loading