From 460d5535134d56fbd601271c216a7aa7d8dc7657 Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=C5=81ukasz=20Samson?= Date: Mon, 1 Jan 2024 19:06:20 +0100 Subject: [PATCH] Async parse (#1045) * debounce parse made async * extract common function * don't go through the server for not parsable documents * use common code path for calls with and without position * handle immediate requests asynchronously * store refs and respond on async process down * cleanup error codes :parse_error is reserved for invalid JSON-RPC requests and not LSP errors * improve LSP compatibility - fill error.data on initialize error * include version in key * enqueue parsing requests to the same uri * fix a few edge cases --- .../lib/language_server/json_rpc.ex | 38 +- .../lib/language_server/parser.ex | 329 +++++++++++------- .../providers/execute_command/apply_spec.ex | 4 +- .../execute_command/manipulate_pipes.ex | 8 +- .../providers/execute_command/mix_clean.ex | 2 +- .../lib/language_server/server.ex | 62 +++- .../execute_command/manipulate_pipes_test.exs | 4 +- 7 files changed, 291 insertions(+), 156 deletions(-) diff --git a/apps/language_server/lib/language_server/json_rpc.ex b/apps/language_server/lib/language_server/json_rpc.ex index 918847002..f45d7f651 100644 --- a/apps/language_server/lib/language_server/json_rpc.ex +++ b/apps/language_server/lib/language_server/json_rpc.ex @@ -67,6 +67,20 @@ defmodule ElixirLS.LanguageServer.JsonRpc do end end + defmacro error_response(id, code, message, data) do + quote do + %{ + "error" => %{ + "code" => unquote(code), + "message" => unquote(message), + "data" => unquote(data) + }, + "id" => unquote(id), + "jsonrpc" => "2.0" + } + end + end + ## Utils def notify(method, params) do @@ -77,9 +91,14 @@ defmodule ElixirLS.LanguageServer.JsonRpc do WireProtocol.send(response(id, result)) end - def respond_with_error(id, type, message \\ nil) do + def respond_with_error(id, type, message \\ nil, data \\ nil) do {code, default_message} = error_code_and_message(type) - WireProtocol.send(error_response(id, code, message || default_message)) + + if data do + WireProtocol.send(error_response(id, code, message || default_message, data)) + else + WireProtocol.send(error_response(id, code, message || default_message)) + end end def show_message(type, message) do @@ -226,16 +245,25 @@ defmodule ElixirLS.LanguageServer.JsonRpc do end end + # https://microsoft.github.io/language-server-protocol/specifications/lsp/3.17/specification/#errorCodes + + # Defined by JSON-RPC defp error_code_and_message(:parse_error), do: {-32700, "Parse error"} defp error_code_and_message(:invalid_request), do: {-32600, "Invalid Request"} defp error_code_and_message(:method_not_found), do: {-32601, "Method not found"} defp error_code_and_message(:invalid_params), do: {-32602, "Invalid params"} defp error_code_and_message(:internal_error), do: {-32603, "Internal error"} - defp error_code_and_message(:server_error), do: {-32000, "Server error"} + + # -32099 - -32000 - JSON-RPC reserved error codes + # No LSP error codes should be defined between the start and end range. + # For backwards compatibility the `ServerNotInitialized` and the `UnknownErrorCode` + # are left in the range. defp error_code_and_message(:server_not_initialized), do: {-32002, "Server not initialized"} defp error_code_and_message(:unknown_error_code), do: {-32001, "Unknown error code"} - defp error_code_and_message(:request_cancelled), do: {-32800, "Request cancelled"} + # -32899 - -32800 - LSP reserved error codes + defp error_code_and_message(:request_failed), do: {-32803, "Request cancelled"} + defp error_code_and_message(:server_cancelled), do: {-32802, "Server cancelled"} defp error_code_and_message(:content_modified), do: {-32801, "Content modified"} - defp error_code_and_message(:code_lens_error), do: {-32900, "Error while building code lenses"} + defp error_code_and_message(:request_cancelled), do: {-32800, "Request cancelled"} end diff --git a/apps/language_server/lib/language_server/parser.ex b/apps/language_server/lib/language_server/parser.ex index 3381ef1e0..e2aef5f4d 100644 --- a/apps/language_server/lib/language_server/parser.ex +++ b/apps/language_server/lib/language_server/parser.ex @@ -12,7 +12,7 @@ defmodule ElixirLS.LanguageServer.Parser do require Logger @debounce_timeout 300 - @parse_timeout 30_000 + @parse_timeout 120_000 @dummy_source "" @dummy_ast Code.string_to_quoted!(@dummy_source) @@ -39,21 +39,47 @@ defmodule ElixirLS.LanguageServer.Parser do end def parse_with_debounce(uri, source_file = %SourceFile{}) do - GenServer.cast(__MODULE__, {:parse_with_debounce, uri, source_file}) - end + if should_parse?(uri, source_file) do + GenServer.cast(__MODULE__, {:parse_with_debounce, uri, source_file}) + else + Logger.debug( + "Not parsing #{uri} version #{source_file.version} languageId #{source_file.language_id} with debounce" + ) - def parse_immediate(uri, source_file = %SourceFile{}) do - GenServer.call(__MODULE__, {:parse_immediate, uri, source_file}, @parse_timeout) + :ok + end end - def parse_immediate(uri, source_file = %SourceFile{}, position) do - GenServer.call(__MODULE__, {:parse_immediate, uri, source_file, position}, @parse_timeout) + def parse_immediate(uri, source_file = %SourceFile{}, position \\ nil) do + if should_parse?(uri, source_file) do + case GenServer.call( + __MODULE__, + {:parse_immediate, uri, source_file, position}, + @parse_timeout + ) do + :error -> raise "parser error" + :stale -> raise Server.ContentModifiedError, uri + %Context{} = context -> context + end + else + Logger.debug( + "Not parsing #{uri} version #{source_file.version} languageId #{source_file.language_id} immediately" + ) + + # not parsing - respond with empty struct + %Context{ + source_file: source_file, + path: get_path(uri), + ast: @dummy_ast, + metadata: @dummy_metadata + } + end end @impl true def init(_args) do # TODO get source files on start? - {:ok, %{files: %{}, debounce_refs: %{}}} + {:ok, %{files: %{}, debounce_refs: %{}, parse_pids: %{}, parse_uris: %{}, queue: []}} end @impl GenServer @@ -87,178 +113,206 @@ defmodule ElixirLS.LanguageServer.Parser do end @impl true - def handle_cast({:closed, uri}, state = %{files: files, debounce_refs: debounce_refs}) do - {maybe_ref, updated_debounce_refs} = Map.pop(debounce_refs, uri) + def handle_cast({:closed, uri}, state = %{files: files}) do + state = cancel_debounce(state, uri) - if maybe_ref do - Process.cancel_timer(maybe_ref, info: false) - end + # TODO maybe cancel parse updated_files = Map.delete(files, uri) notify_diagnostics_updated(updated_files) - {:noreply, %{state | files: updated_files, debounce_refs: updated_debounce_refs}} + {:noreply, %{state | files: updated_files}} end - def handle_cast({:parse_with_debounce, uri, source_file = %SourceFile{}}, state) do + def handle_cast( + {:parse_with_debounce, uri, source_file = %SourceFile{version: current_version}}, + state + ) do state = - if should_parse?(uri, source_file) do - state = - update_in(state.debounce_refs[uri], fn old_ref -> - if old_ref do - Process.cancel_timer(old_ref, info: false) - end + update_in(state.debounce_refs[uri], fn + nil -> + {Process.send_after(self(), {:parse_file, uri}, @debounce_timeout), current_version} - Process.send_after(self(), {:parse_file, uri}, @debounce_timeout) - end) + {old_ref, ^current_version} -> + {old_ref, current_version} - update_in(state.files[uri], fn - nil -> - %Context{ - source_file: source_file, - path: get_path(uri) - } + {old_ref, old_version} when old_version < current_version -> + Process.cancel_timer(old_ref, info: false) + {Process.send_after(self(), {:parse_file, uri}, @debounce_timeout), current_version} + end) - old_file -> - %Context{old_file | source_file: source_file} - end) - else - Logger.debug("Not parsing #{uri} with debounce: languageId #{source_file.language_id}") - state - end + state = + update_in(state.files[uri], fn + nil -> + %Context{ + source_file: source_file, + path: get_path(uri) + } + + %Context{source_file: %SourceFile{version: old_version}} = old_file + when current_version > old_version -> + %Context{old_file | source_file: source_file} + + %Context{source_file: %SourceFile{version: old_version}} = old_file -> + old_file + end) {:noreply, state} end @impl true def handle_call( - {:parse_immediate, uri, source_file = %SourceFile{}}, - _from, - %{files: files, debounce_refs: debounce_refs} = state + {:parse_immediate, uri, source_file = %SourceFile{}, position}, + from, + %{files: files} = state ) do - {reply, state} = - if should_parse?(uri, source_file) do - {maybe_ref, updated_debounce_refs} = Map.pop(debounce_refs, uri) + current_version = source_file.version + parent = self() - if maybe_ref do - Process.cancel_timer(maybe_ref, info: false) - end + case {files[uri], Map.has_key?(state.parse_pids, {uri, current_version})} do + {%Context{parsed_version: ^current_version} = file, _} -> + Logger.debug( + "#{uri} version #{current_version} languageId #{source_file.language_id} already parsed" + ) + + file = maybe_fix_missing_env(file, position) + + {:reply, file, state} + + {_, true} -> + Logger.debug( + "#{uri} version #{current_version} languageId #{source_file.language_id} is currently being parsed" + ) - current_version = source_file.version + state = %{state | queue: state.queue ++ [{{uri, current_version, position}, from}]} + {:noreply, state} - case files[uri] do - %Context{parsed_version: ^current_version} = file -> - Logger.debug("#{uri} already parsed") - # current version already parsed - {file, state} + {%Context{source_file: %SourceFile{version: old_version}}, _} + when old_version > current_version -> + {:reply, :stale, state} + + {other, _} -> + state = cancel_debounce(state, uri) + + updated_file = + case other do + nil -> + Logger.debug( + "Parsing #{uri} version #{current_version} languageId #{source_file.language_id} immediately" + ) - _other -> - Logger.debug("Parsing #{uri} immediately: languageId #{source_file.language_id}") - # overwrite everything - file = %Context{ source_file: source_file, path: get_path(uri) } - |> do_parse() - updated_files = Map.put(files, uri, file) + %Context{source_file: %SourceFile{version: old_version}} = old_file + when old_version <= current_version -> + Logger.debug( + "Parsing #{uri} version #{current_version} languageId #{source_file.language_id} immediately" + ) - notify_diagnostics_updated(updated_files) + %Context{old_file | source_file: source_file} + end - state = %{state | files: updated_files, debounce_refs: updated_debounce_refs} - {file, state} - end - else - Logger.debug("Not parsing #{uri} immediately: languageId #{source_file.language_id}") - # not parsing - respond with empty struct - reply = %Context{ - source_file: source_file, - path: get_path(uri), - ast: @dummy_ast, - metadata: @dummy_metadata - } - - {reply, state} - end + {pid, ref} = + spawn_monitor(fn -> + updated_file = do_parse(updated_file, position) + send(parent, {:parse_file_done, uri, updated_file, from}) + end) - {:reply, reply, state} + {:noreply, + %{ + state + | files: Map.put(files, uri, updated_file), + parse_pids: Map.put(state.parse_pids, {uri, current_version}, {pid, ref, from}), + parse_uris: Map.put(state.parse_uris, ref, {uri, current_version}) + }} + end end - def handle_call( - {:parse_immediate, uri, source_file = %SourceFile{}, position}, - _from, + @impl GenServer + def handle_info( + {:parse_file, uri}, %{files: files, debounce_refs: debounce_refs} = state ) do - {reply, state} = - if should_parse?(uri, source_file) do - {maybe_ref, updated_debounce_refs} = Map.pop(debounce_refs, uri) + file = Map.fetch!(files, uri) + version = file.source_file.version - if maybe_ref do - Process.cancel_timer(maybe_ref, info: false) - end + Logger.debug( + "Parsing #{uri} version #{version} languageId #{file.source_file.language_id} after debounce" + ) - current_version = source_file.version + parent = self() - case files[uri] do - %Context{parsed_version: ^current_version} = file -> - Logger.debug("#{uri} already parsed for cursor position #{inspect(position)}") - file = maybe_fix_missing_env(file, position) + {pid, ref} = + spawn_monitor(fn -> + updated_file = do_parse(file) + send(parent, {:parse_file_done, uri, updated_file, nil}) + end) - updated_files = Map.put(files, uri, file) - # no change to diagnostics, only update stored metadata - state = %{state | files: updated_files, debounce_refs: updated_debounce_refs} - {file, state} + state = %{ + state + | debounce_refs: Map.delete(debounce_refs, uri), + parse_pids: Map.put(state.parse_pids, {uri, version}, {pid, ref, nil}), + parse_uris: Map.put(state.parse_uris, ref, {uri, version}) + } - _other -> - Logger.debug("Parsing #{uri} immediately: languageId #{source_file.language_id}") - # overwrite everything - file = - %Context{ - source_file: source_file, - path: get_path(uri) - } - |> do_parse(position) + {:noreply, state} + end - updated_files = Map.put(files, uri, file) + def handle_info( + {:parse_file_done, uri, updated_file, from}, + %{files: files} = state + ) do + if from do + GenServer.reply(from, updated_file) + end - notify_diagnostics_updated(updated_files) + parsed_file_version = updated_file.parsed_version - state = %{state | files: updated_files, debounce_refs: updated_debounce_refs} - {file, state} - end - else - Logger.debug("Not parsing #{uri} immediately: languageId #{source_file.language_id}") - # not parsing - respond with empty struct - reply = %Context{ - source_file: source_file, - path: get_path(uri), - ast: @dummy_ast, - metadata: @dummy_metadata - } - - {reply, state} + state = + case files[uri] do + nil -> + # file got closed, no need to do anything + state + + %Context{source_file: %SourceFile{version: version}} when version > parsed_file_version -> + # result is from stale request, discard it + state + + _ -> + updated_files = Map.put(files, uri, updated_file) + notify_diagnostics_updated(updated_files) + %{state | files: updated_files} end - {:reply, reply, state} + queue = + Enum.reduce(state.queue, [], fn + {{^uri, ^parsed_file_version, position}, from}, acc -> + file = maybe_fix_missing_env(updated_file, position) + GenServer.reply(from, file) + acc + + {request, from}, acc -> + [{request, from} | acc] + end) + |> Enum.reverse() + + {:noreply, %{state | queue: queue}} end - @impl GenServer def handle_info( - {:parse_file, uri}, - %{files: files, debounce_refs: debounce_refs} = state + {:DOWN, ref, :process, pid, reason}, + %{parse_pids: parse_pids, parse_uris: parse_uris} = state ) do - file = Map.fetch!(files, uri) - Logger.debug("Parsing #{uri} after debounce: languageId #{file.source_file.language_id}") - - updated_file = - file - |> do_parse() - - updated_files = Map.put(files, uri, updated_file) + {{uri, version}, updated_parse_uris} = Map.pop!(parse_uris, ref) + {{^pid, ^ref, from}, updated_parse_pids} = Map.pop!(parse_pids, {uri, version}) - state = %{state | files: updated_files, debounce_refs: Map.delete(debounce_refs, uri)} + if reason != :normal and from != nil do + GenServer.reply(from, :error) + end - notify_diagnostics_updated(updated_files) + state = %{state | parse_pids: updated_parse_pids, parse_uris: updated_parse_uris} {:noreply, state} end @@ -268,6 +322,8 @@ defmodule ElixirLS.LanguageServer.Parser do source_file.language_id in ["elixir", "eex", "html-eex"] end + defp maybe_fix_missing_env(%Context{} = file, nil), do: file + defp maybe_fix_missing_env( %Context{metadata: metadata, flag: flag, source_file: source_file = %SourceFile{}} = file, @@ -421,6 +477,17 @@ defmodule ElixirLS.LanguageServer.Parser do end end + defp cancel_debounce(state = %{debounce_refs: debounce_refs}, uri) do + {maybe_ref, updated_debounce_refs} = Map.pop(debounce_refs, uri) + + if maybe_ref do + {ref, _version} = maybe_ref + Process.cancel_timer(ref, info: false) + end + + %{state | debounce_refs: updated_debounce_refs} + end + defp notify_diagnostics_updated(updated_files) do updated_files |> Map.new(fn {uri, %Context{diagnostics: diagnostics, parsed_version: version}} -> diff --git a/apps/language_server/lib/language_server/providers/execute_command/apply_spec.ex b/apps/language_server/lib/language_server/providers/execute_command/apply_spec.ex index bd42753ab..7000dc2ed 100644 --- a/apps/language_server/lib/language_server/providers/execute_command/apply_spec.ex +++ b/apps/language_server/lib/language_server/providers/execute_command/apply_spec.ex @@ -96,11 +96,11 @@ defmodule ElixirLS.LanguageServer.Providers.ExecuteCommand.ApplySpec do {:ok, nil} other -> - {:error, :server_error, + {:error, :request_failed, "cannot insert spec, workspace/applyEdit returned #{inspect(other)}", true} end else - {:error, :server_error, + {:error, :content_modified, "cannot insert spec, function definition has moved since suggestion was generated. " <> "Try again after file has been recompiled.", false} end diff --git a/apps/language_server/lib/language_server/providers/execute_command/manipulate_pipes.ex b/apps/language_server/lib/language_server/providers/execute_command/manipulate_pipes.ex index c36961480..7d072cbcd 100644 --- a/apps/language_server/lib/language_server/providers/execute_command/manipulate_pipes.ex +++ b/apps/language_server/lib/language_server/providers/execute_command/manipulate_pipes.ex @@ -52,16 +52,16 @@ defmodule ElixirLS.LanguageServer.Providers.ExecuteCommand.ManipulatePipes do {:ok, nil} else {:error, :pipe_not_found} -> - {:error, :parse_error, "Pipe operator not found at cursor", false} + {:error, :request_failed, "Pipe operator not found at cursor", false} {:error, :function_call_not_found} -> - {:error, :parse_error, "Function call not found at cursor", false} + {:error, :request_failed, "Function call not found at cursor", false} {:error, :invalid_code} -> - {:error, :parse_error, "Malformed code", false} + {:error, :request_failed, "Malformed code", false} error -> - {:error, :server_error, + {:error, :request_failed, "Cannot execute pipe conversion, workspace/applyEdit returned #{inspect(error)}", true} end end diff --git a/apps/language_server/lib/language_server/providers/execute_command/mix_clean.ex b/apps/language_server/lib/language_server/providers/execute_command/mix_clean.ex index 570950374..011639258 100644 --- a/apps/language_server/lib/language_server/providers/execute_command/mix_clean.ex +++ b/apps/language_server/lib/language_server/providers/execute_command/mix_clean.ex @@ -5,7 +5,7 @@ defmodule ElixirLS.LanguageServer.Providers.ExecuteCommand.MixClean do def execute([clean_deps?], state) do case ElixirLS.LanguageServer.Build.clean(state.project_dir, clean_deps?) do :ok -> {:ok, %{}} - {:error, reason} -> {:error, :server_error, "Mix clean failed: #{inspect(reason)}", true} + {:error, reason} -> {:error, :request_failed, "Mix clean failed: #{inspect(reason)}", true} end end end diff --git a/apps/language_server/lib/language_server/server.ex b/apps/language_server/lib/language_server/server.ex index 7f8d02e86..94c028b22 100644 --- a/apps/language_server/lib/language_server/server.ex +++ b/apps/language_server/lib/language_server/server.ex @@ -91,6 +91,16 @@ defmodule ElixirLS.LanguageServer.Server do end end + defmodule ContentModifiedError do + defexception [:uri, :message] + + @impl true + def exception(uri) do + msg = "document URI: #{inspect(uri)} modified" + %ContentModifiedError{message: msg, uri: uri} + end + end + @default_watched_extensions [ ".ex", ".exs", @@ -407,7 +417,7 @@ defmodule ElixirLS.LanguageServer.Server do if id do {{^pid, ^ref, command, _start_time}, updated_requests} = Map.pop!(requests, id) error_msg = Exception.format_exit(reason) - JsonRpc.respond_with_error(id, :server_error, error_msg) + JsonRpc.respond_with_error(id, :internal_error, error_msg) do_sanity_check(state) @@ -415,7 +425,7 @@ defmodule ElixirLS.LanguageServer.Server do "lsp_request_error", %{ "elixir_ls.lsp_command" => String.replace(command, "/", "_"), - "elixir_ls.lsp_error" => :server_error, + "elixir_ls.lsp_error" => :internal_error, "elixir_ls.lsp_error_message" => error_msg }, %{} @@ -748,15 +758,42 @@ defmodule ElixirLS.LanguageServer.Server do case packet do initialize_req(_id, _root_uri, _client_capabilities) -> - {:ok, result, state} = handle_request(packet, state) - elapsed = System.monotonic_time(:millisecond) - start_time - JsonRpc.respond(id, result) + try do + {:ok, result, state} = handle_request(packet, state) + elapsed = System.monotonic_time(:millisecond) - start_time + JsonRpc.respond(id, result) - JsonRpc.telemetry("lsp_request", %{"elixir_ls.lsp_command" => "initialize"}, %{ - "elixir_ls.lsp_request_time" => elapsed - }) + JsonRpc.telemetry("lsp_request", %{"elixir_ls.lsp_command" => "initialize"}, %{ + "elixir_ls.lsp_request_time" => elapsed + }) - state + state + catch + kind, payload -> + {payload, stacktrace} = Exception.blame(kind, payload, __STACKTRACE__) + error_msg = Exception.format(kind, payload, stacktrace) + + # on error in initialize the protocol requires to respond with + # https://microsoft.github.io/language-server-protocol/specifications/lsp/3.17/specification/#initializeError + # the initialize request can fail on broken OTP installs, no point in retrying + JsonRpc.respond_with_error(id, :internal_error, error_msg, %{ + "retry" => false + }) + + do_sanity_check(state) + + JsonRpc.telemetry( + "lsp_request_error", + %{ + "elixir_ls.lsp_command" => "initialize", + "elixir_ls.lsp_error" => :internal_error, + "elixir_ls.lsp_error_message" => error_msg + }, + %{} + ) + + state + end _ -> JsonRpc.respond_with_error(id, :server_not_initialized) @@ -854,7 +891,7 @@ defmodule ElixirLS.LanguageServer.Server do kind, payload -> {payload, stacktrace} = Exception.blame(kind, payload, __STACKTRACE__) error_msg = Exception.format(kind, payload, stacktrace) - JsonRpc.respond_with_error(id, :server_error, error_msg) + JsonRpc.respond_with_error(id, :internal_error, error_msg) do_sanity_check(state) @@ -862,7 +899,7 @@ defmodule ElixirLS.LanguageServer.Server do "lsp_request_error", %{ "elixir_ls.lsp_command" => String.replace(command, "/", "_"), - "elixir_ls.lsp_error" => :server_error, + "elixir_ls.lsp_error" => :internal_error, "elixir_ls.lsp_error_message" => error_msg }, %{} @@ -1190,6 +1227,9 @@ defmodule ElixirLS.LanguageServer.Server do rescue e in InvalidParamError -> {:error, :invalid_params, e.message, true} + + e in ContentModifiedError -> + {:error, :content_modified, e.message, true} end GenServer.call(parent, {:request_finished, id, result}, :infinity) diff --git a/apps/language_server/test/providers/execute_command/manipulate_pipes_test.exs b/apps/language_server/test/providers/execute_command/manipulate_pipes_test.exs index 45ac17edd..213ed5ce9 100644 --- a/apps/language_server/test/providers/execute_command/manipulate_pipes_test.exs +++ b/apps/language_server/test/providers/execute_command/manipulate_pipes_test.exs @@ -577,7 +577,7 @@ defmodule ElixirLS.LanguageServer.Providers.ExecuteCommand.ManipulatePipesTest d assert_never_raises(text, uri, "toPipe") - assert {:error, :parse_error, "Function call not found at cursor", false} = + assert {:error, :request_failed, "Function call not found at cursor", false} = ManipulatePipes.execute( ["toPipe", uri, 4, 13], %Server{ @@ -1144,7 +1144,7 @@ defmodule ElixirLS.LanguageServer.Providers.ExecuteCommand.ManipulatePipesTest d assert_never_raises(text, uri, "fromPipe") - assert {:error, :parse_error, "Pipe operator not found at cursor", false} = + assert {:error, :request_failed, "Pipe operator not found at cursor", false} = ManipulatePipes.execute( ["fromPipe", uri, 4, 16], %Server{