fastlane_core/spec/command_executor_spec.rb:12 is flaky

[lacostej]

  1) FastlaneCore FastlaneCore::CommandExecutor execute executes a simple command successfully
     Failure/Error: expect(result).to eq('foo')
     
       expected: "foo"
            got: ""
     
       (compared using ==)
     # ./fastlane_core/spec/command_executor_spec.rb:12:in `block (5 levels) in <top (required)>'
     # ./.bundle/ruby/3.1.0/gems/webmock-3.18.1/lib/webmock/rspec.rb:37:in `block (2 levels) in <top (required)>'

  2) FastlaneCore FastlaneCore::CommandExecutor execute executes a simple command successfully
     Failure/Error: expect(result).to eq('foo')
     
       expected: "foo"
            got: ""
     
       (compared using ==)
     # ./fastlane_core/spec/command_executor_spec.rb:12:in `block (5 levels) in <top (required)>'
     # ./.bundle/ruby/3.1.0/gems/webmock-3.18.1/lib/webmock/rspec.rb:37:in `block (2 levels) in <top (required)>'

  3) FastlaneCore FastlaneCore::CommandExecutor execute executes a simple command successfully
     Failure/Error: expect(result).to eq('foo')
     
       expected: "foo"
            got: ""
     
       (compared using ==)
     # ./fastlane_core/spec/command_executor_spec.rb:12:in `block (5 levels) in <top (required)>'
     # ./.bundle/ruby/3.1.0/gems/webmock-3.18.1/lib/webmock/rspec.rb:37:in `block (2 levels) in <top (required)>'

Finished in 2 minutes 53.7 seconds (files took 2.1 seconds to load)
10000 examples, 3 failures

New Issue Checklist

• Updated fastlane to the latest version
• I read the Contribution Guidelines
• I read docs.fastlane.tools
• I searched for existing GitHub issues

Issue Description

Command executed

Complete output when running fastlane, including the stack trace and command used

 [REPLACE THIS WITH YOUR INFORMATION] 

Environment

 [REPLACE THIS WITH YOUR INFORMATION] 

[lacostej]

The following script fails on some of my environments

require 'pty'
require 'expect'

def run_command(command)
  output = []
  PTY.spawn(command) do |command_stdout, command_stdin, pid|
    begin
      command_stdout.each do |l|
        line = l.chomp
        output << line
      end
    rescue Errno::EIO
      # This is expected on some linux systems, that indicates that the subcommand finished
      # and we kept trying to read, ignore it
    ensure
      command_stdout.close
      command_stdin.close
      Process.wait(pid)
    end
  end
  [$?.exitstatus, output.join("\n")]
end

def run_command2(command)
  output = []
  PTY.spawn(command) do |command_stdout, command_stdin, pid|
    output = ""
    begin
      a = command_stdout.expect(/foo.*/, 5)
      output = a[0] if a
    ensure
      command_stdout.close
      command_stdin.close
      Process.wait(pid)
    end
  end
  [$?.exitstatus, output]
end

def test_spawn(command)
  status, output = run_command(command)
  errors = []
  errors << "status was '#{status}'" unless status == 0
  errors << "output was '#{output}'" unless output == "foo"
  raise errors.join(" - ") unless errors.empty?
end

t = nil
pid = nil
if ENV['STRESS']
  t = Thread.new do |t|
    puts "Spawning stress"
    pid = spawn("stress -c 16 -t 99", pgroup: true)
    puts "Waiting #{pid}"
    Process.wait(pid)
    puts "#{pid} DONE"
  end
end

command = "echo foo"
#command = "sh -c 'echo foo'"
#command = "ruby -e \"puts 'foo'\""

if ARGV.count == 1
  command = ARGV[0]
end

puts "Will run command: '#{command}'"

errors = 0
1000.times do |i|
  begin
    test_spawn(command)
  rescue => e
    puts "ERROR #{i}: #{e}"
    errors += 1
  end
end

if t
  Process.kill(:SIGKILL, -pid)
  t.join
end

raise "Failed #{errors} times" unless errors == 0

You can edit the script to change

• the number of iterations
• the command to test

If you install the stress program, it will help adding some stress to the system to make the issues easier to reproduce.

Here are some of my findings.

 STRESS=y ruby test_pty.rb "echo foo"
[...]
ERROR 39: output was ''
ERROR 57: output was ''
ERROR 181: output was ''
ERROR 279: output was ''
ERROR 303: output was ''
ERROR 307: output was ''
ERROR 376: output was ''
[...]
test_pty.rb:83:in `<main>': Failed 16 times (RuntimeError)

STRESS=y ruby test_pty.rb "echo 'foo'"
works

update STRESS=y ruby test_pty.rb "echo 'foo'" used to fail, but this was fixed with closing the output/input.

so

• echo foo and echo 'foo' behave differently
• the first one reproduces the empty output rather regularly
• the second one reproduces Can't get Master/Slave device error #8258. This seems to happen only after running the test a few times, and I have a hard time to reproduce this at fresh start. Still it's a weird issue.

I'll add that I tested this on a second Mac. On the second Mac, I didn't mange to reproduce the output issue.

[lacostej]

I've reported the issue to Ruby. https://bugs.ruby-lang.org/issues/20206. Waiting for some feedback.

[lacostej]

Related to #3821 maybe?

[lacostej]

I've found out the following

running ruby test_pty.rb "echo 'foo'" or ruby test_pty.rb "stdbuf -i0 -o0 -e0 echo foo" doesn't reproduce the failure. So this could very much be caused by buffering issues on the terminal side. I still don't yet undertand how why echo "foo" and echo foo impact the buffering. I'll update the code to take this into account. Hopefully that will reduce the flakyness.