Merge pull request #2511 from rspec/myron/bisect-forker

Improve performance of bisect using new forking bisect runner

Author: myronmarston

Changelog.md

@@ -7,6 +7,14 @@ Enhancements:
   that it works on `Pathname` objects. (Andrew Vit, #2479)
 * Nicely format errors encountered while loading files specified
   by `--require` option.  (Myron Marston, #2504)
+* Significantly improve the performance of `--bisect` on platforms that
+  support forking by replacing the shell-based runner with one that uses
+  forking so that RSpec and the application environment can be booted only
+  once, instead of once per spec run. (Myron Marston, #2511)
+* Provide a configuration API to pick which bisect runner is used for
+  `--bisect`. Pick a runner via `config.bisect_runner = :shell` or
+  `config.bisect_runner = :fork` in a file loaded by a `--require`
+  option passed at the command line or set in `.rspec`. (Myron Marston, #2511)
 
 ### 3.7.1 / 2018-01-02
 [Full Changelog](http://github.com/rspec/rspec-core/compare/v3.7.0...v3.7.1)

features/command_line/bisect.feature

@@ -94,7 +94,7 @@ Feature: Bisect
     When I run `rspec --seed 1234 --bisect=verbose`
     Then bisect should succeed with output like:
       """
-      Bisect started using options: "--seed 1234"
+      Bisect started using options: "--seed 1234" and bisect runner: :fork
       Running suite to find failures... (0.16528 seconds)
        - Failing examples (1):
           - ./spec/calculator_1_spec.rb[1:1]
@@ -156,3 +156,23 @@ Feature: Bisect
       """
     When I run `rspec ./spec/calculator_10_spec.rb[1:1] ./spec/calculator_1_spec.rb[1:1] --seed 1234`
     Then the output should contain "2 examples, 1 failure"
+
+  Scenario: Pick a bisect runner via a config option
+    Given a file named "spec/spec_helper.rb" with:
+      """
+      RSpec.configure do |c|
+        c.bisect_runner = :shell
+      end
+      """
+    And a file named ".rspec" with:
+      """
+      --require spec_helper
+      """
+    When I run `rspec --seed 1234 --bisect=verbose`
+    Then bisect should succeed with output like:
+      """
+      Bisect started using options: "--seed 1234" and bisect runner: :shell
+      # ...
+      The minimal reproduction command is:
+        rspec ./spec/calculator_10_spec.rb[1:1] ./spec/calculator_1_spec.rb[1:1] --seed 1234
+      """

features/step_definitions/additional_cli_steps.rb

@@ -180,9 +180,14 @@
     "Output:\n\n#{last_process.stdout}"
 
   expected = normalize_durations(expected_output)
-  actual   = normalize_durations(last_process.stdout)
+  actual   = normalize_durations(last_process.stdout).sub(/\n+\Z/, '')
 
-  expect(actual.sub(/\n+\Z/, '')).to eq(expected)
+  if expected.include?("# ...")
+    expected_start, expected_end = expected.split("# ...")
+    expect(actual).to start_with(expected_start).and end_with(expected_end)
+  else
+    expect(actual).to eq(expected)
+  end
 end
 
 When(/^I run `([^`]+)` and abort in the middle with ctrl\-c$/) do |cmd|

lib/rspec/core/bisect/coordinator.rb

@@ -1,31 +1,30 @@
 RSpec::Support.require_rspec_core "bisect/shell_command"
-RSpec::Support.require_rspec_core "bisect/shell_runner"
 RSpec::Support.require_rspec_core "bisect/example_minimizer"
 RSpec::Support.require_rspec_core "bisect/utilities"
 RSpec::Support.require_rspec_core "formatters/bisect_progress_formatter"
 
 module RSpec
   module Core
     module Bisect
-      # @private
       # The main entry point into the bisect logic. Coordinates among:
       #   - Bisect::ShellCommand: Generates shell commands to run spec subsets
-      #   - Bisect::ShellRunner: Runs a set of examples and returns the results.
       #   - Bisect::ExampleMinimizer: Contains the core bisect logic.
-      #   - Formatters::BisectProgressFormatter: provides progress updates
-      #     to the user.
+      #   - A bisect runner: runs a set of examples and returns the results.
+      #   - A bisect formatter: provides progress updates to the user.
+      # @private
       class Coordinator
-        def self.bisect_with(original_cli_args, formatter)
-          new(original_cli_args, formatter).bisect
+        def self.bisect_with(spec_runner, original_cli_args, formatter)
+          new(spec_runner, original_cli_args, formatter).bisect
         end
 
-        def initialize(original_cli_args, formatter)
+        def initialize(spec_runner, original_cli_args, formatter)
+          @spec_runner   = spec_runner
           @shell_command = ShellCommand.new(original_cli_args)
           @notifier      = Bisect::Notifier.new(formatter)
         end
 
         def bisect
-          repro = ShellRunner.start(@shell_command) do |runner|
+          repro = start_bisect_runner do |runner|
             minimizer = ExampleMinimizer.new(@shell_command, runner, @notifier)
 
             gracefully_abort_on_sigint(minimizer)
@@ -45,6 +44,11 @@ def bisect
 
       private
 
+        def start_bisect_runner(&block)
+          klass = @spec_runner.configuration.bisect_runner_class
+          klass.start(@shell_command, @spec_runner, &block)
+        end
+
         def gracefully_abort_on_sigint(minimizer)
           trap('INT') do
             repro = minimizer.repro_command_for_currently_needed_ids

lib/rspec/core/bisect/example_minimizer.rb

@@ -111,7 +111,8 @@ def example_range(ids)
         end
 
         def prep
-          notify(:bisect_starting, :original_cli_args => shell_command.original_cli_args)
+          notify(:bisect_starting, :original_cli_args => shell_command.original_cli_args,
+                                   :bisect_runner => runner.class.name)
 
           _, duration = track_duration do
             original_results    = runner.original_results

lib/rspec/core/bisect/fork_runner.rb

@@ -0,0 +1,134 @@
+require 'stringio'
+RSpec::Support.require_rspec_core "formatters/base_bisect_formatter"
+RSpec::Support.require_rspec_core "bisect/utilities"
+
+module RSpec
+  module Core
+    module Bisect
+      # A Bisect runner that runs requested subsets of the suite by forking
+      # sub-processes. The master process bootstraps RSpec and the application
+      # environment (including preloading files specified via `--require`) so
+      # that the individual spec runs do not have to re-pay that cost.  Each
+      # spec run happens in a forked process, ensuring that the spec files are
+      # not loaded in the main process.
+      #
+      # For most projects, bisections that use `ForkRunner` instead of
+      # `ShellRunner` will finish significantly faster, because the `ShellRunner`
+      # pays the cost of booting RSpec and the app environment on _every_ run of
+      # a subset. In contrast, `ForkRunner` pays that cost only once.
+      #
+      # However, not all projects can use `ForkRunner`. Obviously, on platforms
+      # that do not support forking (e.g. Windows), it cannot be used. In addition,
+      # it can cause problems for some projects that put side-effectful spec
+      # bootstrapping logic that should run on every spec run directly at the top
+      # level in a file loaded by `--require`, rather than in a `before(:suite)`
+      # hook. For example, consider a project that relies on some top-level logic
+      # in `spec_helper` to boot a Redis server for the test suite, intending the
+      # Redis bootstrapping to happen on every spec run. With `ShellRunner`, the
+      # bootstrapping logic will happen for each run of any subset of the suite,
+      # but for `ForkRunner`, such logic will only get run once, when the
+      # `RunDispatcher` boots the application environment. This might cause
+      # problems. The solution is for users to move the bootstrapping logic into
+      # a `before(:suite)` hook, or use the slower `ShellRunner`.
+      #
+      # @private
+      class ForkRunner
+        def self.start(shell_command, spec_runner)
+          instance = new(shell_command, spec_runner)
+          yield instance
+        ensure
+          instance.shutdown
+        end
+
+        def self.name
+          :fork
+        end
+
+        def initialize(shell_command, spec_runner)
+          @shell_command = shell_command
+          @channel = Channel.new
+          @run_dispatcher = RunDispatcher.new(spec_runner, @channel)
+        end
+
+        def run(locations)
+          run_descriptor = ExampleSetDescriptor.new(locations, original_results.failed_example_ids)
+          dispatch_run(run_descriptor)
+        end
+
+        def original_results
+          @original_results ||= dispatch_run(ExampleSetDescriptor.new(
+            @shell_command.original_locations, []))
+        end
+
+        def shutdown
+          @channel.close
+        end
+
+      private
+
+        def dispatch_run(run_descriptor)
+          @run_dispatcher.dispatch_specs(run_descriptor)
+          @channel.receive.tap do |result|
+            if result.is_a?(String)
+              raise BisectFailedError.for_failed_spec_run(result)
+            end
+          end
+        end
+
+        # @private
+        class RunDispatcher
+          def initialize(runner, channel)
+            @runner = runner
+            @channel = channel
+
+            @spec_output = StringIO.new
+
+            runner.configuration.tap do |c|
+              c.reset_reporter
+              c.output_stream = @spec_output
+              c.error_stream = @spec_output
+            end
+          end
+
+          def dispatch_specs(run_descriptor)
+            pid = fork { run_specs(run_descriptor) }
+            Process.waitpid(pid)
+          end
+
+        private
+
+          def run_specs(run_descriptor)
+            $stdout = $stderr = @spec_output
+            formatter = CaptureFormatter.new(run_descriptor.failed_example_ids)
+
+            @runner.configuration.tap do |c|
+              c.files_or_directories_to_run = run_descriptor.all_example_ids
+              c.formatter = formatter
+              c.load_spec_files
+            end
+
+            # `announce_filters` has the side effect of implementing the logic
+            # that honors `config.run_all_when_everything_filtered` so we need
+            # to call it here. When we remove `run_all_when_everything_filtered`
+            # (slated for RSpec 4), we can remove this call to `announce_filters`.
+            @runner.world.announce_filters
+
+            @runner.run_specs(@runner.world.ordered_example_groups)
+            latest_run_results = formatter.results
+
+            if latest_run_results.nil? || latest_run_results.all_example_ids.empty?
+              @channel.send(@spec_output.string)
+            else
+              @channel.send(latest_run_results)
+            end
+          end
+        end
+
+        class CaptureFormatter < Formatters::BaseBisectFormatter
+          attr_accessor :results
+          alias_method :notify_results, :results=
+        end
+      end
+    end
+  end
+end

lib/rspec/core/bisect/shell_runner.rb

@@ -10,12 +10,16 @@ module Bisect
       # Sets of specs are run by shelling out.
       # @private
       class ShellRunner
-        def self.start(shell_command)
+        def self.start(shell_command, _spec_runner)
           Server.run do |server|
             yield new(server, shell_command)
           end
         end
 
+        def self.name
+          :shell
+        end
+
         def initialize(server, shell_command)
           @server        = server
           @shell_command = shell_command

lib/rspec/core/bisect/utilities.rb

@@ -27,6 +27,32 @@ def publish(event, *args)
           @formatter.__send__(event, notification)
         end
       end
+
+      # Wraps a pipe to support sending objects between a child and
+      # parent process.
+      # @private
+      class Channel
+        def initialize
+          @read_io, @write_io = IO.pipe
+        end
+
+        def send(message)
+          packet = Marshal.dump(message)
+          @write_io.write("#{packet.bytesize}\n#{packet}")
+        end
+
+        # rubocop:disable Security/MarshalLoad
+        def receive
+          packet_size = Integer(@read_io.gets)
+          Marshal.load(@read_io.read(packet_size))
+        end
+        # rubocop:enable Security/MarshalLoad
+
+        def close
+          @read_io.close
+          @write_io.close
+        end
+      end
     end
   end
 end

lib/rspec/core/configuration.rb

@@ -413,6 +413,38 @@ def shared_context_metadata_behavior=(value)
       # return [Integer]
       add_setting :max_displayed_failure_line_count
 
+      # Determines which bisect runner implementation gets used to run subsets
+      # of the suite during a bisection. Your choices are:
+      #
+      #   - `:shell`: Performs a spec run by shelling out, booting RSpec and your
+      #     application environment each time. This runner is the most widely
+      #     compatible runner, but is not as fast. On platforms that do not
+      #     support forking, this is the default.
+      #   - `:fork`: Pre-boots RSpec and your application environment in a parent
+      #     process, and then forks a child process for each spec run. This runner
+      #     tends to be significantly faster than the `:shell` runner but cannot
+      #     be used in some situations. On platforms that support forking, this
+      #     is the default. If you use this runner, you should ensure that all
+      #     of your one-time setup logic goes in a `before(:suite)` hook instead
+      #     of getting run at the top-level of a file loaded by `--require`.
+      #
+      # @note This option will only be used by `--bisect` if you set it in a file
+      #   loaded via `--require`.
+      #
+      # @return [Symbol]
+      attr_reader :bisect_runner
+      def bisect_runner=(value)
+        if @bisect_runner_class && value != @bisect_runner
+          raise "`config.bisect_runner = #{value.inspect}` can no longer take " \
+            "effect as the #{@bisect_runner.inspect} bisect runnner is already " \
+            "in use. This config setting must be set in a file loaded by a " \
+            "`--require` option (passed at the CLI or in a `.rspec` file) for " \
+            "it to have any effect."
+        end
+
+        @bisect_runner = value
+      end
+
       # @private
       # @deprecated Use {#color_mode} = :on, instead of {#color} with {#tty}
       add_setting :tty
@@ -437,6 +469,9 @@ def initialize
         @extend_modules  = FilterableItemRepository::QueryOptimized.new(:any?)
         @prepend_modules = FilterableItemRepository::QueryOptimized.new(:any?)
 
+        @bisect_runner = RSpec::Support::RubyFeatures.fork_supported? ? :fork : :shell
+        @bisect_runner_class = nil
+
         @before_suite_hooks = []
         @after_suite_hooks  = []
 
@@ -1962,6 +1997,23 @@ def on_example_group_definition_callbacks
         @on_example_group_definition_callbacks ||= []
       end
 
+      # @private
+      def bisect_runner_class
+        @bisect_runner_class ||= begin
+          case bisect_runner
+          when :fork
+            RSpec::Support.require_rspec_core 'bisect/fork_runner'
+            Bisect::ForkRunner
+          when :shell
+            RSpec::Support.require_rspec_core 'bisect/shell_runner'
+            Bisect::ShellRunner
+          else
+            raise "Unsupported value for `bisect_runner` (#{bisect_runner.inspect}). " \
+                  "Only `:fork` and `:shell` are supported."
+          end
+        end
+      end
+
     private
 
       def load_file_handling_errors(method, file)