From 14b88788cca4c4cc6508235ed16a426704524478 Mon Sep 17 00:00:00 2001 From: Guillaume Malette Date: Thu, 2 Apr 2026 15:18:57 -0400 Subject: [PATCH] Fix OrderReporter producing empty test_order.log in parallel DRb mode ## Situation OrderReporter writes test identifiers in its before_test method, but in Rails parallel DRb mode (forked processes), before_test is never called. The parallelization server only calls prerecord and record on the parent process's reporters. Since tests execute in forked workers via Minitest.run_one_method (which bypasses reporters entirely), the test_order.log file is truncated on start and never written to. This makes it impossible to bisect order-dependent flaky test failures because the test order is never recorded. ## Execution Instead of relying on the reporter API (which lacks worker identity in DRb mode), prepend a TestOrderTracking module onto Minitest::Test that hooks into before_setup. This fires inside the forked worker process during run_one_method, where Process.pid correctly identifies the worker. Each forked worker writes to its own file (test_order.worker-{pid}.log) with sync writes enabled (workers never call report, so buffered writes risk data loss on crash). The parent process's main test_order.log is used in non-parallel mode where the parent is the test process. On start, stale worker files from previous runs are cleaned up. --- ruby/lib/minitest/queue/order_reporter.rb | 86 ++++++++++++++----- .../minitest/queue/order_reporter_test.rb | 79 ++++++++++++----- 2 files changed, 124 insertions(+), 41 deletions(-) diff --git a/ruby/lib/minitest/queue/order_reporter.rb b/ruby/lib/minitest/queue/order_reporter.rb index eb1f0d71..e95b4a42 100644 --- a/ruby/lib/minitest/queue/order_reporter.rb +++ b/ruby/lib/minitest/queue/order_reporter.rb @@ -2,38 +2,82 @@ require 'minitest/reporters' class Minitest::Queue::OrderReporter < Minitest::Reporters::BaseReporter + # Hook prepended onto Minitest::Test to capture test order from within the + # test process. In DRb parallel mode, reporters only receive prerecord/record + # in the parent, but before_setup runs inside the forked worker where we can + # identify the process and write to a per-worker file. + # + # All file management lives here (class-level) so forked workers are + # self-contained and don't depend on a reporter instance crossing the fork. + module TestOrderTracking + def before_setup + TestOrderTracking.record(self.class.name, self.name) + super + end + + @mutex = Mutex.new + @files = {} + @dir = nil + @basename = nil + @ext = nil + + class << self + def configure(dir:, basename:, ext:) + @dir = dir + @basename = basename + @ext = ext + end + + def reset + @dir = nil + @files.each_value do |f| + f.flush + f.close + end + @files.clear + end + + def record(klass_name, test_name) + return unless @dir + + file.puts("#{klass_name}##{test_name}") + end + + private + + def file + pid = Process.pid + @mutex.synchronize do + @files[pid] ||= File.open( + File.join(@dir, "#{@basename}.worker-#{pid}#{@ext}"), + 'a+', + ).tap { |f| f.sync = true } + end + end + end + end + def initialize(options = {}) @path = options.delete(:path) - @file = nil - @flush_every = Integer(ENV.fetch('CI_QUEUE_ORDER_FLUSH_EVERY', '50')) - @flush_every = 1 if @flush_every < 1 - @pending = 0 + @dir = File.dirname(@path) + @basename = File.basename(@path, File.extname(@path)) + @ext = File.extname(@path) super end def start super - file.truncate(0) - end + TestOrderTracking.configure(dir: @dir, basename: @basename, ext: @ext) - def before_test(test) - super - file.puts("#{test.class.name}##{test.name}") - @pending += 1 - if @pending >= @flush_every - file.flush - @pending = 0 + # Clean stale worker files from previous runs + Dir.glob(File.join(@dir, "#{@basename}.worker-*#{@ext}")).each do |f| + File.delete(f) end end def report - file.flush - file.close - end - - private - - def file - @file ||= File.open(@path, 'a+') + TestOrderTracking.reset end end + +Minitest::Test.prepend(Minitest::Queue::OrderReporter::TestOrderTracking) diff --git a/ruby/test/minitest/queue/order_reporter_test.rb b/ruby/test/minitest/queue/order_reporter_test.rb index 3ba2952d..225ddf41 100644 --- a/ruby/test/minitest/queue/order_reporter_test.rb +++ b/ruby/test/minitest/queue/order_reporter_test.rb @@ -9,47 +9,86 @@ def setup @reporter = OrderReporter.new(path: log_path) end - def test_start + def teardown + OrderReporter::TestOrderTracking.reset + cleanup_worker_files + end + + def test_start_cleans_stale_worker_files + stale_path = worker_path(99999) + File.write(stale_path, "stale\n") + + @reporter.start + @reporter.report + + refute File.exist?(stale_path), "Stale worker file should be cleaned up" + end + + def test_records_test_order_via_hook @reporter.start + test_instance = Minitest::Test.new('a') + test_instance.before_setup @reporter.report - assert_equal [], File.readlines(log_path).map(&:chomp) + + assert_equal ['Minitest::Test#a'], File.readlines(worker_path(Process.pid)).map(&:chomp) end - def test_before_test + def test_records_multiple_tests @reporter.start - @reporter.before_test(runnable('a')) - @reporter.before_test(runnable('b')) + Minitest::Test.new('a').before_setup + Minitest::Test.new('b').before_setup @reporter.report - assert_equal ['Minitest::Test#a', 'Minitest::Test#b'], File.readlines(log_path).map(&:chomp) + + assert_equal ['Minitest::Test#a', 'Minitest::Test#b'], File.readlines(worker_path(Process.pid)).map(&:chomp) + end + + def test_noop_when_not_started + # before_setup should not fail or write when no reporter is active + OrderReporter::TestOrderTracking.reset + Minitest::Test.new('a').before_setup + + assert_empty Dir.glob(File.join(log_dir, "test_order.worker-*.log")) end unless truffleruby? - def test_forking - pid = fork do - @reporter.start - end - pids = 5.times.map do + def test_forked_workers_write_per_pid_files + @reporter.start + + pids = 3.times.map do fork do - @reporter.before_test(runnable(Process.pid)) - @reporter.report + Minitest::Test.new("test_#{Process.pid}").before_setup end end - (pids + [pid]).map do |pid| - Process.waitpid(pid) - end + pids.each { |pid| Process.waitpid(pid) } + + @reporter.report - assert_equal pids.map { |pid| "Minitest::Test##{pid}" }.sort, File.readlines(log_path).map(&:chomp).sort + pids.each do |pid| + path = worker_path(pid) + assert File.exist?(path), "Expected #{path} to exist" + assert_equal ["Minitest::Test#test_#{pid}"], File.readlines(path).map(&:chomp) + end end end private - def delete_log - File.delete(log_path) if File.exists?(log_path) + def log_dir + @log_dir ||= Dir.tmpdir end def log_path - @path ||= File.join(Dir.tmpdir, 'test_order.log') + @log_path ||= File.join(log_dir, 'test_order.log') + end + + def worker_path(pid) + File.join(log_dir, "test_order.worker-#{pid}.log") + end + + def cleanup_worker_files + Dir.glob(File.join(log_dir, "test_order.worker-*.log")).each do |f| + File.delete(f) + end end end end