Skip to content

Fix logger crash when :gen_statem format_status/2 returns non-tuple #13684

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
merged 3 commits into from
Jun 22, 2024
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
4 changes: 1 addition & 3 deletions lib/logger/lib/logger/translator.ex
Original file line number Diff line number Diff line change
Expand Up @@ -298,7 +298,7 @@ defmodule Logger.Translator do
client_info: client,
name: name,
reason: {kind, reason, stack},
state: {state, data},
state: state,
queue: queue,
postponed: postponed,
callback_mode: callback_mode,
Expand Down Expand Up @@ -328,8 +328,6 @@ defmodule Logger.Translator do
msg,
"\nState: ",
inspect(state, inspect_opts),
"\nData: ",
inspect(data, inspect_opts),
"\nCallback mode: ",
"#{inspect(callback_mode, inspect_opts)}, state_enter: #{state_enter?}"
| format_client_info(client)
Expand Down
66 changes: 56 additions & 10 deletions lib/logger/test/logger/translator_test.exs
Original file line number Diff line number Diff line change
Expand Up @@ -100,6 +100,28 @@ defmodule Logger.TranslatorTest do
end
end

defmodule MyGenStatemHandleEvent do
@behaviour :gen_statem

@impl true
def callback_mode, do: :handle_event_function

@impl true
def init(state) do
{:ok, :no_state, state}
end

@impl true
def handle_event({:call, _}, :error, :no_state, _data) do
raise "oops"
end

@impl :gen_statem
def format_status(_opts, [_pdict, _, state]) do
state
end
end

defmodule MyBridge do
@behaviour :supervisor_bridge

Expand Down Expand Up @@ -393,7 +415,7 @@ defmodule Logger.TranslatorTest do
assert {%RuntimeError{message: "oops"}, [_ | _]} = process_metadata[:crash_reason]

refute Map.has_key?(gen_statem_metadata, :initial_call)
assert process_metadata[:initial_call] == {Logger.TranslatorTest.MyGenStatem, :init, 1}
assert process_metadata[:initial_call] == {MyGenStatem, :init, 1}

refute Map.has_key?(gen_statem_metadata, :registered_name)
refute Map.has_key?(process_metadata, :registered_name)
Expand Down Expand Up @@ -445,7 +467,7 @@ defmodule Logger.TranslatorTest do
assert capture_log(:debug, fn ->
catch_exit(:gen_statem.call(pid, :error))
end) =~ """
[:ok, :ok, :ok, ...]
State: {:started, [:ok, ...]}
"""
after
Application.put_env(:logger, :translator_inspect_opts, [])
Expand All @@ -462,8 +484,7 @@ defmodule Logger.TranslatorTest do
.*
Queue: .*
Postponed: \[\]
State: :started
Data: :ok
State: {:started, :ok}
Callback mode: :state_functions, state_enter: false
Client #PID<\d+\.\d+\.\d+> is alive
.*
Expand All @@ -488,8 +509,7 @@ defmodule Logger.TranslatorTest do
.*
Queue: .*
Postponed: \[\]
State: :started
Data: :ok
State: {:started, :ok}
Callback mode: :state_functions, state_enter: false
Client :named_client is alive
.*
Expand All @@ -513,8 +533,7 @@ defmodule Logger.TranslatorTest do
.*
Queue: .*
Postponed: \[\]
State: :started
Data: :ok
State: {:started, :ok}
Callback mode: :state_functions, state_enter: false
Client #PID<\d+\.\d+\.\d+> is dead
"""s
Expand All @@ -533,8 +552,7 @@ defmodule Logger.TranslatorTest do
.*
Queue: .*
Postponed: \[\]
State: :started
Data: :ok
State: {:started, :ok}
Callback mode: :state_functions, state_enter: false
"""s
end
Expand All @@ -552,6 +570,34 @@ defmodule Logger.TranslatorTest do
assert_receive {:event, {:string, ["Process " | _]}, _process_metadata}
end

test "translates :gen_statem crashes when callback_mode is :handle_event_function" do
{:ok, pid} = :gen_statem.start(MyGenStatemHandleEvent, :ok, [])

assert capture_log(:debug, fn ->
catch_exit(:gen_statem.call(pid, :error))
end) =~ ~r"""
\[error\] :gen_statem #PID<\d+\.\d+\.\d+> terminating
\*\* \(RuntimeError\) oops
.*
Queue: .*
Postponed: \[\]
State: :ok
Callback mode: .*, state_enter: false
Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Note: I can't check for callback mode because of erlang/otp#8605

"""s

assert_receive {:event, {:string, [[":gen_statem " <> _ | _] | _]}, gen_statem_metadata}
assert_receive {:event, {:string, ["Process " | _]}, process_metadata}

assert {%RuntimeError{message: "oops"}, [_ | _]} = gen_statem_metadata[:crash_reason]
assert {%RuntimeError{message: "oops"}, [_ | _]} = process_metadata[:crash_reason]

refute Map.has_key?(gen_statem_metadata, :initial_call)
assert process_metadata[:initial_call] == {MyGenStatemHandleEvent, :init, 1}

refute Map.has_key?(gen_statem_metadata, :registered_name)
refute Map.has_key?(process_metadata, :registered_name)
end

test "translates Task crashes" do
{:ok, pid} = Task.start_link(__MODULE__, :task, [self()])
parent = self()
Expand Down