From dd101389aba52adc150fb27598271626315c887b Mon Sep 17 00:00:00 2001
From: Carlos Castellanos Vera <me@carloscastellanos.dev>
Date: Wed, 2 Dec 2020 18:43:53 +0100
Subject: [PATCH] Avoid mutating stdout and stderr (#2486)

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

Closes: https://github.com/puma/puma/issues/1948

Co-authored-by: Nate Berkopec <nate.berkopec@gmail.com>
---
 History.md                |  1 +
 lib/puma/control_cli.rb   |  2 ++
 lib/puma/error_logger.rb  | 13 ++++++++++---
 lib/puma/events.rb        |  5 ++---
 lib/puma/runner.rb        |  4 ++--
 test/test_error_logger.rb |  8 ++++++++
 test/test_events.rb       |  9 +++++++++
 7 files changed, 34 insertions(+), 8 deletions(-)

diff --git a/History.md b/History.md
index 1faac2e2f6..7034333e21 100644
--- a/History.md
+++ b/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])
 
diff --git a/lib/puma/control_cli.rb b/lib/puma/control_cli.rb
index df749ff6a5..cc874acc57 100644
--- a/lib/puma/control_cli.rb
+++ b/lib/puma/control_cli.rb
@@ -237,6 +237,7 @@ 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
@@ -244,6 +245,7 @@ def send_signal
           begin
             Process.kill 0, @pid
             @stdout.puts 'Puma is started'
+            @stdout.flush unless @stdout.sync
           rescue Errno::ESRCH
             raise 'Puma is not running'
           end
diff --git a/lib/puma/error_logger.rb b/lib/puma/error_logger.rb
index 7a2bb462b0..4b1f183add 100644
--- a/lib/puma/error_logger.rb
+++ b/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
diff --git a/lib/puma/events.rb b/lib/puma/events.rb
index 29280075d2..f96d553845 100644
--- a/lib/puma/events.rb
+++ b/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
 
diff --git a/lib/puma/runner.rb b/lib/puma/runner.rb
index 615c62d869..a2cbe94e27 100644
--- a/lib/puma/runner.rb
+++ b/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
 
diff --git a/test/test_error_logger.rb b/test/test_error_logger.rb
index 38aba15522..08be915803 100644
--- a/test/test_error_logger.rb
+++ b/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'))
diff --git a/test/test_events.rb b/test/test_events.rb
index d0da584cfb..ddd9659cdf 100644
--- a/test/test_events.rb
+++ b/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