Fix deadlock in Hbc::SystemCommand

Gemfile

@@ -16,9 +16,11 @@ group :release do
 end
 
 group :test do
-  gem 'coveralls', :require => false
+  gem 'coveralls', require: false
   gem 'minitest', '5.4.1'
   gem 'minitest-reporters'
-  gem 'mocha', '1.1.0', :require => false
+  gem 'mocha', '1.1.0', require: false
   gem 'rspec', '~> 3.0.0'
+  gem 'rspec-its', require: false
+  gem 'rspec-wait', require: false
 end

Gemfile.lock

@@ -64,9 +64,14 @@ GEM
     rspec-expectations (3.0.4)
       diff-lcs (>= 1.2.0, < 2.0)
       rspec-support (~> 3.0.0)
+    rspec-its (1.2.0)
+      rspec-core (>= 3.0.0)
+      rspec-expectations (>= 3.0.0)
     rspec-mocks (3.0.4)
       rspec-support (~> 3.0.0)
     rspec-support (3.0.4)
+    rspec-wait (0.0.8)
+      rspec (>= 2.11, < 3.5)
     rubocop (0.40.0)
       parser (>= 2.3.1.0, < 3.0)
       powerpack (~> 0.1)
@@ -104,6 +109,8 @@ DEPENDENCIES
   rake
   ronn (= 0.7.3)
   rspec (~> 3.0.0)
+  rspec-its
+  rspec-wait
   rubocop-cask (~> 0.6.1)
 
 BUNDLED WITH

lib/hbc/system_command.rb

@@ -2,64 +2,112 @@
 require 'shellwords'
 
 class Hbc::SystemCommand
+  attr_reader :command
+
   def self.run(executable, options={})
-    command = _process_options(executable, options)
-    processed_stdout = ''
-    processed_stderr = ''
+    self.new(executable, options).run!
+  end
+
+  def self.run!(command, options={})
+    run(command, options.merge(:must_succeed => true))
+  end
 
-    command[0] = Shellwords.shellescape(command[0]) if command.size == 1
+  def run!
+    @processed_output = { stdout: '', stderr: '' }
+    odebug "Executing: #{ expanded_command.utf8_inspect }"
+
+    each_output_line do |type, line|
+      case type
+      when :stdout
+        processed_output[:stdout] << line
+        ohai line.chomp if options[:print_stdout]
+      when :stderr
+        processed_output[:stderr] << line
+        ohai line.chomp if options[:print_stderr]
+      end
+    end
 
-    to_exec = command.map { |arg| arg.respond_to?(:to_path) ? File.absolute_path(arg) : String(arg) }
+    assert_success if options[:must_succeed]
+    result
+  end
 
-    odebug "Executing: #{to_exec.utf8_inspect}"
+  def initialize(executable, options)
+    @executable = executable
+    @options = options
+    process_options!
+  end
 
-    raw_stdin, raw_stdout, raw_stderr, raw_wait_thr = Open3.popen3(*to_exec)
+  private
 
-    if options[:input]
-      Array(options[:input]).each { |line| raw_stdin.puts line }
-    end
-    raw_stdin.close_write
+  attr_reader :executable, :options,
+    :processed_output, :processed_status
 
-    while line = raw_stdout.gets
-      processed_stdout << line
-      ohai line.chomp if options[:print_stdout]
+  def process_options!
+    options.assert_valid_keys :input, :print_stdout, :print_stderr, :args, :must_succeed, :sudo, :bsexec
+    sudo_prefix = %w{/usr/bin/sudo -E --}
+    bsexec_prefix = [ '/bin/launchctl', 'bsexec',  options[:bsexec]  == :startup ? '/' : options[:bsexec] ]
+    @command = [executable]
+    options[:print_stderr] = true   if !options.key?(:print_stderr)
+    @command.unshift(*bsexec_prefix) if  options[:bsexec]
+    @command.unshift(*sudo_prefix)   if  options[:sudo]
+    @command.concat(options[:args])  if  options.key?(:args) and !options[:args].empty?
+    if @command.size == 1
+      @command[0] = Shellwords.shellescape(@command[0])
     end
+    nil
+  end
 
-    while line = raw_stderr.gets
-      processed_stderr << line
-      ohai line.chomp if options[:print_stderr]
+  def assert_success
+    unless processed_status && processed_status.success?
+      raise Hbc::CaskCommandFailedError.new(
+        command.utf8_inspect,
+        processed_output[:stdout],
+        processed_status)
     end
+  end
 
-    raw_stdout.close_read
-    raw_stderr.close_read
+  def expanded_command
+    @expanded_command ||= command.map do |arg|
+      if arg.respond_to?(:to_path)
+        File.absolute_path(arg)
+      else
+        String(arg)
+      end
+    end
+  end
 
-    processed_status = raw_wait_thr.value
+  def each_output_line(&b)
+    raw_stdin, raw_stdout, raw_stderr, raw_wait_thr =
+      Open3.popen3(*expanded_command)
 
-    _assert_success(processed_status, command, processed_stdout) if options[:must_succeed]
+    write_input_to(raw_stdin) if options[:input]
+    raw_stdin.close_write
+    each_line_from [raw_stdout, raw_stderr], &b
 
-    Hbc::SystemCommand::Result.new(command, processed_stdout, processed_stderr, processed_status.exitstatus)
+    @processed_status = raw_wait_thr.value
   end
 
-  def self.run!(command, options={})
-    run(command, options.merge(:must_succeed => true))
+  def write_input_to(raw_stdin)
+    Array(options[:input]).each { |line| raw_stdin.puts line }
   end
 
-  def self._process_options(executable, options)
-    options.assert_valid_keys :input, :print_stdout, :print_stderr, :args, :must_succeed, :sudo, :bsexec
-    sudo_prefix = %w{/usr/bin/sudo -E --}
-    bsexec_prefix = [ '/bin/launchctl', 'bsexec',  options[:bsexec]  == :startup ? '/' : options[:bsexec] ]
-    command = [executable]
-    options[:print_stderr] = true   if !options.key?(:print_stderr)
-    command.unshift(*bsexec_prefix) if  options[:bsexec]
-    command.unshift(*sudo_prefix)   if  options[:sudo]
-    command.concat(options[:args])  if  options.key?(:args) and !options[:args].empty?
-    command
+  def each_line_from(sources)
+    begin
+      readable_sources = IO.select(sources)[0]
+      readable_sources.delete_if(&:eof?).first(1).each do |source|
+        type = (source == sources[0] ? :stdout : :stderr)
+        yield(type, source.gets || '')
+      end
+    end until readable_sources.empty?
+    sources.each(&:close_read)
   end
 
-  def self._assert_success(status, command, output)
-    unless status and status.success?
-      raise Hbc::CaskCommandFailedError.new(command.utf8_inspect, output, status)
-    end
+  def result
+    Hbc::SystemCommand::Result.new(command,
+      processed_output[:stdout],
+      processed_output[:stderr],
+      processed_status.exitstatus
+    )
   end
 end
 

spec/cask/system_command_spec.rb

@@ -2,16 +2,11 @@
 
 describe Hbc::SystemCommand do
   describe "when the exit code is 0" do
-    let(:command) { '/usr/bin/true' }
+    describe "its result" do
+      subject { described_class.run('/usr/bin/true') }
 
-    it "says the command was successful" do
-      result = described_class.run(command)
-      expect(result.success?).to eq(true)
-    end
-
-    it "says the exit status is 0" do
-      result = described_class.run(command)
-      expect(result.exit_status).to eq(0)
+      it { is_expected.to be_a_success }
+      its(:exit_status) { is_expected.to eq(0) }
     end
   end
 
@@ -27,32 +22,110 @@
     end
 
     describe "and the command does not have to succeed" do
-      it "says the command failed" do
-        result = described_class.run(command)
-        expect(result.success?).to eq(false)
-      end
+      describe "its result" do
+        subject { described_class.run(command) }
 
-      it "says the exit status is 1" do
-        result = described_class.run(command)
-        expect(result.exit_status).to eq(1)
+        it { is_expected.not_to be_a_success }
+        its(:exit_status) { is_expected.to eq(1) }
       end
     end
   end
 
-  describe "args" do
+  describe "given a pathname" do
     let(:command) { '/bin/ls' }
     let(:path)    { Pathname(Dir.mktmpdir) }
 
-    before do
-      FileUtils.touch(path.join('somefile'))
+    before { FileUtils.touch(path.join('somefile')) }
+
+    describe "its result" do
+      subject { described_class.run(command, args: [path]) }
+
+      it { is_expected.to be_a_success }
+      its(:stdout) { is_expected.to eq("somefile\n") }
+    end
+  end
+
+  describe "with both STDOUT and STDERR output from upstream" do
+    let(:command) { '/bin/bash' }
+    let(:options) do
+      { args: [
+        '-c',
+        'for i in $(seq 1 2 5); do echo $i; echo $(($i + 1)) >&2; done'
+      ] }
+    end
+
+    shared_examples "it returns '1 2 3 4 5 6'" do
+      describe "its result" do
+        subject { shutup { described_class.run(command, options) } }
+
+        it { is_expected.to be_a_success }
+        its(:stdout) { is_expected.to eq([1, 3, 5, nil].join("\n")) }
+        its(:stderr) { is_expected.to eq([2, 4, 6, nil].join("\n")) }
+      end
     end
 
-    it "can be pathnames" do
-      result = described_class.run(command, args: [path])
+    describe "with default options" do
+      it "echoes only STDERR" do
+        expected = [2, 4, 6].map { |i| "==> #{ i }\n" }.join('')
+        expect { described_class.run(command, options)
+          }.to output(expected).to_stdout
+      end
+
+      include_examples("it returns '1 2 3 4 5 6'")
+    end
+
+    describe "with print_stdout" do
+      before { options.merge!(print_stdout: true) }
+
+      it "echoes both STDOUT and STDERR" do
+        (1..6).each do |i|
+          expect { described_class.run(command, options)
+            }.to output(/==> #{ i }/).to_stdout
+        end
+      end
 
-      expect(result.success?).to eq(true)
-      expect(result.stdout).to eq("somefile\n")
+      include_examples("it returns '1 2 3 4 5 6'")
+    end
+
+    describe "without print_stderr" do
+      before { options.merge!(print_stderr: false) }
+
+      it "echoes nothing" do
+        expect { described_class.run(command, options)
+          }.to output('').to_stdout
+      end
+
+      include_examples("it returns '1 2 3 4 5 6'")
+    end
+
+    describe "with print_stdout but without print_stderr" do
+      before do
+        options.merge!(print_stdout: true, print_stderr: false)
+      end
+
+      it "echoes only STDOUT" do
+        expected = [1, 3, 5].map { |i| "==> #{ i }\n" }.join('')
+        expect { described_class.run(command, options)
+          }.to output(expected).to_stdout
+      end
+
+      include_examples("it returns '1 2 3 4 5 6'")
     end
   end
-end
 
+  describe "with a very long STDERR output" do
+    let(:command) { '/bin/bash' }
+    let(:options) do
+      { args: [
+        '-c',
+        'for i in $(seq 1 2 100000); do echo $i; echo $(($i + 1)) >&2; done'
+      ] }
+    end
+
+    it "returns without deadlocking" do
+      wait(10).for {
+        shutup { described_class.run(command, options) }
+      }.to be_a_success
+    end
+  end
+end

spec/spec_helper.rb

@@ -1,4 +1,6 @@
 require 'pathname'
+require 'rspec/its'
+require 'rspec/wait'
 
 if ENV['COVERAGE']
   require 'coveralls'

test/support/fake_system_command.rb

@@ -42,7 +42,7 @@ def self.verify_expectations!
   end
 
   def self.run(command_string, options={})
-    command = Hbc::SystemCommand._process_options(command_string, options)
+    command = Hbc::SystemCommand.new(command_string, options).command
     unless responses.key?(command)
       fail("no response faked for #{command.inspect}, faked responses are: #{responses.inspect}")
     end