From c56cb67bb2bb5b9b25787b3eb1517eb4b3189c92 Mon Sep 17 00:00:00 2001 From: sabiwara Date: Wed, 6 Mar 2024 09:03:56 +0900 Subject: [PATCH 1/4] Logger logs :process_label if present --- lib/logger/lib/logger.ex | 4 ++++ lib/logger/lib/logger/translator.ex | 6 ++++- lib/logger/test/logger/translator_test.exs | 28 ++++++++++++++++++++++ 3 files changed, 37 insertions(+), 1 deletion(-) diff --git a/lib/logger/lib/logger.ex b/lib/logger/lib/logger.ex index 5432913cead..aad7786ee42 100644 --- a/lib/logger/lib/logger.ex +++ b/lib/logger/lib/logger.ex @@ -119,6 +119,10 @@ defmodule Logger do * `:registered_name` - the process registered name as an atom + * `:process_label` - (available from Erlang/OTP 27+) an arbitrary term + which can be added to a process with `:proc_lib.set_label/1` for + debugging purpose. + * `:domain` - a list of domains for the logged message. For example, all Elixir reports default to `[:elixir]`. Erlang reports may start with `[:otp]` or `[:sasl]` diff --git a/lib/logger/lib/logger/translator.ex b/lib/logger/lib/logger/translator.ex index a3f3be1eb56..07367e1b438 100644 --- a/lib/logger/lib/logger/translator.ex +++ b/lib/logger/lib/logger/translator.ex @@ -459,10 +459,14 @@ defmodule Logger.Translator do [prefix, "Ancestors: ", inspect(ancestors) | crash_info(min_level, debug, prefix)] end - defp crash_info(min_level, [{:process_label, _} | info], prefix) do + defp crash_info(min_level, [{:process_label, :undefined} | info], prefix) do crash_info(min_level, info, prefix) end + defp crash_info(min_level, [{:process_label, label} | debug], prefix) do + [prefix, "Process Label: ", inspect(label) | crash_info(min_level, debug, prefix)] + end + defp crash_info(:debug, debug, prefix) do for {key, value} <- debug do crash_debug(key, value, prefix) diff --git a/lib/logger/test/logger/translator_test.exs b/lib/logger/test/logger/translator_test.exs index 2307d8b8f8e..a0684f35ec7 100644 --- a/lib/logger/test/logger/translator_test.exs +++ b/lib/logger/test/logger/translator_test.exs @@ -530,6 +530,34 @@ defmodule Logger.TranslatorTest do assert {%RuntimeError{message: "oops"}, [_ | _]} = process_metadata[:crash_reason] end + if :erlang.system_info(:otp_release) >= ~c"27" do + test "translates :proc_lib crashes with :process_label" do + fun = fn -> + :proc_lib.set_label({:any, "term"}) + raise "oops" + end + + pid = :proc_lib.spawn_link(__MODULE__, :task, [self(), fun]) + + assert capture_log(:info, fn -> + ref = Process.monitor(pid) + send(pid, :message) + send(pid, :go) + receive do: ({:DOWN, ^ref, _, _, _} -> :ok) + end) =~ ~r""" + \[error\] Process #PID<\d+\.\d+\.\d+> terminating + \*\* \(RuntimeError\) oops + .* + Initial Call: Logger.TranslatorTest.task/2 + Process Label: {:any, \"term\"} + Ancestors: \[#PID<\d+\.\d+\.\d+>\] + """s + + assert_receive {:event, {:string, ["Process " | _]}, process_metadata} + assert {%RuntimeError{message: "oops"}, [_ | _]} = process_metadata[:crash_reason] + end + end + test "translates :proc_lib crashes without initial call" do fun = fn -> Process.delete(:"$initial_call") From bde3efa591c2f50db6f6e9875600fbabb724d56e Mon Sep 17 00:00:00 2001 From: Jean Klingler Date: Wed, 6 Mar 2024 20:44:10 +0900 Subject: [PATCH 2/4] Update lib/logger/lib/logger.ex Co-authored-by: Andrea Leopardi --- lib/logger/lib/logger.ex | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/logger/lib/logger.ex b/lib/logger/lib/logger.ex index aad7786ee42..b569d95010b 100644 --- a/lib/logger/lib/logger.ex +++ b/lib/logger/lib/logger.ex @@ -121,7 +121,7 @@ defmodule Logger do * `:process_label` - (available from Erlang/OTP 27+) an arbitrary term which can be added to a process with `:proc_lib.set_label/1` for - debugging purpose. + debugging purposes. * `:domain` - a list of domains for the logged message. For example, all Elixir reports default to `[:elixir]`. Erlang reports may start From 6abb021433e15e36570ef43f772ad87c046c2d29 Mon Sep 17 00:00:00 2001 From: sabiwara Date: Wed, 6 Mar 2024 20:45:39 +0900 Subject: [PATCH 3/4] Apply suggestion: use @tag skip: --- lib/logger/test/logger/translator_test.exs | 49 +++++++++++----------- 1 file changed, 24 insertions(+), 25 deletions(-) diff --git a/lib/logger/test/logger/translator_test.exs b/lib/logger/test/logger/translator_test.exs index a0684f35ec7..4c2065e4889 100644 --- a/lib/logger/test/logger/translator_test.exs +++ b/lib/logger/test/logger/translator_test.exs @@ -530,32 +530,31 @@ defmodule Logger.TranslatorTest do assert {%RuntimeError{message: "oops"}, [_ | _]} = process_metadata[:crash_reason] end - if :erlang.system_info(:otp_release) >= ~c"27" do - test "translates :proc_lib crashes with :process_label" do - fun = fn -> - :proc_lib.set_label({:any, "term"}) - raise "oops" - end - - pid = :proc_lib.spawn_link(__MODULE__, :task, [self(), fun]) - - assert capture_log(:info, fn -> - ref = Process.monitor(pid) - send(pid, :message) - send(pid, :go) - receive do: ({:DOWN, ^ref, _, _, _} -> :ok) - end) =~ ~r""" - \[error\] Process #PID<\d+\.\d+\.\d+> terminating - \*\* \(RuntimeError\) oops - .* - Initial Call: Logger.TranslatorTest.task/2 - Process Label: {:any, \"term\"} - Ancestors: \[#PID<\d+\.\d+\.\d+>\] - """s - - assert_receive {:event, {:string, ["Process " | _]}, process_metadata} - assert {%RuntimeError{message: "oops"}, [_ | _]} = process_metadata[:crash_reason] + @tag skip: System.otp_release() < "27" + test "translates :proc_lib crashes with :process_label" do + fun = fn -> + :proc_lib.set_label({:any, "term"}) + raise "oops" end + + pid = :proc_lib.spawn_link(__MODULE__, :task, [self(), fun]) + + assert capture_log(:info, fn -> + ref = Process.monitor(pid) + send(pid, :message) + send(pid, :go) + receive do: ({:DOWN, ^ref, _, _, _} -> :ok) + end) =~ ~r""" + \[error\] Process #PID<\d+\.\d+\.\d+> terminating + \*\* \(RuntimeError\) oops + .* + Initial Call: Logger.TranslatorTest.task/2 + Process Label: {:any, \"term\"} + Ancestors: \[#PID<\d+\.\d+\.\d+>\] + """s + + assert_receive {:event, {:string, ["Process " | _]}, process_metadata} + assert {%RuntimeError{message: "oops"}, [_ | _]} = process_metadata[:crash_reason] end test "translates :proc_lib crashes without initial call" do From c3b5b074a4b20930a44d434652b7bd7562ba15fb Mon Sep 17 00:00:00 2001 From: Jean Klingler Date: Wed, 6 Mar 2024 20:47:52 +0900 Subject: [PATCH 4/4] Update lib/logger/lib/logger.ex MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Co-authored-by: José Valim --- lib/logger/lib/logger.ex | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/lib/logger/lib/logger.ex b/lib/logger/lib/logger.ex index b569d95010b..241cd1860bb 100644 --- a/lib/logger/lib/logger.ex +++ b/lib/logger/lib/logger.ex @@ -121,7 +121,7 @@ defmodule Logger do * `:process_label` - (available from Erlang/OTP 27+) an arbitrary term which can be added to a process with `:proc_lib.set_label/1` for - debugging purposes. + debugging purposes * `:domain` - a list of domains for the logged message. For example, all Elixir reports default to `[:elixir]`. Erlang reports may start