Wrap stderr in a structure log delegator (#564)

After #559, the server and its add-ons can send notifications, but regular `puts` that would normally be redirected to stderr are now lost.

Trying to account for any type of print in the notifier thread would be difficult. We need to be able to match against the `\r\n\r\n` separator, so that we can know exactly the start and end of a structured message.

So I propose we wrap stderr in a delegator instead. Essentially, any method invoked on `stderr` will still be redirect to it, but it gives us an opportunity to override `puts` and `print` to use structured logging, instead of just writing the strings directly to the pipe.

I tested this with the Tapioca add-on and I'm able to accurately see both progress notifications and messages in the output tab.

Author: vinistock

lib/ruby_lsp/ruby_lsp_rails/server.rb

@@ -3,6 +3,7 @@
 
 require "json"
 require "open3"
+require "delegate"
 
 module RubyLsp
   module Rails
@@ -197,6 +198,23 @@ def execute(request, params)
       end
     end
 
+    class IOWrapper < SimpleDelegator
+      def puts(*args)
+        args.each { |arg| log("#{arg}\n") }
+      end
+
+      def print(*args)
+        args.each { |arg| log(arg.to_s) }
+      end
+
+      private
+
+      def log(message)
+        json_message = { method: "window/logMessage", params: { type: 4, message: message } }.to_json
+        write("Content-Length: #{json_message.bytesize}\r\n\r\n#{json_message}")
+      end
+    end
+
     class Server
       include Common
 
@@ -218,7 +236,7 @@ def initialize(stdout: $stdout, stderr: $stderr, override_default_output_device:
         # # Set the default output device to be $stderr. This means that using `puts` by itself will default to printing
         # # to $stderr and only explicit `$stdout.puts` will go to $stdout. This reduces the chance that output coming
         # # from the Rails app will be accidentally sent to the client
-        $> = $stderr if override_default_output_device
+        $> = IOWrapper.new(@stderr) if override_default_output_device
 
         @running = true
       end

test/ruby_lsp_rails/server_test.rb

@@ -158,25 +158,6 @@ def execute(request, params)
     FileUtils.rm("server_addon.rb")
   end
 
-  test "prints in the Rails application or server are automatically redirected to stderr" do
-    stdout = StringIO.new
-    server = RubyLsp::Rails::Server.new(stdout: stdout)
-
-    server.instance_eval do
-      def resolve_route_info(requirements)
-        puts "Hello"
-        super
-      end
-    end
-
-    _, stderr = capture_subprocess_io do
-      server.execute("route_info", { controller: "UsersController", action: "index" })
-    end
-
-    refute_match("Hello", stdout.string)
-    assert_equal("Hello\n", stderr)
-  end
-
   test "checking for pending migrations" do
     capture_subprocess_io do
       system("bundle exec rails g migration CreateStudents name:string")
@@ -252,6 +233,30 @@ def resolve_route_info(requirements)
     assert_equal "Content-Length: #{expected_notification.bytesize}\r\n\r\n#{expected_notification}", @stderr.string
   end
 
+  test "regular prints become structured log messages" do
+    original_stdout = $stdout
+
+    stdout = StringIO.new
+    stderr = StringIO.new
+    server = RubyLsp::Rails::Server.new(stdout: stdout, stderr: stderr, override_default_output_device: true)
+
+    server.instance_eval do
+      def print_it!
+        puts "hello"
+      end
+    end
+
+    T.unsafe(server).print_it!
+
+    assert_match("Content-Length: 70\r\n\r\n", stderr.string)
+    assert_match(
+      "{\"method\":\"window/logMessage\",\"params\":{\"type\":4,\"message\":\"hello\\n\"}}",
+      stderr.string,
+    )
+  ensure
+    $> = original_stdout
+  end
+
   private
 
   def response