Merge pull request #361 from Shopify/ss-rspec-report

Improve test summary output for `rspec` and `minitest`

Author: ChrisBr

ruby/lib/minitest/queue/build_status_reporter.rb

@@ -153,7 +153,10 @@ def report
         puts
 
         errors = error_reports
-        puts errors
+        if errors.any?
+          pretty_print_summary(errors)
+          pretty_print_failures(errors)
+        end
 
         build.worker_errors.to_a.sort.each do |worker_id, error|
           puts red("Worker #{worker_id } crashed")
@@ -224,6 +227,37 @@ def write_flaky_tests_file(file)
 
       attr_reader :build, :supervisor
 
+      def pretty_print_summary(errors)
+        test_paths = errors.map(&:test_file).compact
+        return unless test_paths.any?
+
+        file_counts = test_paths.each_with_object(Hash.new(0)) { |path, counts| counts[path] += 1 }
+
+        puts "\n" + "=" * 80
+        puts "FAILED TESTS SUMMARY:"
+        puts "=" * 80
+        file_counts.sort_by { |path, _| path }.each do |path, count|
+          relative_path = Minitest::Queue.relative_path(path)
+          if count == 1
+            puts "  #{relative_path}"
+          else
+            puts "  #{relative_path} (#{count} failures)"
+          end
+        end
+        puts "=" * 80
+      end
+
+      def pretty_print_failures(errors)
+        errors.each_with_index do |error, index|
+          puts "\n" + "-" * 80
+          puts "Error #{index + 1} of #{errors.size}"
+          puts "-" * 80
+          puts error
+        end
+
+        puts "=" * 80
+      end
+
       def timed_out?
         supervisor.time_left.to_i <= 0
       end

ruby/lib/rspec/queue.rb

@@ -5,6 +5,7 @@
 require 'ci/queue'
 require 'rspec/queue/build_status_recorder'
 require 'rspec/queue/order_recorder'
+require 'rspec/queue/error_report'
 
 module RSpec
   module Queue
@@ -291,16 +292,56 @@ def call(options, stdout, stderr)
           end
         end
 
-        # TODO: better reporting
-        errors = supervisor.build.error_reports.sort_by(&:first).map(&:last)
+        errors = supervisor.build.error_reports.sort_by(&:first).map do |_, error_data|
+            RSpec::Queue::ErrorReport.load(error_data)
+        end
         if errors.empty?
           step(green('No errors found'))
           0
         else
           message = errors.size == 1 ? "1 error found" : "#{errors.size} errors found"
           step(red(message), collapsed: false)
-          puts errors
+
+          pretty_print_summary(errors)
+          pretty_print_failures(errors)
           1
+          # Example output
+          #
+          # FAILED TESTS SUMMARY:
+          # =================================================================================
+          #   ./spec/dummy_spec.rb
+          #   ./spec/dummy_spec_2.rb (2 failures)
+          #   ./spec/dummy_spec_3.rb (3 failures)
+          # =================================================================================
+          #
+          # --------------------------------------------------------------------------------
+          # Error 1 of 3
+          # --------------------------------------------------------------------------------
+          #
+          #   Object doesn't work on first try
+          #   Failure/Error: expect(1 + 1).to be == 42
+          #
+          #     expected: == 42
+          #      got:    2
+          #
+          # --- stacktrace will be here ---
+          # --- rerun command will be here ---
+          #
+          # --------------------------------------------------------------------------------
+          # Error 2 of 3
+          # --------------------------------------------------------------------------------
+          #
+          #   Object doesn't work on first try
+          #   Failure/Error: expect(1 + 1).to be == 42
+          #
+          #     expected: == 42
+          #      got:    2
+          #
+          # --- stacktrace will be here ---
+          # --- rerun command will be here ---
+          #
+          #  ... etc
+          # =================================================================================
         end
       end
 
@@ -320,6 +361,38 @@ def setup(options, out, err)
         invalid_usage!('Missing --queue parameter') unless queue_url
         invalid_usage!('Missing --build parameter') unless RSpec::Queue.config.build_id
       end
+
+      private
+
+      def pretty_print_summary(errors)
+        test_paths = errors.map(&:test_file).compact
+        return unless test_paths.any?
+
+        file_counts = test_paths.each_with_object(Hash.new(0)) { |path, counts| counts[path] += 1 }
+
+        puts "\n" + "=" * 80
+        puts "FAILED TESTS SUMMARY:"
+        puts "=" * 80
+        file_counts.sort_by { |path, _| path }.each do |path, count|
+          if count == 1
+            puts "  #{path}"
+          else
+            puts "  #{path} (#{count} failures)"
+          end
+        end
+        puts "=" * 80
+      end
+
+      def pretty_print_failures(errors)
+        errors.each_with_index do |error, index|
+          puts "\n" + "-" * 80
+          puts "Error #{index + 1} of #{errors.size}"
+          puts "-" * 80
+          puts error.to_s
+        end
+
+        puts "=" * 80
+      end
     end
 
     class QueueReporter < SimpleDelegator
@@ -362,7 +435,18 @@ def setup(err, out)
         invalid_usage!('Missing --queue parameter') unless queue_url
         invalid_usage!('Missing --build parameter') unless RSpec::Queue.config.build_id
         invalid_usage!('Missing --worker parameter') unless RSpec::Queue.config.worker_id
-        RSpec.configuration.backtrace_formatter.filter_gem('ci-queue')
+        RSpec.configure do |config|
+          config.backtrace_exclusion_patterns = [
+            # Filter bundler paths
+            %r{/tmp/bundle/},
+            # RSpec internals
+            %r{/gems/rspec-},
+            # ci-queue and rspec-queue internals
+            %r{exe/rspec-queue},
+            %r{lib/ci/queue/},
+            %r{rspec/queue}
+          ]
+        end
       end
 
       def run_specs(example_groups)

ruby/lib/rspec/queue/build_status_recorder.rb

@@ -1,12 +1,17 @@
 # frozen_string_literal: true
+require 'rspec/queue/failure_formatter'
+require 'rspec/queue/error_report'
+
 module RSpec
   module Queue
     class BuildStatusRecorder
       ::RSpec::Core::Formatters.register self, :example_passed, :example_failed
 
       class << self
         attr_accessor :build
+        attr_accessor :failure_formatter
       end
+      self.failure_formatter = FailureFormatter
 
       def initialize(*)
       end
@@ -18,17 +23,13 @@ def example_passed(notification)
 
       def example_failed(notification)
         example = notification.example
-        build.record_error(example.id, [
-          notification.fully_formatted(nil),
-          colorized_rerun_command(example),
-        ].join("\n"))
+        build.record_error(example.id, dump(notification))
       end
 
       private
 
-      def colorized_rerun_command(example, colorizer=::RSpec::Core::Formatters::ConsoleCodes)
-        colorizer.wrap("rspec #{example.location_rerun_argument}", RSpec.configuration.failure_color) + " " +
-        colorizer.wrap("# #{example.full_description}",   RSpec.configuration.detail_color)
+      def dump(notification)
+        ErrorReport.new(self.class.failure_formatter.new(notification).to_h).dump
       end
 
       def build

ruby/lib/rspec/queue/error_report.rb

@@ -0,0 +1,92 @@
+# frozen_string_literal: true
+module RSpec
+  module Queue
+    class ErrorReport
+      class << self
+        attr_accessor :coder
+
+        def load(payload)
+          new(coder.load(payload))
+        end
+      end
+
+      # Default to Marshal
+      self.coder = Marshal
+
+      # Try to use SnappyPack if available from consumer's bundle
+      begin
+        require 'snappy'
+        require 'msgpack'
+        require 'stringio'
+
+        module SnappyPack
+          extend self
+
+          MSGPACK = MessagePack::Factory.new
+          MSGPACK.register_type(0x00, Symbol)
+
+          def load(payload)
+            io = StringIO.new(Snappy.inflate(payload))
+            MSGPACK.unpacker(io).unpack
+          end
+
+          def dump(object)
+            io = StringIO.new
+            packer = MSGPACK.packer(io)
+            packer.pack(object)
+            packer.flush
+            io.rewind
+            Snappy.deflate(io.string).force_encoding(Encoding::UTF_8)
+          end
+        end
+
+        self.coder = SnappyPack
+      rescue LoadError
+      end
+
+      def initialize(data)
+        @data = data
+      end
+
+      def dump
+        self.class.coder.dump(@data)
+      end
+
+      def test_name
+        @data[:test_name]
+      end
+
+      def error_class
+        @data[:error_class]
+      end
+
+      def test_and_module_name
+        @data[:test_and_module_name]
+      end
+
+      def test_suite
+        @data[:test_suite]
+      end
+
+      def test_file
+        @data[:test_file]
+      end
+
+      def test_line
+        @data[:test_line]
+      end
+
+      def to_h
+        @data
+      end
+
+      def to_s
+        output
+      end
+
+      def output
+        @data[:output]
+      end
+    end
+  end
+end

ruby/lib/rspec/queue/failure_formatter.rb

@@ -0,0 +1,45 @@
+# frozen_string_literal: true
+require 'delegate'
+require 'ci/queue/output_helpers'
+
+module RSpec
+  module Queue
+    class FailureFormatter < SimpleDelegator
+      include ::CI::Queue::OutputHelpers
+
+      def initialize(notification)
+        @notification = notification
+        super
+      end
+
+      def to_s
+        [
+          @notification.fully_formatted(nil),
+          colorized_rerun_command(@notification.example)
+        ].join("\n")
+      end
+
+      def to_h
+        example = @notification.example
+        {
+          test_file: example.file_path,
+          test_line: example.metadata[:line_number],
+          test_and_module_name: example.id,
+          test_name: example.description,
+          test_suite: example.example_group.description,
+          error_class: @notification.exception.class.name,
+          output: to_s,
+        }
+      end
+
+      private
+
+      attr_reader :notification
+
+      def colorized_rerun_command(example, colorizer=::RSpec::Core::Formatters::ConsoleCodes)
+        colorizer.wrap("rspec #{example.location_rerun_argument}", RSpec.configuration.failure_color) + " " +
+        colorizer.wrap("# #{example.full_description}", RSpec.configuration.detail_color)
+      end
+    end
+  end
+end

ruby/test/integration/minitest_redis_test.rb

@@ -954,15 +954,40 @@ def test_redis_reporter
           Ran 7 tests, 8 assertions, 2 failures, 1 errors, 1 skips, 4 requeues in X.XXs (aggregated)
 
 
+
+          ================================================================================
+          FAILED TESTS SUMMARY:
+          ================================================================================
+            test/dummy_test.rb (3 failures)
+          ================================================================================
+
+          --------------------------------------------------------------------------------
+          Error 1 of 3
+          --------------------------------------------------------------------------------
           FAIL ATest#test_bar
           Expected false to be truthy.
               test/dummy_test.rb:10:in `test_bar'
 
+
+          --------------------------------------------------------------------------------
+          Error 2 of 3
+          --------------------------------------------------------------------------------
           FAIL ATest#test_flaky_fails_retry
           Expected false to be truthy.
               test/dummy_test.rb:23:in `test_flaky_fails_retry'
 
+
+          --------------------------------------------------------------------------------
+          Error 3 of 3
+          --------------------------------------------------------------------------------
           ERROR BTest#test_bar
+          Minitest::UnexpectedError: TypeError: String can't be coerced into Integer
+              test/dummy_test.rb:37:in `+'
+              test/dummy_test.rb:37:in `test_bar'
+              test/dummy_test.rb:37:in `+'
+              test/dummy_test.rb:37:in `test_bar'
+          
+          ================================================================================
         END
         assert_includes output, expected_output
       end