Logger freezes if one of it's backend crashes

[rahuljayaraman]

Logger seems to deadlock if it enters into this state

• One of it's backend has crashed and
• No. of messages in it's queue has gone past sync_threshold and
• handle_otp_reports in turned on

In such cases,

1. Logger calls gen_event,
2. There's a crash
3. gen_event calls logger to report termination.
4. But logger is in sync mode.

Environment

• elixir 1.9.x, erlang 22
• Operating system: macOS catalina 10.15.6

Current behavior

Can reproduce this on 1.9.x, 1.10.x and 1.11
https://github.com/rahuljayaraman/logger_backend_crash

config :logger,
  backends: [
    LoggerBackendCrash
  ],
  handle_otp_reports: true,
  sync_threshold: 10

defmodule LoggerBackendCrash do
  @behaviour :gen_event

  @impl true
  def init(_) do
    {:ok, []}
  end

  @impl true
  def handle_call(_, _) do
    raise "handle_call_error"
    {:ok, []}
  end

  @impl true
  def handle_event(_, _) do
    raise "handle_event_error"
    {:ok, []}
  end

  @impl true
  def handle_info(_, _) do
    {:ok, []}
  end
end

Enum.each(1..20, fn cnt ->
  Logger.info("#{cnt}")
end)

Stack Trace

stacktrace:
  (stdlib) gen.erl:167: :gen.do_call/4
  (stdlib) gen_event.erl:239: :gen_event.rpc/2
  (logger) lib/logger.ex:692: Logger.__do_log__/3

Processes

Messages

Logger is in waiting state

Stack trace for logger.

Expected behavior

Logger should not deadlock.

[rahuljayaraman]

Perhaps solution could involve some sort of deadlock detection in Logger.Handler?

  defp can_deadlock?(), do: self() == whereis(Logger)

Assumes gen_event.report_terminate and Logger.Handler.log/2 is called in the same process.