New subject: [ruby-core:116953] [Ruby master Bug#20206] PTY.spawn seems to fail to capture the output of "echo foo" once in a while

23 Jan 2024

      Issue #20206 has been reported by lacostej (Jerome Lacoste).

----------------------------------------
Bug #20206: PTY.spawn seems to fail to capture the output of "echo foo" once in a while
https://bugs.ruby-lang.org/issues/20206

* Author: lacostej (Jerome Lacoste)
* Status: Open
* Priority: Normal
* ruby -v: ruby 3.3.0 (2023-12-25 revision 5124f9ac75) [arm64-darwin23]
* Backport: 3.0: UNKNOWN, 3.1: UNKNOWN, 3.2: UNKNOWN, 3.3: UNKNOWN
----------------------------------------
We use PTY.spawn to call "echo foo", and on Mac it seems to randomly fail, capturing an empty output every now and then.
On Linux, the failure doesn't seem to happen.

The following code
1. contains 2 ways of capturing the output from PTY.spawn. Both seem to show the same issue (`run_command` and `run_command2`)
2. invokes the external `stress` program. This helps to trigger the issue more often.

``` ruby
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
  raise "#{$?.exited?} #{$?.stopped?} #{$?.signaled?} - #{$?.stopsig} - #{$?.termsig} -" unless $?.exitstatus == 0
  [$?.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
  raise "#{$?.exited?} #{$?.stopped?} #{$?.signaled?} - #{$?.stopsig} - #{$?.termsig} -" unless $?.exitstatus == 0
  [$?.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"

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

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

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

if t
  begin
    Process.kill(:SIGKILL, -pid)
  rescue Errno::ESRCH # already dead, ignore
  end
  t.join
end

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

Here are some ways of reproducing the issue
```
ruby test_pty.rb
STRESS=y ruby test_pty.rb
```

Here's an example of how it fails on circleci. https://app.circleci.com/pipelines/github/lacostej/cienvs/33/workflows/d6d8e...

Tested on ruby 2.6 to ruby 3.3.0 on Mac.

-- 
https://bugs.ruby-lang.org/

[ruby-core:116387] [Ruby master Bug#20206] PTY.spawn seems to fail to capture the output of "echo foo" once in a while

lacostej (Jerome Lacoste)

lacostej (Jerome Lacoste)

tags

participants (1)