Merge pull request rails#54425 from zzak/ci-verbose-tests

Run tests with --profile in CI

Author: byroot

actioncable/Rakefile

@@ -15,6 +15,7 @@ Rake::TestTask.new do |t|
   t.test_files = FileList["#{__dir__}/test/**/*_test.rb"]
   t.warning = true
   t.verbose = true
+  t.options = "--profile" if ENV["CI"]
   t.ruby_opts = ["--dev"] if defined?(JRUBY_VERSION)
 end
 

actionmailbox/Rakefile

@@ -10,6 +10,7 @@ Rake::TestTask.new do |t|
   t.libs << "test"
   t.pattern = "test/**/*_test.rb"
   t.verbose = true
+  t.options = "--profile" if ENV["CI"]
 end
 
 namespace :test do

actionmailer/Rakefile

@@ -13,6 +13,7 @@ Rake::TestTask.new { |t|
   t.pattern = "test/**/*_test.rb"
   t.warning = true
   t.verbose = true
+  t.options = "--profile" if ENV["CI"]
   t.ruby_opts = ["--dev"] if defined?(JRUBY_VERSION)
 }
 

actionpack/Rakefile

@@ -16,6 +16,7 @@ Rake::TestTask.new do |t|
 
   t.warning = true
   t.verbose = true
+  t.options = "--profile" if ENV["CI"]
   t.ruby_opts = ["--dev"] if defined?(JRUBY_VERSION)
 end
 

actiontext/Rakefile

@@ -10,12 +10,14 @@ Rake::TestTask.new do |t|
   t.libs << "test"
   t.test_files = FileList["test/**/*_test.rb"].exclude("test/system/**/*", "test/dummy/**/*")
   t.verbose = true
+  t.options = "--profile" if ENV["CI"]
 end
 
 Rake::TestTask.new "test:system" do |t|
   t.libs << "test"
   t.test_files = FileList["test/system/**/*_test.rb"]
   t.verbose = true
+  t.options = "--profile" if ENV["CI"]
 end
 
 namespace :test do

actionview/Rakefile

@@ -27,6 +27,7 @@ namespace :test do
     t.test_files = FileList["test/template/**/*_test.rb"]
     t.warning = true
     t.verbose = true
+    t.options = "--profile" if ENV["CI"]
     t.ruby_opts = ["--dev"] if defined?(JRUBY_VERSION)
   end
 
@@ -37,6 +38,7 @@ namespace :test do
       t.test_files = FileList["test/activerecord/*_test.rb"]
       t.warning = true
       t.verbose = true
+      t.options = "--profile" if ENV["CI"]
       t.ruby_opts = ["--dev"] if defined?(JRUBY_VERSION)
     end
 
@@ -46,6 +48,7 @@ namespace :test do
       t.test_files = FileList["test/actionpack/**/*_test.rb"]
       t.warning = true
       t.verbose = true
+      t.options = "--profile" if ENV["CI"]
       t.ruby_opts = ["--dev"] if defined?(JRUBY_VERSION)
     end
   end

activejob/Rakefile

@@ -41,6 +41,7 @@ namespace :test do
           (x.include?("async") && adapter != "async")
       }
       t.verbose = true
+      t.options = "--profile" if ENV["CI"]
       t.warning = true
       t.ruby_opts = ["--dev"] if defined?(JRUBY_VERSION)
     end
@@ -62,6 +63,7 @@ namespace :test do
         t.libs << "test"
         t.test_files = FileList["test/integration/**/*_test.rb"]
         t.verbose = true
+        t.options = "--profile" if ENV["CI"]
         t.warning = true
         t.ruby_opts = ["--dev"] if defined?(JRUBY_VERSION)
       end

activemodel/Rakefile

@@ -11,6 +11,7 @@ Rake::TestTask.new do |t|
   t.test_files = FileList["#{__dir__}/test/cases/**/*_test.rb"]
   t.warning = true
   t.verbose = true
+  t.options = "--profile" if ENV["CI"]
   t.ruby_opts = ["--dev"] if defined?(JRUBY_VERSION)
 end
 

activerecord/Rakefile

@@ -45,6 +45,7 @@ namespace :test do
 
     t.warning = true
     t.verbose = true
+    t.options = "--profile" if ENV["CI"]
   end
 end
 
@@ -69,6 +70,7 @@ end
       t.test_files = files
       t.warning = true
       t.verbose = true
+      t.options = "--profile" if ENV["CI"]
       t.ruby_opts = ["--dev"] if defined?(JRUBY_VERSION)
     end
 
@@ -80,6 +82,7 @@ end
           t.test_files = FileList["test/activejob/*_test.rb"]
           t.warning = true
           t.verbose = true
+          t.options = "--profile" if ENV["CI"]
           t.ruby_opts = ["--dev"] if defined?(JRUBY_VERSION)
         end
       end
@@ -186,6 +189,7 @@ end
 
           t.warning = true
           t.verbose = true
+          t.options = "--profile" if ENV["CI"]
           t.ruby_opts = ["--dev"] if defined?(JRUBY_VERSION)
         end
       end

activestorage/Rakefile

@@ -11,6 +11,7 @@ Rake::TestTask.new do |t|
   t.libs << "test"
   t.test_files = FileList["test/**/*_test.rb"]
   t.verbose = true
+  t.options = "--profile" if ENV["CI"]
   t.warning = true
 end
 

activesupport/Rakefile

@@ -10,6 +10,7 @@ Rake::TestTask.new do |t|
   t.pattern = "test/**/*_test.rb"
   t.warning = true
   t.verbose = true
+  t.options = "--profile" if ENV["CI"]
   t.ruby_opts = ["--dev"] if defined?(JRUBY_VERSION)
 end
 

railties/Rakefile

@@ -66,11 +66,13 @@ namespace :test do
 
     # Only generate the template app once.
     require_relative "test/isolation/abstract_unit"
+    require "minitest/rails_plugin"
 
     failing_files = []
 
     dirs = (ENV["TEST_DIR"] || ENV["TEST_DIRS"] || "**").split(",")
     test_options = ENV["TESTOPTS"].to_s.split(/[\s]+/)
+    test_options << "--profile" if ENV["BUILDKITE"]
 
     test_patterns = dirs.map { |dir| "test/#{dir}/*_test.rb" }
     test_files = Dir[*test_patterns].select do |file|
@@ -94,6 +96,8 @@ namespace :test do
       test_files = buckets[n]
     end
 
+    output_file = Tempfile.new("railties_test_reporter")
+
     test_files.each do |file|
       puts "--- #{file}"
       fake_command = Shellwords.join([
@@ -108,6 +112,7 @@ namespace :test do
         # We could run these in parallel, but pretty much all of the
         # railties tests already run in parallel, so ¯\_(⊙︿⊙)_/¯
         Process.waitpid fork {
+          ENV["RAILTIES_OUTPUT_FILE"] = output_file.path
           ARGV.clear.concat test_options
           Rake.application = nil
 
@@ -123,9 +128,22 @@ namespace :test do
       end
     end
 
-    puts "--- All tests completed"
+    puts "+++ All tests completed"
+
+    if ENV["BUILDKITE"]
+      TestResult = Struct.new(:NAME, :failures, :assertions, :klass, :time, :source_location, :location)
+      profile = Minitest::ProfileReporter.new($stdout, profile: 10)
+      output_file.rewind
+      output_file.each_line do |result|
+        data = JSON.parse(result)
+        profile.results << TestResult.new(*data.values)
+      end
+
+      profile.summary
+    end
+
     unless failing_files.empty?
-      puts "^^^ +++"
+      puts "+++"
       puts
       puts "Failed in:"
       failing_files.each do |file|
@@ -135,6 +153,9 @@ namespace :test do
 
       exit 1
     end
+  ensure
+    output_file&.close
+    output_file&.unlink
   end
 end
 
@@ -143,5 +164,6 @@ Rake::TestTask.new("test:regular") do |t|
   t.pattern = "test/**/*_test.rb"
   t.warning = true
   t.verbose = true
+  t.options = "--profile" if ENV["BUILDKITE"]
   t.ruby_opts = ["--dev"] if defined?(JRUBY_VERSION)
 end

railties/lib/minitest/rails_plugin.rb

@@ -26,33 +26,58 @@ def aggregated_results(*)
   end
 
   class ProfileReporter < Reporter
+    attr_accessor :results
+
     def initialize(io = $stdout, options = {})
       super
       @results = []
       @count = options[:profile]
     end
 
     def record(result)
-      @results << result
+      if output_file = ENV["RAILTIES_OUTPUT_FILE"]
+        File.open(output_file, "a") do |f|
+          # Round-trip for re-serialization
+          data = JSON.parse(result.to_json)
+          data[:location] = result.location
+          f.puts(data.to_json)
+        end
+      else
+        @results << result
+      end
+    end
+
+    def passed?
+      true
     end
 
     def report
-      total_time = @results.sum(&:time)
+      # Skip if we're outputting to a file
+      return if ENV["RAILTIES_OUTPUT_FILE"]
+      print_summary
+    end
 
-      @results.sort! { |a, b| b.time <=> a.time }
-      slow_results = @results.take(@count)
-      slow_tests_total_time = slow_results.sum(&:time)
+    def summary
+      print_summary
+    end
+
+    private
+      def print_summary
+        total_time = @results.sum(&:time)
+
+        @results.sort! { |a, b| b.time <=> a.time }
+        slow_results = @results.take(@count)
+        slow_tests_total_time = slow_results.sum(&:time)
 
-      ratio = (total_time == 0) ? 0.0 : (slow_tests_total_time / total_time) * 100
+        ratio = (total_time == 0) ? 0.0 : (slow_tests_total_time / total_time) * 100
 
-      io.puts("\nTop %d slowest tests (%.2f seconds, %.1f%% of total time):\n" % [slow_results.size, slow_tests_total_time, ratio])
-      slow_results.each do |result|
-        io.puts("  %s\n    %.4f seconds %s\n" % [result.location, result.time, source_location(result)])
+        io.puts("\nTop %d slowest tests (%.2f seconds, %.1f%% of total time):\n" % [slow_results.size, slow_tests_total_time, ratio])
+        slow_results.each do |result|
+          io.puts("  %s\n    %.4f seconds %s\n" % [result.location, result.time, source_location(result)])
+        end
+        io.puts("\n")
       end
-      io.puts("\n")
-    end
 
-    private
       def source_location(result)
         filename, line = result.source_location
         return "" unless filename