Implement Rails::TestUnitReporter#prerecord

This is invoked by Minitest before invoking the test, allowing
to print the test name in advance.

This is useful to debug slow and stuck tests by turning on verbose
mode. This way the stuck test name is printed before the process
deadlock.

Otherwise you have to resort to dirty tricks to figure out which
test is not returning.

This is also how the default Minitest reporter works in verbose
mode.

Author: byroot

railties/lib/rails/test_unit/reporter.rb

@@ -8,6 +8,13 @@ class TestUnitReporter < Minitest::StatisticsReporter
     class_attribute :app_root
     class_attribute :executable, default: "bin/rails test"
 
+    def prerecord(test_class, test_name)
+      super
+      if options[:verbose]
+        io.print "%s#%s = " % [test_class.name, test_name]
+      end
+    end
+
     def record(result)
       super
 
@@ -69,8 +76,7 @@ def fail_fast?
       end
 
       def format_line(result)
-        klass = result.respond_to?(:klass) ? result.klass : result.class
-        "%s#%s = %.2f s = %s" % [klass, result.name, result.time, result.result_code]
+        "%.2f s = %s" % [result.time, result.result_code]
       end
 
       def format_rerun_snippet(result)

railties/test/test_unit/reporter_test.rb

@@ -15,34 +15,34 @@ def woot; end
   end
 
   test "prints rerun snippet to run a single failed test" do
-    @reporter.record(failed_test)
+    record(failed_test)
     @reporter.report
 
     assert_match %r{^bin/rails test .*test/test_unit/reporter_test\.rb:\d+$}, @output.string
     assert_rerun_snippet_count 1
   end
 
   test "prints rerun snippet for every failed test" do
-    @reporter.record(failed_test)
-    @reporter.record(failed_test)
-    @reporter.record(failed_test)
+    record(failed_test)
+    record(failed_test)
+    record(failed_test)
     @reporter.report
 
     assert_rerun_snippet_count 3
   end
 
   test "does not print snippet for successful and skipped tests" do
-    @reporter.record(passing_test)
-    @reporter.record(skipped_test)
+    record(passing_test)
+    record(skipped_test)
     @reporter.report
     assert_no_match "Failed tests:", @output.string
     assert_rerun_snippet_count 0
   end
 
   test "prints rerun snippet for skipped tests if run in verbose mode" do
-    verbose = Rails::TestUnitReporter.new @output, verbose: true
-    verbose.record(skipped_test)
-    verbose.report
+    @reporter = Rails::TestUnitReporter.new @output, verbose: true
+    record(skipped_test)
+    @reporter.report
 
     assert_rerun_snippet_count 1
   end
@@ -51,7 +51,7 @@ def woot; end
     original_executable = Rails::TestUnitReporter.executable
     begin
       Rails::TestUnitReporter.executable = "bin/test"
-      @reporter.record(failed_test)
+      record(failed_test)
       @reporter.report
 
       assert_match %r{^bin/test .*test/test_unit/reporter_test\.rb:\d+$}, @output.string
@@ -61,44 +61,44 @@ def woot; end
   end
 
   test "outputs failures inline" do
-    @reporter.record(failed_test)
+    record(failed_test)
     @reporter.report
 
     expect = %r{\AF\n\nFailure:\nTestUnitReporterTest::ExampleTest#woot \[[^\]]+\]:\nboo\n\nbin/rails test test/test_unit/reporter_test\.rb:\d+\n\n\z}
     assert_match expect, @output.string
   end
 
   test "outputs errors inline" do
-    @reporter.record(errored_test)
+    record(errored_test)
     @reporter.report
 
     expect = %r{\AE\n\nError:\nTestUnitReporterTest::ExampleTest#woot:\nArgumentError: wups\n    some_test.rb:4\n\nbin/rails test .*test/test_unit/reporter_test\.rb:\d+\n\n\z}
     assert_match expect, @output.string
   end
 
   test "outputs skipped tests inline if verbose" do
-    verbose = Rails::TestUnitReporter.new @output, verbose: true, output_inline: true
-    verbose.record(skipped_test)
-    verbose.report
+    @reporter = Rails::TestUnitReporter.new @output, verbose: true, output_inline: true
+    record(skipped_test)
+    @reporter.report
 
     expect = %r{\ATestUnitReporterTest::ExampleTest#woot = 10\.00 s = S\n\n\nSkipped:\nTestUnitReporterTest::ExampleTest#woot \[[^\]]+\]:\nskipchurches, misstemples\n\nbin/rails test test/test_unit/reporter_test\.rb:\d+\n\n\z}
     assert_match expect, @output.string
   end
 
   test "does not output rerun snippets after run" do
-    @reporter.record(failed_test)
+    record(failed_test)
     @reporter.report
 
     assert_no_match "Failed tests:", @output.string
   end
 
   test "fail fast interrupts run on failure" do
-    fail_fast = Rails::TestUnitReporter.new @output, fail_fast: true
+    @reporter = Rails::TestUnitReporter.new @output, fail_fast: true
     interrupt_raised = false
 
     # Minitest passes through Interrupt, catch it manually.
     begin
-      fail_fast.record(failed_test)
+      record(failed_test)
     rescue Interrupt
       interrupt_raised = true
     ensure
@@ -107,12 +107,12 @@ def woot; end
   end
 
   test "fail fast interrupts run on error" do
-    fail_fast = Rails::TestUnitReporter.new @output, fail_fast: true
+    @reporter = Rails::TestUnitReporter.new @output, fail_fast: true
     interrupt_raised = false
 
     # Minitest passes through Interrupt, catch it manually.
     begin
-      fail_fast.record(errored_test)
+      record(errored_test)
     rescue Interrupt
       interrupt_raised = true
     ensure
@@ -121,16 +121,16 @@ def woot; end
   end
 
   test "fail fast does not interrupt run skips" do
-    fail_fast = Rails::TestUnitReporter.new @output, fail_fast: true
+    @reporter = Rails::TestUnitReporter.new @output, fail_fast: true
 
-    fail_fast.record(skipped_test)
+    record(skipped_test)
     assert_no_match "Failed tests:", @output.string
   end
 
   test "outputs colored passing results" do
     @output.stub(:tty?, true) do
-      colored = Rails::TestUnitReporter.new @output, color: true, output_inline: true
-      colored.record(passing_test)
+      @reporter = Rails::TestUnitReporter.new @output, color: true, output_inline: true
+      record(passing_test)
 
       expect = %r{\e\[32m\.\e\[0m}
       assert_match expect, @output.string
@@ -139,8 +139,8 @@ def woot; end
 
   test "outputs colored skipped results" do
     @output.stub(:tty?, true) do
-      colored = Rails::TestUnitReporter.new @output, color: true, output_inline: true
-      colored.record(skipped_test)
+      @reporter = Rails::TestUnitReporter.new @output, color: true, output_inline: true
+      record(skipped_test)
 
       expect = %r{\e\[33mS\e\[0m}
       assert_match expect, @output.string
@@ -149,8 +149,8 @@ def woot; end
 
   test "outputs colored failed results" do
     @output.stub(:tty?, true) do
-      colored = Rails::TestUnitReporter.new @output, color: true, output_inline: true
-      colored.record(failed_test)
+      @reporter = Rails::TestUnitReporter.new @output, color: true, output_inline: true
+      record(failed_test)
 
       expected = %r{\e\[31mF\e\[0m\n\n\e\[31mFailure:\nTestUnitReporterTest::ExampleTest#woot \[test/test_unit/reporter_test.rb:\d+\]:\nboo\n\e\[0m\n\nbin/rails test .*test/test_unit/reporter_test.rb:\d+\n\n}
       assert_match expected, @output.string
@@ -159,15 +159,20 @@ def woot; end
 
   test "outputs colored error results" do
     @output.stub(:tty?, true) do
-      colored = Rails::TestUnitReporter.new @output, color: true, output_inline: true
-      colored.record(errored_test)
+      @reporter = Rails::TestUnitReporter.new @output, color: true, output_inline: true
+      record(errored_test)
 
       expected = %r{\e\[31mE\e\[0m\n\n\e\[31mError:\nTestUnitReporterTest::ExampleTest#woot:\nArgumentError: wups\n    some_test.rb:4\n\e\[0m}
       assert_match expected, @output.string
     end
   end
 
   private
+    def record(test_result)
+      @reporter.prerecord(test_result.klass.constantize, test_result.name)
+      @reporter.record(test_result)
+    end
+
     def assert_rerun_snippet_count(snippet_count)
       assert_equal snippet_count, @output.string.scan(%r{^bin/rails test }).size
     end