標準出力がコンソールか別のコマンドかによって、バッファリングやフラッシュの規則が異なる

環境

• ruby 2.7.1p83 (2020-03-31 revision a0c7c23c9c) [x86_64-linux]
• Ubuntu 20.04 LTS (Focal Fossa) [Windows Subsystem for Linux 2; WSL2]

事象

Rubyで標準出力を利用する場合、標準出力の先がコンソールか別のコマンドかによって、バッファリング・フラッシュの規則が異なっているようです。

• 標準出力が別コマンドにつながっている場合、バッファリングする
• 標準出力がコンソールにつながっている場合、1行ごとにフラッシュする。

これを簡単に検証してみましょう。標準出力がコンソールにつながっている場合はtrue、コマンドにつながっている場合はfalseを標準出力に出力したあと、0から4までの数字を1秒おきに標準出力に出力するRubyコードです。

main.rb

puts "STDOUT.isatty = #{STDOUT.isatty}"
5.times do |x|
  sleep 1
  puts x
end

以下のcmd.rbとconsole.rbはruby main.rbの標準出力をパイプまたはコンソールにつなげて実行し、出力した結果にタイムスタンプを付与します。

cmd.rb

require 'open3'

# 読み込み専用IOから1行づつ読み込み、タイムスタンプを付与して出力する。
puts '*** main.rbの標準出力が別コマンドにつながっている場合 ***'
Open3.popen3('ruby main.rb') do |stdin, stdout, stderr, wait_thr|
  stdout.each do |line|
    timestamp = Time.now.strftime('%F %T')
    puts "#{timestamp} #{line}"
  end
end

console.rb

require 'pty'

# 読み込み専用IOから1行づつ読み込み、タイムスタンプを付与して出力する。
puts '*** main.rbの標準出力がコンソールにつながっている場合 ***'
PTY.spawn('ruby main.rb') do |read, write, pid|
  read.each do |line|
    timestamp = Time.now.strftime('%F %T')
    puts "#{timestamp} #{line}"
  end
end

cmd.rbとconsole.rbの実行結果は以下の通りになります。

$ ruby cmd.rb 2>/dev/null
*** main.rbの標準出力が別コマンドにつながっている場合 ***
2020-07-05 16:45:09 STDOUT.isatty = false
2020-07-05 16:45:09 0
2020-07-05 16:45:09 1
2020-07-05 16:45:09 2
2020-07-05 16:45:09 3
2020-07-05 16:45:09 4
$ ruby console.rb 2>/dev/null
*** main.rbの標準出力がコンソールにつながっている場合 ***
2020-07-05 16:45:11 STDOUT.isatty = true
2020-07-05 16:45:12 0
2020-07-05 16:45:13 1
2020-07-05 16:45:14 2
2020-07-05 16:45:15 3
2020-07-05 16:45:16 4

タイムスタンプを見ると、標準出力がパイプにつながっているmain.rbはバッファリングしていますが、コンソールにつながっている場合は、行ごとにフラッシュしていることがわかります。

標準出力がコマンドにつながっている場合でも、バッファリングしたくない

いろいろやり方はあるとは思いますが、とりあえず思いつくのはこのあたりでしょうか。

• STDOUT.sync = trueを設定して、標準出力を同期モードにする
• STDOUT.flushを任意のタイミングで呼び出す。

前者について実験してみます。上記のmain.rbを以下のように改造します。

main.rb

$stdout.sync = true
puts "STDOUT.isatty = #{STDOUT.isatty}"
5.times do |x|
  sleep 1
  puts x
end

main.rbの標準出力を別コマンドにつなげるcmd.rbを実行すると、さきほどとは違って、バッファリングしていないことがわかります。

$ ruby cmd.rb 2>/dev/null
*** main.rbの標準出力が別コマンドにつながっている場合 ***
2020-07-05 16:51:33 STDOUT.isatty = false
2020-07-05 16:51:34 0
2020-07-05 16:51:35 1
2020-07-05 16:51:36 2
2020-07-05 16:51:37 3
2020-07-05 16:51:38 4

標準出力がコンソールにつながっている場合でも、フラッシュしてほしくない

これについてもやりようはいろいろありそうですが、自分の思いつく範囲だと「$stdoutをStringIOにリダイレクトし、任意のタイミングでStringIOにため込んだ内容をSTDOUTに出力する」というものがあります。この場合、main.rbは以下のようになるはずです。

main.rb

require 'stringio'

StringIO.open do |io|
  # 標準出力をStringIOにリダイレクト
  $stdout = io

  # ここはもともとのmain.rbと同じ
  puts "STDOUT.isatty = #{STDOUT.isatty}"
  5.times do |x|
    sleep 1
    puts x
  end

  # StringIOにためた内容をSTDOUTに吐き出す
  $stdout = STDOUT
  io.rewind
  puts io.read
end

console.rbを実行して、main.rbがコンソールにつながっている場合の動きを確認すると、想定通りバッファリングしていることがわかります。

$ ruby console.rb 2>/dev/null
*** main.rbの標準出力がコンソールにつながっている場合 ***
2020-07-05 16:56:38 STDOUT.isatty = true
2020-07-05 16:56:38 0
2020-07-05 16:56:38 1
2020-07-05 16:56:38 2
2020-07-05 16:56:38 3
2020-07-05 16:56:38 4