Allow server to print debug messages (#478)

Author: vinistock

lib/ruby_lsp/ruby_lsp_rails/runner_client.rb

@@ -106,6 +106,15 @@ def initialize(outgoing_queue)
             end
           end
         end
+
+        @logger_thread = T.let(
+          Thread.new do
+            while (content = @stderr.gets("\n"))
+              log_message(content, type: RubyLsp::Constant::MessageType::LOG)
+            end
+          end,
+          Thread,
+        )
       rescue Errno::EPIPE, IncompleteMessageError
         raise InitializationError, @stderr.read
       end
@@ -126,7 +135,7 @@ def model(name)
         make_request("model", name: name)
       rescue IncompleteMessageError
         log_message(
-          "Ruby LSP Rails failed to get model information: #{@stderr.read}",
+          "Ruby LSP Rails failed to get model information",
           type: RubyLsp::Constant::MessageType::ERROR,
         )
         nil
@@ -144,9 +153,9 @@ def association_target_location(model_name:, association_name:)
           model_name: model_name,
           association_name: association_name,
         )
-      rescue => e
+      rescue IncompleteMessageError
         log_message(
-          "Ruby LSP Rails failed with #{e.message}: #{@stderr.read}",
+          "Ruby LSP Rails failed to get association location",
           type: RubyLsp::Constant::MessageType::ERROR,
         )
         nil
@@ -157,7 +166,7 @@ def route_location(name)
         make_request("route_location", name: name)
       rescue IncompleteMessageError
         log_message(
-          "Ruby LSP Rails failed to get route location: #{@stderr.read}",
+          "Ruby LSP Rails failed to get route location",
           type: RubyLsp::Constant::MessageType::ERROR,
         )
         nil
@@ -168,7 +177,7 @@ def route(controller:, action:)
         make_request("route_info", controller: controller, action: action)
       rescue IncompleteMessageError
         log_message(
-          "Ruby LSP Rails failed to get route information: #{@stderr.read}",
+          "Ruby LSP Rails failed to get route information",
           type: RubyLsp::Constant::MessageType::ERROR,
         )
         nil

lib/ruby_lsp/ruby_lsp_rails/server.rb

@@ -8,7 +8,22 @@
 
 module RubyLsp
   module Rails
+    module Common
+      # Write a message to the client. Can be used for sending notifications to the editor
+      def send_message(message)
+        json_message = message.to_json
+        @stdout.write("Content-Length: #{json_message.length}\r\n\r\n#{json_message}")
+      end
+
+      # Log a debug message to the editor's output
+      def debug_message(message)
+        $stderr.puts(message)
+      end
+    end
+
     class ServerAddon
+      include Common
+
       @server_addon_classes = []
       @server_addons = {}
 
@@ -38,12 +53,6 @@ def initialize(stdout)
         @stdout = stdout
       end
 
-      # Write a response back. Can be used for sending notifications to the editor
-      def write_response(response)
-        json_response = response.to_json
-        @stdout.write("Content-Length: #{json_response.length}\r\n\r\n#{json_response}")
-      end
-
       def name
         raise NotImplementedError, "Not implemented!"
       end
@@ -54,6 +63,8 @@ def execute(request, params)
     end
 
     class Server
+      include Common
+
       def initialize(stdout: $stdout, override_default_output_device: true)
         # Grab references to the original pipes so that we can change the default output device further down
         @stdin = $stdin
@@ -79,8 +90,7 @@ def start
         routes_reloader = ::Rails.application.routes_reloader
         routes_reloader.execute_unless_loaded if routes_reloader&.respond_to?(:execute_unless_loaded)
 
-        initialize_result = { result: { message: "ok", root: ::Rails.root.to_s } }.to_json
-        @stdout.write("Content-Length: #{initialize_result.length}\r\n\r\n#{initialize_result}")
+        send_message({ result: { message: "ok", root: ::Rails.root.to_s } })
 
         while @running
           headers = @stdin.gets("\r\n\r\n")
@@ -96,15 +106,15 @@ def execute(request, params)
         when "shutdown"
           @running = false
         when "model"
-          write_response(resolve_database_info_from_model(params.fetch(:name)))
+          send_message(resolve_database_info_from_model(params.fetch(:name)))
         when "association_target_location"
-          write_response(resolve_association_target(params))
+          send_message(resolve_association_target(params))
         when "reload"
           ::Rails.application.reloader.reload!
         when "route_location"
-          write_response(route_location(params.fetch(:name)))
+          send_message(route_location(params.fetch(:name)))
         when "route_info"
-          write_response(resolve_route_info(params))
+          send_message(resolve_route_info(params))
         when "server_addon/register"
           require params[:server_addon_path]
           ServerAddon.finalize_registrations!(@stdout)
@@ -114,16 +124,11 @@ def execute(request, params)
           ServerAddon.delegate(server_addon_name, request_name, params)
         end
       rescue => e
-        write_response({ error: e.full_message(highlight: false) })
+        send_message({ error: e.full_message(highlight: false) })
       end
 
       private
 
-      def write_response(response)
-        json_response = response.to_json
-        @stdout.write("Content-Length: #{json_response.length}\r\n\r\n#{json_response}")
-      end
-
       def resolve_route_info(requirements)
         if requirements[:controller]
           requirements[:controller] = requirements.fetch(:controller).underscore.delete_suffix("_controller")

test/ruby_lsp_rails/runner_client_test.rb

@@ -119,6 +119,42 @@ class RunnerClientTest < ActiveSupport::TestCase
         @client.delegate_request(server_addon_name: "My Add-on", request_name: "do_something", id: 5)
       end
 
+      test "server add-ons can log messages with the editor" do
+        File.write("server_addon.rb", <<~RUBY)
+          class TapiocaServerAddon < RubyLsp::Rails::ServerAddon
+            def name
+              "Tapioca"
+            end
+
+            def execute(request, params)
+              debug_message("Hello!")
+              send_message({ request:, params: })
+            end
+          end
+        RUBY
+
+        @client.register_server_addon(File.expand_path("server_addon.rb"))
+        @client.delegate_notification(server_addon_name: "Tapioca", request_name: "dsl")
+
+        # Started booting server
+        pop_log_notification(@outgoing_queue, RubyLsp::Constant::MessageType::LOG)
+        # Finished booting server
+        pop_log_notification(@outgoing_queue, RubyLsp::Constant::MessageType::LOG)
+
+        log = pop_log_notification(@outgoing_queue, RubyLsp::Constant::MessageType::LOG)
+
+        # Sometimes we get warnings concerning deprecations and they mess up this expectation
+        3.times do
+          unless log.params.message.match?(/Hello!/)
+            log = pop_log_notification(@outgoing_queue, RubyLsp::Constant::MessageType::LOG)
+          end
+        end
+
+        assert_match("Hello!", log.params.message)
+      ensure
+        FileUtils.rm("server_addon.rb")
+      end
+
       private
 
       def pop_log_notification(message_queue, type)

test/ruby_lsp_rails/server_test.rb

@@ -144,7 +144,7 @@ def name
         end
 
         def execute(request, params)
-          write_response({ request:, params: })
+          send_message({ request:, params: })
         end
       end
     RUBY