Avoid mutating stdout and stderr (#2486)

Uses `flush` after every write if the stdio it is not synchronized.

Closes: #1948

Co-authored-by: Nate Berkopec <nate.berkopec@gmail.com>

History.md

@@ -2,6 +2,7 @@
 
 * Features
   * Your feature goes here <Most recent on the top, like GitHub> (#Github Number)
+  * Uses `flush` after writing messages to avoid mutating $stdout and $stderr using `sync=true` ([#2486])
   * Fail build if compiling extensions raises warnings on GH Actions ([#1953])
   * Add MAKE_WARNINGS_INTO_ERRORS environment variable to toggle whether a build should treat all warnings into errors or not ([#1953])
 

lib/puma/control_cli.rb

@@ -237,13 +237,15 @@ def send_signal
 
         if sig.nil?
           @stdout.puts "'#{@command}' not available via pid only"
+          @stdout.flush unless @stdout.sync
           return
         elsif sig.start_with? 'SIG'
           Process.kill sig, @pid
         elsif @command == 'status'
           begin
             Process.kill 0, @pid
             @stdout.puts 'Puma is started'
+            @stdout.flush unless @stdout.sync
           rescue Errno::ESRCH
             raise 'Puma is not running'
           end

lib/puma/error_logger.rb

@@ -15,7 +15,6 @@ class ErrorLogger
 
     def initialize(ioerr)
       @ioerr = ioerr
-      @ioerr.sync = true
 
       @debug = ENV.key? 'PUMA_DEBUG'
     end
@@ -32,7 +31,7 @@ def self.stdio
     #   and before all remaining info.
     #
     def info(options={})
-      ioerr.puts title(options)
+      log title(options)
     end
 
     # Print occured error details only if
@@ -54,7 +53,7 @@ def debug(options={})
       string_block << request_dump(req) if request_parsed?(req)
       string_block << error.backtrace if error
 
-      ioerr.puts string_block.join("\n")
+      log string_block.join("\n")
     end
 
     def title(options={})
@@ -93,5 +92,13 @@ def request_headers(req)
     def request_parsed?(req)
       req && req.env[REQUEST_METHOD]
     end
+
+    private
+
+    def log(str)
+      ioerr.puts str
+
+      ioerr.flush unless ioerr.sync
+    end
   end
 end

lib/puma/events.rb

@@ -30,9 +30,6 @@ def initialize(stdout, stderr)
       @stdout = stdout
       @stderr = stderr
 
-      @stdout.sync = true
-      @stderr.sync = true
-
       @debug = ENV.key? 'PUMA_DEBUG'
       @error_logger = ErrorLogger.new(@stderr)
 
@@ -66,6 +63,8 @@ def register(hook, obj=nil, &blk)
     #
     def log(str)
       @stdout.puts format(str) if @stdout.respond_to? :puts
+
+      @stdout.flush unless @stdout.sync
     rescue Errno::EPIPE
     end
 

lib/puma/runner.rb

@@ -113,8 +113,8 @@ def redirect_io
         end
 
         STDOUT.reopen stdout, (append ? "a" : "w")
-        STDOUT.sync = true
         STDOUT.puts "=== puma startup: #{Time.now} ==="
+        STDOUT.flush unless STDOUT.sync
       end
 
       if stderr
@@ -123,8 +123,8 @@ def redirect_io
         end
 
         STDERR.reopen stderr, (append ? "a" : "w")
-        STDERR.sync = true
         STDERR.puts "=== puma startup: #{Time.now} ==="
+        STDERR.flush unless STDERR.sync
       end
     end
 

test/test_error_logger.rb

@@ -10,6 +10,14 @@ def test_stdio
     assert_equal STDERR, error_logger.ioerr
   end
 
+
+  def test_stdio_respects_sync
+    error_logger = Puma::ErrorLogger.stdio
+
+    assert_equal STDERR.sync, error_logger.ioerr.sync
+    assert_equal STDERR, error_logger.ioerr
+  end
+
   def test_info_with_only_error
     _, err = capture_io do
       Puma::ErrorLogger.stdio.info(error: StandardError.new('ready'))

test/test_events.rb

@@ -24,6 +24,15 @@ def test_stdio
     assert_equal STDERR, events.stderr
   end
 
+  def test_stdio_respects_sync
+    events = Puma::Events.stdio
+
+    assert_equal STDOUT.sync, events.stdout.sync
+    assert_equal STDERR.sync, events.stderr.sync
+    assert_equal STDOUT, events.stdout
+    assert_equal STDERR, events.stderr
+  end
+
   def test_register_callback_with_block
     res = false