From 3ddeeff569c48edb513e322d0b7fbcfc8bdb6aa2 Mon Sep 17 00:00:00 2001 From: Zach Allaun Date: Fri, 11 Aug 2023 11:39:35 -0400 Subject: [PATCH 1/9] fix: improve error handling for compiler diagnostics --- lib/next_ls/extensions/elixir_extension.ex | 2 +- lib/next_ls/runtime.ex | 27 ++++++++++++++-------- 2 files changed, 18 insertions(+), 11 deletions(-) diff --git a/lib/next_ls/extensions/elixir_extension.ex b/lib/next_ls/extensions/elixir_extension.ex index fd36b30a..76a9ed35 100644 --- a/lib/next_ls/extensions/elixir_extension.ex +++ b/lib/next_ls/extensions/elixir_extension.ex @@ -24,7 +24,7 @@ defmodule NextLS.ElixirExtension do end @impl GenServer - def handle_info({:compiler, diagnostics}, state) do + def handle_info({:compiler, diagnostics}, state) when is_list(diagnostics) do DiagnosticCache.clear(state.cache, :elixir) for d <- diagnostics do diff --git a/lib/next_ls/runtime.ex b/lib/next_ls/runtime.ex index c71065f5..41d61b21 100644 --- a/lib/next_ls/runtime.ex +++ b/lib/next_ls/runtime.ex @@ -128,7 +128,7 @@ defmodule NextLS.Runtime do NextLS.Logger.log(logger, "The runtime for #{name} has successfully shutdown.") reason -> - NextLS.Logger.error(logger, "The runtime for #{name} has crashed with reason: #{reason}.") + NextLS.Logger.error(logger, "The runtime for #{name} has crashed with reason: #{inspect(reason)}.") end end end) @@ -144,8 +144,8 @@ defmodule NextLS.Runtime do |> Path.join("monkey/_next_ls_private_compiler.ex") |> then(&:rpc.call(node, Code, :compile_file, [&1])) |> tap(fn - {:badrpc, :EXIT, {error, _}} -> - NextLS.Logger.error(logger, error) + {:badrpc, error} -> + NextLS.Logger.error(logger, {:badrpc, error}) _ -> :ok @@ -200,15 +200,22 @@ defmodule NextLS.Runtime do def handle_call(:compile, from, %{node: node} = state) do task = Task.Supervisor.async_nolink(state.task_supervisor, fn -> - {_, errors} = :rpc.call(node, :_next_ls_private_compiler, :compile, []) + case :rpc.call(node, :_next_ls_private_compiler, :compile, []) do + {:badrpc, error} -> + NextLS.Logger.error(state.logger, {:badrpc, error}) + [] - Registry.dispatch(state.registry, :extensions, fn entries -> - for {pid, _} <- entries do - send(pid, {:compiler, errors}) - end - end) + {_, diagnostics} when is_list(diagnostics) -> + Registry.dispatch(state.registry, :extensions, fn entries -> + for {pid, _} <- entries, do: send(pid, {:compiler, diagnostics}) + end) - errors + diagnostics + + unknown -> + NextLS.Logger.warning(state.logger, "Unexpected compiler response: #{inspect(unknown)}") + [] + end end) {:noreply, %{state | compiler_ref: %{task.ref => from}}} From c0bef57a84c4ab2b02b3b0457c9f882f0df60b75 Mon Sep 17 00:00:00 2001 From: Zach Allaun Date: Fri, 11 Aug 2023 14:48:17 -0400 Subject: [PATCH 2/9] test(runtime): compilation errors and logs --- lib/next_ls/runtime.ex | 27 ++++--- test/next_ls/runtime_test.exs | 136 +++++++++++++++++++--------------- test/support/utils.ex | 8 +- 3 files changed, 101 insertions(+), 70 deletions(-) diff --git a/lib/next_ls/runtime.ex b/lib/next_ls/runtime.ex index 41d61b21..cf6e466a 100644 --- a/lib/next_ls/runtime.ex +++ b/lib/next_ls/runtime.ex @@ -128,7 +128,7 @@ defmodule NextLS.Runtime do NextLS.Logger.log(logger, "The runtime for #{name} has successfully shutdown.") reason -> - NextLS.Logger.error(logger, "The runtime for #{name} has crashed with reason: #{inspect(reason)}.") + NextLS.Logger.error(logger, "The runtime for #{name} has crashed with reason: #{inspect(reason)}") end end end) @@ -144,20 +144,16 @@ defmodule NextLS.Runtime do |> Path.join("monkey/_next_ls_private_compiler.ex") |> then(&:rpc.call(node, Code, :compile_file, [&1])) |> tap(fn - {:badrpc, error} -> - NextLS.Logger.error(logger, {:badrpc, error}) - - _ -> - :ok + {:badrpc, error} -> NextLS.Logger.error(logger, "Bad RPC call: #{inspect(error)}") + _ -> :ok end) :rpc.call(node, Code, :put_compiler_option, [:parser_options, [columns: true, token_metadata: true]]) send(me, {:node, node}) else - _ -> - on_initialized.(:error) - send(me, :cancel) + error -> + send(me, {:cancel, error}) end end) @@ -202,7 +198,7 @@ defmodule NextLS.Runtime do Task.Supervisor.async_nolink(state.task_supervisor, fn -> case :rpc.call(node, :_next_ls_private_compiler, :compile, []) do {:badrpc, error} -> - NextLS.Logger.error(state.logger, {:badrpc, error}) + NextLS.Logger.error(state.logger, "Bad RPC call: #{inspect(error)}") [] {_, diagnostics} when is_list(diagnostics) -> @@ -235,6 +231,17 @@ defmodule NextLS.Runtime do {:noreply, %{state | compiler_ref: nil}} end + def handle_info({:DOWN, _, :port, port, reason}, %{port: port} = state) do + error = {:port_down, reason} + state.on_initialized.({:error, error}) + {:stop, {:shutdown, error}, state} + end + + def handle_info({:cancel, error}, state) do + state.on_initialized.({:error, error}) + {:stop, error, state} + end + def handle_info({:node, node}, state) do Node.monitor(node, true) state.on_initialized.(:ready) diff --git a/test/next_ls/runtime_test.exs b/test/next_ls/runtime_test.exs index 178532c4..fc3d25e3 100644 --- a/test/next_ls/runtime_test.exs +++ b/test/next_ls/runtime_test.exs @@ -1,7 +1,6 @@ defmodule NextLs.RuntimeTest do use ExUnit.Case, async: true - import ExUnit.CaptureLog import NextLS.Support.Utils alias NextLS.Runtime @@ -23,11 +22,13 @@ defmodule NextLs.RuntimeTest do end """) + me = self() + {:ok, logger} = Task.start_link(fn -> recv = fn recv -> receive do - msg -> Logger.debug(inspect(msg)) + {:"$gen_cast", msg} -> send(me, msg) end recv.(recv) @@ -36,9 +37,7 @@ defmodule NextLs.RuntimeTest do recv.(recv) end) - me = self() - - on_init = fn _ -> send(me, :ready) end + on_init = fn msg -> send(me, msg) end [logger: logger, cwd: Path.absname(tmp_dir), on_init: on_init] end @@ -63,12 +62,12 @@ defmodule NextLs.RuntimeTest do Process.link(pid) - assert wait_for_ready() + assert_receive :ready assert {:ok, "\"hi\""} = Runtime.call(pid, {Kernel, :inspect, ["hi"]}) end - test "call returns an error when the runtime is node ready", %{logger: logger, cwd: cwd, on_init: on_init} do + test "call returns an error when the runtime is not ready", %{logger: logger, cwd: cwd, on_init: on_init} do start_supervised!({Registry, keys: :duplicate, name: RuntimeTest.Registry}) tvisor = start_supervised!(Task.Supervisor) @@ -97,61 +96,82 @@ defmodule NextLs.RuntimeTest do tvisor = start_supervised!(Task.Supervisor) - capture_log(fn -> - pid = - start_link_supervised!( - {Runtime, - name: "my_proj", - on_initialized: on_init, - task_supervisor: tvisor, - working_dir: cwd, - uri: "file://#{cwd}", - parent: self(), - logger: logger, - db: :some_db, - registry: RuntimeTest.Registry} - ) - - assert wait_for_ready() - - file = Path.join(cwd, "lib/bar.ex") - - assert [ - %Mix.Task.Compiler.Diagnostic{ - file: ^file, - severity: :warning, - message: - "variable \"arg1\" is unused (if the variable is not meant to be used, prefix it with an underscore)", - position: position, - compiler_name: "Elixir", - details: nil - } - ] = Runtime.compile(pid) - - if Version.match?(System.version(), ">= 1.15.0") do - assert position == {4, 11} - else - assert position == 4 - end + pid = + start_link_supervised!( + {Runtime, + name: "my_proj", + on_initialized: on_init, + task_supervisor: tvisor, + working_dir: cwd, + uri: "file://#{cwd}", + parent: self(), + logger: logger, + db: :some_db, + registry: RuntimeTest.Registry} + ) - File.write!(file, """ - defmodule Bar do - def foo(arg1) do - arg1 - end + assert_receive :ready + + file = Path.join(cwd, "lib/bar.ex") + + assert [ + %Mix.Task.Compiler.Diagnostic{ + file: ^file, + severity: :warning, + message: + "variable \"arg1\" is unused (if the variable is not meant to be used, prefix it with an underscore)", + position: position, + compiler_name: "Elixir", + details: nil + } + ] = Runtime.compile(pid) + + if Version.match?(System.version(), ">= 1.15.0") do + assert position == {4, 11} + else + assert position == 4 + end + + File.write!(file, """ + defmodule Bar do + def foo(arg1) do + arg1 end - """) + end + """) - assert [] == Runtime.compile(pid) - end) =~ "Connected to node" + assert [] == Runtime.compile(pid) end - defp wait_for_ready do - receive do - :ready -> true - after - 30_000 -> - false - end + test "emits errors when runtime compilation fails", %{tmp_dir: tmp_dir, logger: logger, cwd: cwd, on_init: on_init} do + # obvious syntax error + bad_mix_exs = String.replace(mix_exs(), "defmodule", "") + File.write!(Path.join(tmp_dir, "mix.exs"), bad_mix_exs) + + start_supervised!({Registry, keys: :duplicate, name: RuntimeTest.Registry}) + + tvisor = start_supervised!(Task.Supervisor) + + start_supervised!( + {Runtime, + task_supervisor: tvisor, + name: "my_proj", + on_initialized: on_init, + working_dir: cwd, + uri: "file://#{cwd}", + parent: self(), + logger: logger, + db: :some_db, + registry: RuntimeTest.Registry}, + restart: :temporary + ) + + assert_receive {:error, {:port_down, :normal}} + + assert_receive {:log, :log, log_msg} + assert log_msg =~ "syntax error" + + assert_receive {:log, :error, error_msg} + assert error_msg =~ "{:shutdown, {:port_down, :normal}}" end end diff --git a/test/support/utils.ex b/test/support/utils.ex index e77285a4..2f97db99 100644 --- a/test/support/utils.ex +++ b/test/support/utils.ex @@ -83,11 +83,15 @@ defmodule NextLS.Support.Utils do [server: server, client: client] end - defmacro assert_is_ready(context, name) do + defmacro assert_is_ready( + context, + name, + timeout \\ Application.get_env(:ex_unit, :assert_receive_timeout) + ) do quote do message = "[NextLS] Runtime for folder #{unquote(context).module}-#{unquote(name)} is ready..." - assert_notification "window/logMessage", %{"message" => ^message} + assert_notification "window/logMessage", %{"message" => ^message}, unquote(timeout) end end From 6de5d5e91a7ad91a056f637985c7bb384c1578fe Mon Sep 17 00:00:00 2001 From: Zach Allaun Date: Sat, 12 Aug 2023 13:16:15 -0400 Subject: [PATCH 3/9] fix(runtime): don't call on_initialized after init fix(runtime): don't crash if compile is called before ready test(runtime): rgroup related tests in describe blocks --- lib/next_ls/runtime.ex | 19 ++- test/next_ls/runtime_test.exs | 246 +++++++++++++++++++--------------- 2 files changed, 154 insertions(+), 111 deletions(-) diff --git a/lib/next_ls/runtime.ex b/lib/next_ls/runtime.ex index cf6e466a..f337cea2 100644 --- a/lib/next_ls/runtime.ex +++ b/lib/next_ls/runtime.ex @@ -144,8 +144,11 @@ defmodule NextLS.Runtime do |> Path.join("monkey/_next_ls_private_compiler.ex") |> then(&:rpc.call(node, Code, :compile_file, [&1])) |> tap(fn - {:badrpc, error} -> NextLS.Logger.error(logger, "Bad RPC call: #{inspect(error)}") - _ -> :ok + {:badrpc, error} -> + NextLS.Logger.error(logger, "Bad RPC call to node #{node}: #{inspect(error)}") + + _ -> + :ok end) :rpc.call(node, Code, :put_compiler_option, [:parser_options, [columns: true, token_metadata: true]]) @@ -198,7 +201,7 @@ defmodule NextLS.Runtime do Task.Supervisor.async_nolink(state.task_supervisor, fn -> case :rpc.call(node, :_next_ls_private_compiler, :compile, []) do {:badrpc, error} -> - NextLS.Logger.error(state.logger, "Bad RPC call: #{inspect(error)}") + NextLS.Logger.error(state.logger, "Bad RPC call to node #{node}: #{inspect(error)}") [] {_, diagnostics} when is_list(diagnostics) -> @@ -217,6 +220,10 @@ defmodule NextLS.Runtime do {:noreply, %{state | compiler_ref: %{task.ref => from}}} end + def handle_call(:compile, _from, state) do + {:reply, {:error, :not_ready}, state} + end + @impl GenServer def handle_info({ref, errors}, %{compiler_ref: compiler_ref} = state) when is_map_key(compiler_ref, ref) do Process.demonitor(ref, [:flush]) @@ -233,7 +240,11 @@ defmodule NextLS.Runtime do def handle_info({:DOWN, _, :port, port, reason}, %{port: port} = state) do error = {:port_down, reason} - state.on_initialized.({:error, error}) + + unless is_map_key(state, :node) do + state.on_initialized.({:error, error}) + end + {:stop, {:shutdown, error}, state} end diff --git a/test/next_ls/runtime_test.exs b/test/next_ls/runtime_test.exs index fc3d25e3..cc75e6b2 100644 --- a/test/next_ls/runtime_test.exs +++ b/test/next_ls/runtime_test.exs @@ -42,37 +42,122 @@ defmodule NextLs.RuntimeTest do [logger: logger, cwd: Path.absname(tmp_dir), on_init: on_init] end - test "returns the response in an ok tuple", %{logger: logger, cwd: cwd, on_init: on_init} do - start_supervised!({Registry, keys: :duplicate, name: RuntimeTest.Registry}) - tvisor = start_supervised!(Task.Supervisor) + describe "call/2" do + test "responds with an ok tuple", %{logger: logger, cwd: cwd, on_init: on_init} do + start_supervised!({Registry, keys: :duplicate, name: RuntimeTest.Registry}) + tvisor = start_supervised!(Task.Supervisor) + + pid = + start_supervised!( + {Runtime, + name: "my_proj", + on_initialized: on_init, + task_supervisor: tvisor, + working_dir: cwd, + uri: "file://#{cwd}", + parent: self(), + logger: logger, + db: :some_db, + registry: RuntimeTest.Registry} + ) + + Process.link(pid) + + assert_receive :ready + + assert {:ok, "\"hi\""} = Runtime.call(pid, {Kernel, :inspect, ["hi"]}) + end - pid = - start_supervised!( - {Runtime, - name: "my_proj", - on_initialized: on_init, - task_supervisor: tvisor, - working_dir: cwd, - uri: "file://#{cwd}", - parent: self(), - logger: logger, - db: :some_db, - registry: RuntimeTest.Registry} - ) + test "responds with an error when the runtime isn't ready", + %{logger: logger, cwd: cwd, on_init: on_init} do + start_supervised!({Registry, keys: :duplicate, name: RuntimeTest.Registry}) + + tvisor = start_supervised!(Task.Supervisor) + + pid = + start_supervised!( + {Runtime, + task_supervisor: tvisor, + name: "my_proj", + on_initialized: on_init, + working_dir: cwd, + uri: "file://#{cwd}", + parent: self(), + logger: logger, + db: :some_db, + registry: RuntimeTest.Registry} + ) + + Process.link(pid) + + assert {:error, :not_ready} = Runtime.call(pid, {IO, :puts, ["hi"]}) + end + end - Process.link(pid) + describe "compile/1" do + test "compiles the project and returns diagnostics", + %{logger: logger, cwd: cwd, on_init: on_init} do + start_supervised!({Registry, keys: :duplicate, name: RuntimeTest.Registry}) + + tvisor = start_supervised!(Task.Supervisor) + + pid = + start_link_supervised!( + {Runtime, + name: "my_proj", + on_initialized: on_init, + task_supervisor: tvisor, + working_dir: cwd, + uri: "file://#{cwd}", + parent: self(), + logger: logger, + db: :some_db, + registry: RuntimeTest.Registry} + ) + + assert_receive :ready + + file = Path.join(cwd, "lib/bar.ex") + + assert [ + %Mix.Task.Compiler.Diagnostic{ + file: ^file, + severity: :warning, + message: + "variable \"arg1\" is unused (if the variable is not meant to be used, prefix it with an underscore)", + position: position, + compiler_name: "Elixir", + details: nil + } + ] = Runtime.compile(pid) + + if Version.match?(System.version(), ">= 1.15.0") do + assert position == {4, 11} + else + assert position == 4 + end - assert_receive :ready + File.write!(file, """ + defmodule Bar do + def foo(arg1) do + arg1 + end + end + """) - assert {:ok, "\"hi\""} = Runtime.call(pid, {Kernel, :inspect, ["hi"]}) - end + assert [] == Runtime.compile(pid) + end + + test "emits errors when runtime compilation fails", + %{tmp_dir: tmp_dir, logger: logger, cwd: cwd, on_init: on_init} do + # obvious syntax error + bad_mix_exs = String.replace(mix_exs(), "defmodule", "") + File.write!(Path.join(tmp_dir, "mix.exs"), bad_mix_exs) - test "call returns an error when the runtime is not ready", %{logger: logger, cwd: cwd, on_init: on_init} do - start_supervised!({Registry, keys: :duplicate, name: RuntimeTest.Registry}) + start_supervised!({Registry, keys: :duplicate, name: RuntimeTest.Registry}) - tvisor = start_supervised!(Task.Supervisor) + tvisor = start_supervised!(Task.Supervisor) - pid = start_supervised!( {Runtime, task_supervisor: tvisor, @@ -83,95 +168,42 @@ defmodule NextLs.RuntimeTest do parent: self(), logger: logger, db: :some_db, - registry: RuntimeTest.Registry} + registry: RuntimeTest.Registry}, + restart: :temporary ) - Process.link(pid) - - assert {:error, :not_ready} = Runtime.call(pid, {IO, :puts, ["hi"]}) - end - - test "compiles the code and returns diagnostics", %{logger: logger, cwd: cwd, on_init: on_init} do - start_supervised!({Registry, keys: :duplicate, name: RuntimeTest.Registry}) + assert_receive {:error, {:port_down, :normal}} - tvisor = start_supervised!(Task.Supervisor) + assert_receive {:log, :log, log_msg} + assert log_msg =~ "syntax error" - pid = - start_link_supervised!( - {Runtime, - name: "my_proj", - on_initialized: on_init, - task_supervisor: tvisor, - working_dir: cwd, - uri: "file://#{cwd}", - parent: self(), - logger: logger, - db: :some_db, - registry: RuntimeTest.Registry} - ) - - assert_receive :ready - - file = Path.join(cwd, "lib/bar.ex") - - assert [ - %Mix.Task.Compiler.Diagnostic{ - file: ^file, - severity: :warning, - message: - "variable \"arg1\" is unused (if the variable is not meant to be used, prefix it with an underscore)", - position: position, - compiler_name: "Elixir", - details: nil - } - ] = Runtime.compile(pid) - - if Version.match?(System.version(), ">= 1.15.0") do - assert position == {4, 11} - else - assert position == 4 + assert_receive {:log, :error, error_msg} + assert error_msg =~ "{:shutdown, {:port_down, :normal}}" end - File.write!(file, """ - defmodule Bar do - def foo(arg1) do - arg1 - end + test "responds with an error when the runtime isn't ready", + %{logger: logger, cwd: cwd, on_init: on_init} do + start_supervised!({Registry, keys: :duplicate, name: RuntimeTest.Registry}) + + tvisor = start_supervised!(Task.Supervisor) + + pid = + start_supervised!( + {Runtime, + task_supervisor: tvisor, + name: "my_proj", + on_initialized: on_init, + working_dir: cwd, + uri: "file://#{cwd}", + parent: self(), + logger: logger, + db: :some_db, + registry: RuntimeTest.Registry} + ) + + Process.link(pid) + + assert {:error, :not_ready} = Runtime.compile(pid) end - """) - - assert [] == Runtime.compile(pid) - end - - test "emits errors when runtime compilation fails", %{tmp_dir: tmp_dir, logger: logger, cwd: cwd, on_init: on_init} do - # obvious syntax error - bad_mix_exs = String.replace(mix_exs(), "defmodule", "") - File.write!(Path.join(tmp_dir, "mix.exs"), bad_mix_exs) - - start_supervised!({Registry, keys: :duplicate, name: RuntimeTest.Registry}) - - tvisor = start_supervised!(Task.Supervisor) - - start_supervised!( - {Runtime, - task_supervisor: tvisor, - name: "my_proj", - on_initialized: on_init, - working_dir: cwd, - uri: "file://#{cwd}", - parent: self(), - logger: logger, - db: :some_db, - registry: RuntimeTest.Registry}, - restart: :temporary - ) - - assert_receive {:error, {:port_down, :normal}} - - assert_receive {:log, :log, log_msg} - assert log_msg =~ "syntax error" - - assert_receive {:log, :error, error_msg} - assert error_msg =~ "{:shutdown, {:port_down, :normal}}" end end From d5f340ed146b8431f6f01334ac3a8b402ab84e27 Mon Sep 17 00:00:00 2001 From: Zach Allaun Date: Sat, 12 Aug 2023 13:22:38 -0400 Subject: [PATCH 4/9] refactor(runtime): encapsulate ready checks in private guard --- lib/next_ls/runtime.ex | 20 +++++++++----------- 1 file changed, 9 insertions(+), 11 deletions(-) diff --git a/lib/next_ls/runtime.ex b/lib/next_ls/runtime.ex index f337cea2..d31c11b3 100644 --- a/lib/next_ls/runtime.ex +++ b/lib/next_ls/runtime.ex @@ -3,6 +3,7 @@ defmodule NextLS.Runtime do use GenServer @env Mix.env() + defguardp is_ready(state) when is_map_key(state, :node) def start_link(opts) do GenServer.start_link(__MODULE__, opts) @@ -179,7 +180,7 @@ defmodule NextLS.Runtime do end @impl GenServer - def handle_call(:ready?, _from, %{node: _node} = state) do + def handle_call(:ready?, _from, state) when is_ready(state) do {:reply, true, state} end @@ -187,15 +188,15 @@ defmodule NextLS.Runtime do {:reply, false, state} end + def handle_call(_, _from, state) when not is_ready(state) do + {:reply, {:error, :not_ready}, state} + end + def handle_call({:call, {m, f, a}}, _from, %{node: node} = state) do reply = :rpc.call(node, m, f, a) {:reply, {:ok, reply}, state} end - def handle_call({:call, _}, _from, state) do - {:reply, {:error, :not_ready}, state} - end - def handle_call(:compile, from, %{node: node} = state) do task = Task.Supervisor.async_nolink(state.task_supervisor, fn -> @@ -220,12 +221,9 @@ defmodule NextLS.Runtime do {:noreply, %{state | compiler_ref: %{task.ref => from}}} end - def handle_call(:compile, _from, state) do - {:reply, {:error, :not_ready}, state} - end - @impl GenServer - def handle_info({ref, errors}, %{compiler_ref: compiler_ref} = state) when is_map_key(compiler_ref, ref) do + def handle_info({ref, errors}, %{compiler_ref: compiler_ref} = state) + when is_map_key(compiler_ref, ref) do Process.demonitor(ref, [:flush]) GenServer.reply(compiler_ref[ref], errors) @@ -241,7 +239,7 @@ defmodule NextLS.Runtime do def handle_info({:DOWN, _, :port, port, reason}, %{port: port} = state) do error = {:port_down, reason} - unless is_map_key(state, :node) do + unless is_ready(state) do state.on_initialized.({:error, error}) end From 47245e9a7272a473d4e9c0bd728e4eefaa243a0b Mon Sep 17 00:00:00 2001 From: Zach Allaun Date: Sat, 12 Aug 2023 13:55:16 -0400 Subject: [PATCH 5/9] fix(runtime): handle and log :nodedown message if node disconnects --- lib/next_ls/runtime.ex | 10 ++- test/next_ls/runtime_test.exs | 104 ++++++++++++++++++++----------- test/next_ls/workspaces_test.exs | 2 +- 3 files changed, 77 insertions(+), 39 deletions(-) diff --git a/lib/next_ls/runtime.ex b/lib/next_ls/runtime.ex index d31c11b3..a295cd80 100644 --- a/lib/next_ls/runtime.ex +++ b/lib/next_ls/runtime.ex @@ -126,7 +126,7 @@ defmodule NextLS.Runtime do {:DOWN, ^ref, :process, ^me, reason} -> case reason do :shutdown -> - NextLS.Logger.log(logger, "The runtime for #{name} has successfully shutdown.") + NextLS.Logger.log(logger, "The runtime for #{name} has successfully shut down.") reason -> NextLS.Logger.error(logger, "The runtime for #{name} has crashed with reason: #{inspect(reason)}") @@ -222,8 +222,7 @@ defmodule NextLS.Runtime do end @impl GenServer - def handle_info({ref, errors}, %{compiler_ref: compiler_ref} = state) - when is_map_key(compiler_ref, ref) do + def handle_info({ref, errors}, %{compiler_ref: compiler_ref} = state) when is_map_key(compiler_ref, ref) do Process.demonitor(ref, [:flush]) GenServer.reply(compiler_ref[ref], errors) @@ -257,6 +256,11 @@ defmodule NextLS.Runtime do {:noreply, Map.put(state, :node, node)} end + def handle_info({:nodedown, node}, %{node: node} = state) do + NextLS.Logger.warning(state.logger, "Connected node #{node} is down. Exiting #{state.name} runtime.") + {:stop, :shutdown, state} + end + def handle_info({port, {:data, data}}, %{port: port} = state) do NextLS.Logger.log(state.logger, data) {:noreply, state} diff --git a/test/next_ls/runtime_test.exs b/test/next_ls/runtime_test.exs index cc75e6b2..c4e2330e 100644 --- a/test/next_ls/runtime_test.exs +++ b/test/next_ls/runtime_test.exs @@ -42,8 +42,75 @@ defmodule NextLs.RuntimeTest do [logger: logger, cwd: Path.absname(tmp_dir), on_init: on_init] end + describe "errors" do + test "emitted on crash during initialization", + %{tmp_dir: tmp_dir, logger: logger, cwd: cwd, on_init: on_init} do + # obvious syntax error + bad_mix_exs = String.replace(mix_exs(), "defmodule", "") + File.write!(Path.join(tmp_dir, "mix.exs"), bad_mix_exs) + + start_supervised!({Registry, keys: :duplicate, name: RuntimeTest.Registry}) + + tvisor = start_supervised!(Task.Supervisor) + + start_supervised!( + {Runtime, + task_supervisor: tvisor, + name: "my_proj", + on_initialized: on_init, + working_dir: cwd, + uri: "file://#{cwd}", + parent: self(), + logger: logger, + db: :some_db, + registry: RuntimeTest.Registry}, + restart: :temporary + ) + + assert_receive {:error, {:port_down, :normal}} + + assert_receive {:log, :log, log_msg} + assert log_msg =~ "syntax error" + + assert_receive {:log, :error, error_msg} + assert error_msg =~ "{:shutdown, {:port_down, :normal}}" + end + + test "emitted on crash after initialization", + %{logger: logger, cwd: cwd, on_init: on_init} do + start_supervised!({Registry, keys: :duplicate, name: RuntimeTest.Registry}) + + tvisor = start_supervised!(Task.Supervisor) + + pid = + start_supervised!( + {Runtime, + task_supervisor: tvisor, + name: "my_proj", + on_initialized: on_init, + working_dir: cwd, + uri: "file://#{cwd}", + parent: self(), + logger: logger, + db: :some_db, + registry: RuntimeTest.Registry}, + restart: :temporary + ) + + assert_receive :ready + + assert {:ok, {:badrpc, :nodedown}} = Runtime.call(pid, {System, :halt, [1]}) + + assert_receive {:log, :warning, warning_msg} + assert warning_msg =~ ~r"Connected node [^ ]+ is down. Exiting my_proj runtime." + + assert_receive {:log, :log, "The runtime for my_proj has successfully shut down."} + end + end + describe "call/2" do - test "responds with an ok tuple", %{logger: logger, cwd: cwd, on_init: on_init} do + test "responds with an ok tuple if the runtime has initialized", + %{logger: logger, cwd: cwd, on_init: on_init} do start_supervised!({Registry, keys: :duplicate, name: RuntimeTest.Registry}) tvisor = start_supervised!(Task.Supervisor) @@ -68,7 +135,7 @@ defmodule NextLs.RuntimeTest do assert {:ok, "\"hi\""} = Runtime.call(pid, {Kernel, :inspect, ["hi"]}) end - test "responds with an error when the runtime isn't ready", + test "responds with an error when the runtime hasn't initialized", %{logger: logger, cwd: cwd, on_init: on_init} do start_supervised!({Registry, keys: :duplicate, name: RuntimeTest.Registry}) @@ -148,39 +215,6 @@ defmodule NextLs.RuntimeTest do assert [] == Runtime.compile(pid) end - test "emits errors when runtime compilation fails", - %{tmp_dir: tmp_dir, logger: logger, cwd: cwd, on_init: on_init} do - # obvious syntax error - bad_mix_exs = String.replace(mix_exs(), "defmodule", "") - File.write!(Path.join(tmp_dir, "mix.exs"), bad_mix_exs) - - start_supervised!({Registry, keys: :duplicate, name: RuntimeTest.Registry}) - - tvisor = start_supervised!(Task.Supervisor) - - start_supervised!( - {Runtime, - task_supervisor: tvisor, - name: "my_proj", - on_initialized: on_init, - working_dir: cwd, - uri: "file://#{cwd}", - parent: self(), - logger: logger, - db: :some_db, - registry: RuntimeTest.Registry}, - restart: :temporary - ) - - assert_receive {:error, {:port_down, :normal}} - - assert_receive {:log, :log, log_msg} - assert log_msg =~ "syntax error" - - assert_receive {:log, :error, error_msg} - assert error_msg =~ "{:shutdown, {:port_down, :normal}}" - end - test "responds with an error when the runtime isn't ready", %{logger: logger, cwd: cwd, on_init: on_init} do start_supervised!({Registry, keys: :duplicate, name: RuntimeTest.Registry}) diff --git a/test/next_ls/workspaces_test.exs b/test/next_ls/workspaces_test.exs index af5189db..dcc96894 100644 --- a/test/next_ls/workspaces_test.exs +++ b/test/next_ls/workspaces_test.exs @@ -89,7 +89,7 @@ defmodule NextLS.WorkspacesTest do } }) - message = "[NextLS] The runtime for #{context.module}-proj_two has successfully shutdown." + message = "[NextLS] The runtime for #{context.module}-proj_two has successfully shut down." assert_notification "window/logMessage", %{ "message" => ^message From 83e1404bbe1a476c94b0cdd2ac828e80bfbac303 Mon Sep 17 00:00:00 2001 From: Zach Allaun Date: Sat, 12 Aug 2023 14:55:10 -0400 Subject: [PATCH 6/9] fix(runtime): ensure that on_initialized is called with error before shutting down runtime --- lib/next_ls/runtime.ex | 15 ++++++++------- test/next_ls/runtime_test.exs | 10 ++++------ 2 files changed, 12 insertions(+), 13 deletions(-) diff --git a/lib/next_ls/runtime.ex b/lib/next_ls/runtime.ex index a295cd80..60b03050 100644 --- a/lib/next_ls/runtime.ex +++ b/lib/next_ls/runtime.ex @@ -235,14 +235,12 @@ defmodule NextLS.Runtime do {:noreply, %{state | compiler_ref: nil}} end - def handle_info({:DOWN, _, :port, port, reason}, %{port: port} = state) do - error = {:port_down, reason} - + def handle_info({:DOWN, _, :port, port, _}, %{port: port} = state) do unless is_ready(state) do - state.on_initialized.({:error, error}) + state.on_initialized.({:error, :portdown}) end - {:stop, {:shutdown, error}, state} + {:stop, {:shutdown, :portdown}, state} end def handle_info({:cancel, error}, state) do @@ -257,8 +255,11 @@ defmodule NextLS.Runtime do end def handle_info({:nodedown, node}, %{node: node} = state) do - NextLS.Logger.warning(state.logger, "Connected node #{node} is down. Exiting #{state.name} runtime.") - {:stop, :shutdown, state} + unless is_ready(state) do + state.on_initialized.({:error, :nodedown}) + end + + {:stop, {:shutdown, :nodedown}, state} end def handle_info({port, {:data, data}}, %{port: port} = state) do diff --git a/test/next_ls/runtime_test.exs b/test/next_ls/runtime_test.exs index c4e2330e..33c02aa4 100644 --- a/test/next_ls/runtime_test.exs +++ b/test/next_ls/runtime_test.exs @@ -67,13 +67,13 @@ defmodule NextLs.RuntimeTest do restart: :temporary ) - assert_receive {:error, {:port_down, :normal}} + assert_receive {:error, :portdown} assert_receive {:log, :log, log_msg} assert log_msg =~ "syntax error" assert_receive {:log, :error, error_msg} - assert error_msg =~ "{:shutdown, {:port_down, :normal}}" + assert error_msg =~ "{:shutdown, :portdown}" end test "emitted on crash after initialization", @@ -101,10 +101,8 @@ defmodule NextLs.RuntimeTest do assert {:ok, {:badrpc, :nodedown}} = Runtime.call(pid, {System, :halt, [1]}) - assert_receive {:log, :warning, warning_msg} - assert warning_msg =~ ~r"Connected node [^ ]+ is down. Exiting my_proj runtime." - - assert_receive {:log, :log, "The runtime for my_proj has successfully shut down."} + assert_receive {:log, :error, error_msg} + assert error_msg =~ "{:shutdown, :nodedown}" end end From 363387468455198a6ef4314b4e05fe201364b5b0 Mon Sep 17 00:00:00 2001 From: Zach Allaun Date: Sat, 12 Aug 2023 15:11:26 -0400 Subject: [PATCH 7/9] fix(test): flush msgs after tests to eliminate order-dependency --- test/next_ls/runtime_test.exs | 10 ++++++++++ 1 file changed, 10 insertions(+) diff --git a/test/next_ls/runtime_test.exs b/test/next_ls/runtime_test.exs index 33c02aa4..3f8cd488 100644 --- a/test/next_ls/runtime_test.exs +++ b/test/next_ls/runtime_test.exs @@ -39,6 +39,8 @@ defmodule NextLs.RuntimeTest do on_init = fn msg -> send(me, msg) end + on_exit(&flush_messages/0) + [logger: logger, cwd: Path.absname(tmp_dir), on_init: on_init] end @@ -238,4 +240,12 @@ defmodule NextLs.RuntimeTest do assert {:error, :not_ready} = Runtime.compile(pid) end end + + defp flush_messages do + receive do + _ -> flush_messages() + after + 0 -> :ok + end + end end From 6b90c5042c01530e73249c47ec85076790910af0 Mon Sep 17 00:00:00 2001 From: Zach Allaun Date: Sat, 12 Aug 2023 18:25:09 -0400 Subject: [PATCH 8/9] fix(runtime): remove dead code --- lib/next_ls/runtime.ex | 4 ---- 1 file changed, 4 deletions(-) diff --git a/lib/next_ls/runtime.ex b/lib/next_ls/runtime.ex index 60b03050..c35a952e 100644 --- a/lib/next_ls/runtime.ex +++ b/lib/next_ls/runtime.ex @@ -255,10 +255,6 @@ defmodule NextLS.Runtime do end def handle_info({:nodedown, node}, %{node: node} = state) do - unless is_ready(state) do - state.on_initialized.({:error, :nodedown}) - end - {:stop, {:shutdown, :nodedown}, state} end From 0f5234f8ad448cc2e66c86ddbd5797d81808c6f9 Mon Sep 17 00:00:00 2001 From: Mitchell Hanberg Date: Sat, 12 Aug 2023 20:10:58 -0400 Subject: [PATCH 9/9] format --- test/next_ls/runtime_test.exs | 6 ++---- 1 file changed, 2 insertions(+), 4 deletions(-) diff --git a/test/next_ls/runtime_test.exs b/test/next_ls/runtime_test.exs index 3f8cd488..a61acc68 100644 --- a/test/next_ls/runtime_test.exs +++ b/test/next_ls/runtime_test.exs @@ -135,8 +135,7 @@ defmodule NextLs.RuntimeTest do assert {:ok, "\"hi\""} = Runtime.call(pid, {Kernel, :inspect, ["hi"]}) end - test "responds with an error when the runtime hasn't initialized", - %{logger: logger, cwd: cwd, on_init: on_init} do + test "responds with an error when the runtime hasn't initialized", %{logger: logger, cwd: cwd, on_init: on_init} do start_supervised!({Registry, keys: :duplicate, name: RuntimeTest.Registry}) tvisor = start_supervised!(Task.Supervisor) @@ -215,8 +214,7 @@ defmodule NextLs.RuntimeTest do assert [] == Runtime.compile(pid) end - test "responds with an error when the runtime isn't ready", - %{logger: logger, cwd: cwd, on_init: on_init} do + test "responds with an error when the runtime isn't ready", %{logger: logger, cwd: cwd, on_init: on_init} do start_supervised!({Registry, keys: :duplicate, name: RuntimeTest.Registry}) tvisor = start_supervised!(Task.Supervisor)