LoggerHandlerKit.Act (Logger Handler Kit v0.1.0)

Functions that trigger log events.

The main purpose of these functions is to serve as inspiration and examples of test cases. They should be usable directly, but users are expected to go beyond them sooner rather than later. This is also the reason why they are not customizable and not DRY. Ultimately, you should be able to understand what's going on by looking at the source code with minimal jumping throughout the code base.

Each function represents a case of interest, potentially with different flavors to highlight various cases.

The functions are divided into three groups: Basic, OTP, and SASL.

Basic

These cases focus on log messages a logger handler might encounter. For all cases here, the logger handler will execute in the same process as the test. The complexity comes from the diversity of data types. It's a good idea to make sure your logger handler can handle and format all of these.

OTP

These cases focus on reports that become relevant once OTP is involved. Consequently, the process where logger handler is called is likely different from the test process, which makes test setup more involved and makes ownership important. This is also when Logger Translator becomes relevant, as a lot of OTP errors originate in Erlang and Elixir translates them to look more familiar.

Most of the time, the flow of these logs is governed by the handle_otp_reports Logger option (enabled by default).

A lot of handlers choose to give GenServer errors special treatment, so these cases are a good way to generate some samples.

SASL

What are SASL logs? Whatever they were, they aren't anymore. The concept was deprecated in Erlang/OTP 21. So for Elixir, SASL logs are the logs that will be skipped if the handle_sasl_reports configuration option is set to false, which are all logs which domain matches [:otp, :sasl | _] pattern.

In real life, SASL logs look like reports from supervisors about things that you would expect: child process restarts and such. They are skipped by Elixir by default, but a thorough handler might have an interest in them.

Summary

Basic

chardata_message(flavor \\ :proper)

Chardata is another tricky type that can be passed directly to the Logger.

charlist_message()

Charlists can be passed to Logger functions

io_format()

IO format with data is an exotic type which exists beyond the string or report categorization.

keyword_report()

Keyword lists can be passed to the Logger, and in this case we call it a report.

map_report()

A Map can be passed to the Logger, and in this case we call it a report.

string_message()

The most basic and perhaps most common log message is a simple string passed to one of the Logger functions

struct_report()

Structs are technically maps, but they do not inherit any of the protocols

OTP

bare_process_crash(handler_id, flavor \\ :exception)

Bare process crashes are reported as simple string errors, not reports. Another fun fact is that an exit, even for a weird reason, is not an error and is not logged.

gen_statem_crash(flavor \\ :exception)

:gen_statem crashes are similar to GenServer

genserver_crash(flavor \\ :exception)

GenServer crash is a very common error message. So common, in fact, that a lot of handlers put additional effort into extracting useful information from GenServer reports, such as process name, labels, and client information. Before Elixir 1.19, that was pretty hard to do as Logger.Translator would replace the structured report with an unstructured string, but with 1.19 the reports survive translation.

task_error(atom)

Tasks are a popular way to run asynchronous workloads in Elixir applications.

SASL

genserver_init_crash()

If GenServer.init/1 callback fails, the caller receives an error tuple. Seemingly, nothing exceptional happened... but SASL knows. And will report.

proc_lib_crash(flavor \\ :exception)

Unlike bare process crashes, :proc_lib crashes are reported as reports and with plenty of metadata.

supervisor_progress_report(flavor \\ :failed_to_start_child)

Supervisor module emits quite a few log reports, which are gated behind the handle_sasl_reports configuration option. They come in different log levels as well!

Basic

chardata_message(flavor \\ :proper)

@spec chardata_message(:proper | :improper) :: :ok

Chardata is another tricky type that can be passed directly to the Logger.

Chardata is an arbitrarily nested and potentially improper list.

Logger.info([?H, ["ello", []], 32 | ~c"World"])

Example Test

test "improper chardata message", %{handler_ref: ref} do
  LoggerHandlerKit.Act.chardata_message(:improper)
  LoggerHandlerKit.Assert.assert_logged(ref)
  
  # handler-specific assertions
end

Example Log Event

%{
  meta: %{
    pid: #PID<0.205.0>,
    time: 1744681993743465,
    gl: #PID<0.69.0>,
    domain: [:elixir]
  },
  msg: {:string, [72, ["ello", []], 32, 87, 111, 114, 108, 100]},
  level: :info
}

charlist_message()

Charlists can be passed to Logger functions:

Logger.info(~c"Hello world")

Example Test

test "charlist message", %{handler_ref: ref} do
  LoggerHandlerKit.Act.charlist_message()
  LoggerHandlerKit.Assert.assert_logged(ref)
  
  # handler-specific assertions
end

Example Log Event

%{
  meta: %{
    pid: #PID<0.205.0>,
    time: 1744680216246655,
    gl: #PID<0.69.0>,
    domain: [:elixir]
  },
  msg: {:string, ~c"Hello World"},
  level: :info
}

io_format()

IO format with data is an exotic type which exists beyond the string or report categorization.

IO format is an Erlang term, and in the Elixir world we almost never encounter it. However, no Erlang thing is truly foreign, so handlers must be prepared for it.

:logger.info("Hello ~ts", ["World"])

Example Test

test "io format", %{handler_ref: ref} do
  LoggerHandlerKit.Act.io_format()
  LoggerHandlerKit.Assert.assert_logged(ref)

  # handler-specific assertions
end

Example Log Event

%{
  meta: %{pid: #PID<0.204.0>, time: 1744766862567895, gl: #PID<0.69.0>},
  msg: {"Hello ~ts", ["World"]},
  level: :info
}

keyword_report()

Keyword lists can be passed to the Logger, and in this case we call it a report.

Logger.info([hello: "world"])

Example Test

test "keyword report", %{handler_ref: ref} do
  LoggerHandlerKit.Act.keyword_report()
  LoggerHandlerKit.Assert.assert_logged(ref)
  
  # handler-specific assertions
end

Example Log Event

%{
  meta: %{
    pid: #PID<0.191.0>,
    time: 1744682416540252,
    gl: #PID<0.69.0>,
    domain: [:elixir]
  },
  msg: {:report, [hello: "world"]},
  level: :info
}

map_report()

A Map can be passed to the Logger, and in this case we call it a report.

Logger.info(%{hello: "world"})

Example Test

test "map report", %{handler_ref: ref} do
  LoggerHandlerKit.Act.map_report()
  LoggerHandlerKit.Assert.assert_logged(ref)
  
  # handler-specific assertions
end

Example Log Event

%{
  meta: %{
    pid: #PID<0.191.0>,
    time: 1744683131714605,
    gl: #PID<0.69.0>,
    domain: [:elixir]
  },
  msg: {:report, %{hello: "world"}},
  level: :info
}

string_message()

The most basic and perhaps most common log message is a simple string passed to one of the Logger functions:

Logger.info("Hello World")

Example Test

test "string message", %{handler_ref: ref} do
  LoggerHandlerKit.Act.string_message()
  LoggerHandlerKit.Assert.assert_logged(ref)
  
  # handler-specific assertions
end

Example Log Event

%{
  meta: %{
    pid: #PID<0.218.0>,
    time: 1744679377402910,
    gl: #PID<0.69.0>,
    domain: [:elixir]
  },
  msg: {:string, "Hello World"},
  level: :info
}

struct_report()

Structs are technically maps, but they do not inherit any of the protocols

Famously, the lack of protocol implementation is what makes it hard to dump structs to JSON.

Example Test

test "struct report", %{handler_ref: ref} do
  LoggerHandlerKit.Act.struct_report()
  LoggerHandlerKit.Assert.assert_logged(ref)

  # handler-specific assertions
end

Example Log Event

%{
  meta: %{
    pid: #PID<0.204.0>,
    time: 1744768094816278,
    gl: #PID<0.69.0>,
    domain: [:elixir]
  },
  msg: {:report, %LoggerHandlerKit.FakeStruct{hello: "world"}},
  level: :info
}

OTP

bare_process_crash(handler_id, flavor \\ :exception)

@spec bare_process_crash(handler_id :: :logger.handler_id(), :exception | :throw) ::
  :ok

Bare process crashes are reported as simple string errors, not reports. Another fun fact is that an exit, even for a weird reason, is not an error and is not logged.

Example Test

test "bare process crash exception", %{handler_id: handler_id, handler_ref: ref} do
  LoggerHandlerKit.Act.bare_process_crash(handler_id, :exception)
  LoggerHandlerKit.Assert.assert_logged(ref)

  # handler-specific assertions
end

Example Log Event

%{
  meta: %{
    error_logger: %{emulator: true, tag: :error},
    pid: #PID<0.214.0>,
    time: 1745101176502155,
    gl: #PID<0.69.0>,
    crash_reason: {%RuntimeError{message: "oops"},
     [
       {LoggerHandlerKit.Act, :"-bare_process_crash/1-fun-0-", 0,
        [
          file: ~c"lib/logger_handler_kit/act.ex",
          line: 1106,
          error_info: %{module: Exception}
        ]}
     ]}
  },
  msg: {:string,
   [
     "Process ",
     "#PID<0.214.0>",
     " raised an exception",
     10,
     "** (RuntimeError) oops",
     ["
    " |
      "(logger_handler_kit 0.1.0) lib/logger_handler_kit/act.ex:1106: anonymous fn/0 in LoggerHandlerKit.Act.bare_process_crash/1"]
   ]},
  level: :error
}

gen_statem_crash(flavor \\ :exception)

@spec gen_statem_crash(:exception | :exit | :throw) :: :ok

:gen_statem crashes are similar to GenServer

Example Test

test "gen_statem crash exception", %{handler_ref: ref} do
  LoggerHandlerKit.Act.gen_statem_crash()
  LoggerHandlerKit.Assert.assert_logged(ref)

  # handler-specific assertions
end

Example Log Event (< 1.19)

%{
  meta: %{
    error_logger: %{tag: :error, report_cb: &:gen_statem.format_log/1},
    line: 4975,
    pid: #PID<0.321.0>,
    time: 1745097781898702,
    file: ~c"gen_statem.erl",
    gl: #PID<0.69.0>,
    domain: [:otp],
    report_cb: &:gen_statem.format_log/2,
    mfa: {:gen_statem, :error_info, 7},
    crash_reason: {%RuntimeError{message: "oops"},
     [
       {LoggerHandlerKit.Act, :"-gen_statem_crash/0-fun-0-", 0,
        [
          file: ~c"lib/logger_handler_kit/act.ex",
          line: 875,
          error_info: %{module: Exception}
        ]},
       {:gen_statem, :loop_state_callback, 11,
        [file: ~c"gen_statem.erl", line: 3735]},
       {:proc_lib, :init_p_do_apply, 3, [file: ~c"proc_lib.erl", line: 329]}
     ]}
  },
  msg: {:string,
   [
     [
       ":gen_statem ",
       "#PID<0.321.0>",
       " terminating",
       [
         [10 | "** (RuntimeError) oops"],
         ["
    " |
          "(logger_handler_kit 0.1.0) lib/logger_handler_kit/act.ex:875: anonymous fn/0 in LoggerHandlerKit.Act.gen_statem_crash/0"],
         ["
    " |
          "(stdlib 6.2.1) gen_statem.erl:3735: :gen_statem.loop_state_callback/11"],
         ["
    " |
          "(stdlib 6.2.1) proc_lib.erl:329: :proc_lib.init_p_do_apply/3"]
       ],
       [],
       "
Queue: [{{:call, {#PID<0.312.0>, #Reference<0.4279064375.3240624134.253706>}}, {:run, #Function<0.101033180/0 in LoggerHandlerKit.Act.gen_statem_crash/0>}}]",
       "
Postponed: []"
     ],
     "
State: ",
     "{:started, nil}",
     "
Callback mode: ",
     ":state_functions, state_enter: false",
     "
Client ",
     "#PID<0.312.0>",
     " is alive
",
     ["
    " | "(stdlib 6.2.1) gen.erl:241: :gen.do_call/4"],
     ["
    " | "(stdlib 6.2.1) gen_statem.erl:3250: :gen_statem.call/3"],
     ["
    " |
      "(logger_handler_kit 0.1.0) lib/logger_handler_kit/act.ex:871: LoggerHandlerKit.Act.gen_statem_crash/0"],
     ["
    " |
      "test/default_logger_test.exs:243: LoggerHandlerKit.DefaultLoggerTest."test Advanced gen_statem crash exception"/1"],
     ["
    " |
      "(ex_unit 1.18.3) lib/ex_unit/runner.ex:511: ExUnit.Runner.exec_test/2"],
     ["
    " |
      "(ex_unit 1.18.3) lib/ex_unit/capture_log.ex:113: ExUnit.CaptureLog.with_log/2"],
     ["
    " |
      "(ex_unit 1.18.3) lib/ex_unit/runner.ex:460: anonymous fn/3 in ExUnit.Runner.maybe_capture_log/3"],
     ["
    " | "(stdlib 6.2.1) timer.erl:595: :timer.tc/2"],
     ["
    " |
      "(ex_unit 1.18.3) lib/ex_unit/runner.ex:433: anonymous fn/6 in ExUnit.Runner.spawn_test_monitor/4"]
   ]},
  level: :error
}

Example Log Event (1.19+)

%{
  meta: %{
    error_logger: %{tag: :error, report_cb: &:gen_statem.format_log/1},
    line: 4975,
    pid: #PID<0.222.0>,
    time: 1745097734784539,
    file: ~c"gen_statem.erl",
    gl: #PID<0.69.0>,
    domain: [:otp],
    report_cb: &Logger.Utils.translated_cb/1,
    mfa: {:gen_statem, :error_info, 7},
    crash_reason: {%RuntimeError{message: "oops"},
     [
       {LoggerHandlerKit.Act, :"-gen_statem_crash/0-fun-0-", 0,
        [
          file: ~c"lib/logger_handler_kit/act.ex",
          line: 843,
          error_info: %{module: Exception}
        ]},
       {:gen_statem, :loop_state_callback, 11,
        [file: ~c"gen_statem.erl", line: 3735]},
       {:proc_lib, :init_p_do_apply, 3, [file: ~c"proc_lib.erl", line: 329]}
     ]}
  },
  msg: {:report,
   %{
     label: {:gen_statem, :terminate},
     name: #PID<0.222.0>,
     reason: {:error, %RuntimeError{message: "oops"},
      [
        {LoggerHandlerKit.Act, :"-gen_statem_crash/0-fun-0-", 0,
         [
           file: ~c"lib/logger_handler_kit/act.ex",
           line: 843,
           error_info: %{module: Exception}
         ]},
        {:gen_statem, :loop_state_callback, 11,
         [file: ~c"gen_statem.erl", line: 3735]},
        {:proc_lib, :init_p_do_apply, 3, [file: ~c"proc_lib.erl", line: 329]}
      ]},
     log: [],
     state: {:started, nil},
     queue: [
       {{:call, {#PID<0.211.0>, #Reference<0.1625241344.3509321731.89483>}},
        {:run,
         #Function<0.101033180/0 in LoggerHandlerKit.Act.gen_statem_crash/0>}}
     ],
     modules: [LoggerHandlerKit.GenStatem],
     process_label: :undefined,
     client_info: {#PID<0.211.0>,
      {#PID<0.211.0>,
       [
         {:gen, :do_call, 4, [file: ~c"gen.erl", line: 241]},
         {:gen_statem, :call, 3, [file: ~c"gen_statem.erl", line: 3250]},
         {LoggerHandlerKit.Act, :gen_statem_crash, 0,
          [file: ~c"lib/logger_handler_kit/act.ex", line: 839]},
         {LoggerHandlerKit.DefaultLoggerTest,
          :"test Advanced gen_statem crash exception", 1,
          [file: ~c"test/default_logger_test.exs", line: 243]},
         {ExUnit.Runner, :exec_test, 2,
          [file: ~c"lib/ex_unit/runner.ex", line: 515]},
         {ExUnit.CaptureLog, :with_log, 2,
          [file: ~c"lib/ex_unit/capture_log.ex", line: 117]},
         {ExUnit.Runner, :"-maybe_capture_log/3-fun-0-", 3,
          [file: ~c"lib/ex_unit/runner.ex", line: 464]},
         {:timer, :tc, 2, [file: ~c"timer.erl", line: 595]},
         {ExUnit.Runner, :"-spawn_test_monitor/4-fun-1-", 6,
          [file: ~c"lib/ex_unit/runner.ex", line: 437]}
       ]}},
     callback_mode: :state_functions,
     postponed: [],
     timeouts: {0, []},
     state_enter: false,
     elixir_translation: [...]
     ]
   }},
  level: :error
}

genserver_crash(flavor \\ :exception)

@spec genserver_crash(
  :exception
  | :exit
  | :exit_with_struct
  | :throw
  | :local_name
  | :global_name
  | :process_label
  | :named_client
  | :dead_client
  | :no_client
) :: :ok

Example Test

test "genserver crash exception", %{handler_ref: ref} do
  LoggerHandlerKit.Act.genserver_crash(:exception)
  LoggerHandlerKit.Assert.assert_logged(ref)
  
  # handler-specific assertions
end

Example Log Event (< 1.19)

%{
  meta: %{
    error_logger: %{tag: :error, report_cb: &:gen_server.format_log/1},
    line: 2646,
    pid: #PID<0.316.0>,
    time: 1744685313255062,
    file: ~c"gen_server.erl",
    gl: #PID<0.69.0>,
    domain: [:otp],
    mfa: {:gen_server, :error_info, 8},
    report_cb: &:gen_server.format_log/2,
    crash_reason: {%RuntimeError{message: "oops"},
     [
       {LoggerHandlerKit.Act, :"-genserver_crash/0-fun-0-", 0,
        [
          file: ~c"lib/logger_handler_kit/act.ex",
          line: 319,
          error_info: %{module: Exception}
        ]},
       {:gen_server, :try_handle_call, 4,
        [file: ~c"gen_server.erl", line: 2381]},
       {:gen_server, :handle_msg, 6, [file: ~c"gen_server.erl", line: 2410]},
       {:proc_lib, :init_p_do_apply, 3, [file: ~c"proc_lib.erl", line: 329]}
     ]}
  },
  msg: {:string,
   [
     [
       "GenServer ",
       "#PID<0.316.0>",
       " terminating",
       [
         [10 | "** (RuntimeError) oops"],
         ["
    " |
          "(logger_handler_kit 0.1.0) lib/logger_handler_kit/act.ex:319: anonymous fn/0 in LoggerHandlerKit.Act.genserver_crash/0"],
         ["
    " |
          "(stdlib 6.2.1) gen_server.erl:2381: :gen_server.try_handle_call/4"],
         ["
    " |
          "(stdlib 6.2.1) gen_server.erl:2410: :gen_server.handle_msg/6"],
         ["
    " |
          "(stdlib 6.2.1) proc_lib.erl:329: :proc_lib.init_p_do_apply/3"]
       ],
       [],
       "
Last message",
       [" (from ", "#PID<0.307.0>", ")"],
       ": ",
       "{:run, #Function<0.66655897/0 in LoggerHandlerKit.Act.genserver_crash/0>}"
     ],
     "
State: ",
     "nil",
     "
Client ",
     "#PID<0.307.0>",
     " is alive
",
     ["
    " | "(stdlib 6.2.1) gen.erl:260: :gen.do_call/4"],
     ["
    " | "(elixir 1.18.3) lib/gen_server.ex:1125: GenServer.call/3"],
     ["
    " |
      "(logger_handler_kit 0.1.0) lib/logger_handler_kit/act.ex:319: LoggerHandlerKit.Act.genserver_crash/0"],
     ["
    " |
      "test/default_logger_test.exs:85: LoggerHandlerKit.DefaultLoggerTest."test Advanced genserver crash"/1"],
     ["
    " |
      "(ex_unit 1.18.3) lib/ex_unit/runner.ex:511: ExUnit.Runner.exec_test/2"],
     ["
    " |
      "(ex_unit 1.18.3) lib/ex_unit/capture_log.ex:113: ExUnit.CaptureLog.with_log/2"],
     ["
    " |
      "(ex_unit 1.18.3) lib/ex_unit/runner.ex:460: anonymous fn/3 in ExUnit.Runner.maybe_capture_log/3"],
     ["
    " | "(stdlib 6.2.1) timer.erl:595: :timer.tc/2"],
     ["
    " |
      "(ex_unit 1.18.3) lib/ex_unit/runner.ex:433: anonymous fn/6 in ExUnit.Runner.spawn_test_monitor/4"]
   ]},
  level: :error
}

Example Log Event (1.19+)

%{
  meta: %{
    error_logger: %{tag: :error, report_cb: &:gen_server.format_log/1},
    line: 2646,
    pid: #PID<0.203.0>,
    time: 1744684762852118,
    file: ~c"gen_server.erl",
    gl: #PID<0.69.0>,
    domain: [:otp],
    report_cb: &Logger.Utils.translated_cb/1,
    mfa: {:gen_server, :error_info, 8},
    crash_reason: {%RuntimeError{message: "oops"},
     [
       {LoggerHandlerKit.Act, :"-genserver_crash/0-fun-0-", 0,
        [
          file: ~c"lib/logger_handler_kit/act.ex",
          line: 246,
          error_info: %{module: Exception}
        ]},
       {:gen_server, :try_handle_call, 4,
        [file: ~c"gen_server.erl", line: 2381]},
       {:gen_server, :handle_msg, 6, [file: ~c"gen_server.erl", line: 2410]},
       {:proc_lib, :init_p_do_apply, 3, [file: ~c"proc_lib.erl", line: 329]}
     ]}
  },
  msg: {:report,
   %{
     label: {:gen_server, :terminate},
     name: #PID<0.203.0>,
     reason: {%RuntimeError{message: "oops"},
      [
        {LoggerHandlerKit.Act, :"-genserver_crash/0-fun-0-", 0,
         [
           file: ~c"lib/logger_handler_kit/act.ex",
           line: 246,
           error_info: %{module: Exception}
         ]},
        {:gen_server, :try_handle_call, 4,
         [file: ~c"gen_server.erl", line: 2381]},
        {:gen_server, :handle_msg, 6, [file: ~c"gen_server.erl", line: 2410]},
        {:proc_lib, :init_p_do_apply, 3, [file: ~c"proc_lib.erl", line: 329]}
      ]},
     log: [],
     state: nil,
     client_info: {#PID<0.192.0>,
      {#PID<0.192.0>,
       [
         {:gen, :do_call, 4, [file: ~c"gen.erl", line: 260]},
         {GenServer, :call, 3, [file: ~c"lib/gen_server.ex", line: 1139]},
         {LoggerHandlerKit.Act, :genserver_crash, 0,
          [file: ~c"lib/logger_handler_kit/act.ex", line: 246]},
         {LoggerHandlerKit.DefaultLoggerTest, :"test Advanced genserver crash",
          1, [file: ~c"test/default_logger_test.exs", line: 85]},
         {ExUnit.Runner, :exec_test, 2,
          [file: ~c"lib/ex_unit/runner.ex", line: 515]},
         {ExUnit.CaptureLog, :with_log, 2,
          [file: ~c"lib/ex_unit/capture_log.ex", line: 117]},
         {ExUnit.Runner, :"-maybe_capture_log/3-fun-0-", 3,
          [file: ~c"lib/ex_unit/runner.ex", line: 464]},
         {:timer, :tc, 2, [file: ~c"timer.erl", line: 595]},
         {ExUnit.Runner, :"-spawn_test_monitor/4-fun-1-", 6,
          [file: ~c"lib/ex_unit/runner.ex", line: 437]}
       ]}},
     last_message: {:run,
      #Function<0.66655897/0 in LoggerHandlerKit.Act.genserver_crash/0>},
     process_label: :undefined,
     elixir_translation: [ ... ]
   }},
  level: :error
}

task_error(atom)

@spec task_error(:exception | :exit | :throw | :undefined) :: :ok

Tasks are a popular way to run asynchronous workloads in Elixir applications.

Tasks are special in that they break some rules. First of all, technically Task errors are reports and include a special report_cb callback as per the Erlang convention. However, usually this callback is not offered a chance to shine as Task errors are translated by Logger.Translator. This means that Elixir defines 2 ways of formatting Task reports: in the Task module itself, and in the Logger.Translator. In the majority of cases we see the output of the latter. This is not particularly important for handlers, but it's a fun fact nevertheless.

Example Test

test "task error exception", %{handler_ref: ref} do
  LoggerHandlerKit.Act.task_error(:exception)
  LoggerHandlerKit.Assert.assert_logged(ref)

  # handler-specific assertions
end

Example Log Event (< 1.19)

%{
  meta: %{
    error_logger: %{tag: :error_msg},
    pid: #PID<0.321.0>,
    time: 1744770005614313,
    gl: #PID<0.69.0>,
    domain: [:otp, :elixir],
    report_cb: &Task.Supervised.format_report/1,
    callers: [#PID<0.312.0>],
    crash_reason: {%RuntimeError{message: "oops"},
     [
       {LoggerHandlerKit.Act, :"-task_error/1-fun-0-", 0,
        [
          file: ~c"lib/logger_handler_kit/act.ex",
          line: 671,
          error_info: %{module: Exception}
        ]},
       {Task.Supervised, :invoke_mfa, 2,
        [file: ~c"lib/task/supervised.ex", line: 101]}
     ]}
  },
  msg: {:string,
   [
     "Task #PID<0.321.0> started from #PID<0.312.0> terminating",
     [
       [10 | "** (RuntimeError) oops"],
       ["
    " |
        "(logger_handler_kit 0.1.0) lib/logger_handler_kit/act.ex:671: anonymous fn/0 in LoggerHandlerKit.Act.task_error/1"],
       ["
    " |
        "(elixir 1.18.3) lib/task/supervised.ex:101: Task.Supervised.invoke_mfa/2"]
     ],
     "
Function: #Function<9.52854244/0 in LoggerHandlerKit.Act.task_error/1>",
     "
    Args: []"
   ]},
  level: :error
}

Example Log Event (1.19+)

%{
  meta: %{
    error_logger: %{tag: :error_msg},
    pid: #PID<0.202.0>,
    time: 1744769872184986,
    gl: #PID<0.69.0>,
    domain: [:otp, :elixir],
    report_cb: &Logger.Utils.translated_cb/1,
    callers: [#PID<0.191.0>],
    crash_reason: {%RuntimeError{message: "oops"},
     [
       {LoggerHandlerKit.Act, :"-task_error/1-fun-0-", 0,
        [
          file: ~c"lib/logger_handler_kit/act.ex",
          line: 621,
          error_info: %{module: Exception}
        ]},
       {Task.Supervised, :invoke_mfa, 2,
        [file: ~c"lib/task/supervised.ex", line: 105]}
     ]}
  },
  msg: {:report,
   %{
     label: {Task.Supervisor, :terminating},
     report: %{
       args: [],
       function: #Function<9.61584632/0 in LoggerHandlerKit.Act.task_error/1>,
       name: #PID<0.202.0>,
       reason: {%RuntimeError{message: "oops"},
        [
          {LoggerHandlerKit.Act, :"-task_error/1-fun-0-", 0,
           [
             file: ~c"lib/logger_handler_kit/act.ex",
             line: 621,
             error_info: %{module: Exception}
           ]},
          {Task.Supervised, :invoke_mfa, 2,
           [file: ~c"lib/task/supervised.ex", line: 105]}
        ]},
       process_label: :undefined,
       starter: #PID<0.191.0>
     },
     elixir_translation: [ ... ]
   }},
  level: :error
}

SASL

genserver_init_crash()

If GenServer.init/1 callback fails, the caller receives an error tuple. Seemingly, nothing exceptional happened... but SASL knows. And will report.

defmodule MyGenserver do
  use GenServer

  def init(_), do: raise "oops"
end

{:error, {%RuntimeError{}, _}} = GenServer.start(MyGenserver, nil)

# This log is only sent if handle_sasl_reports is set to true
# 21:54:45.734 [error] Process #PID<0.115.0> terminating
# ** (RuntimeError) oops
#     iex:4: MyGenserver.init/1
#     (stdlib 6.2.1) gen_server.erl:2229: :gen_server.init_it/2
#     (stdlib 6.2.1) gen_server.erl:2184: :gen_server.init_it/6
#     (stdlib 6.2.1) proc_lib.erl:329: :proc_lib.init_p_do_apply/3
# Initial Call: MyGenserver.init/1
# Ancestors: [#PID<0.108.0>, #PID<0.98.0>]
# Message Queue Length: 0
# Messages: []
# Links: []
# Dictionary: []
# Trapping Exits: false
# Status: :running
# Heap Size: 233
# Stack Size: 29
# Reductions: 57

Example Test

test "genserver init crash", %{handler_ref: ref} do
  LoggerHandlerKit.Act.genserver_init_crash()
  LoggerHandlerKit.Assert.assert_logged(ref)

  # handler-specific assertions
end

Example Log Event (< 1.19)

%{
  meta: %{
    error_logger: %{tag: :error_report, type: :crash_report},
    initial_call: {LoggerHandlerKit.GenServer, :init, 1},
    line: 948,
    pid: #PID<0.214.0>,
    time: 1744844942033945,
    file: ~c"proc_lib.erl",
    gl: #PID<0.69.0>,
    domain: [:otp, :sasl],
    logger_formatter: %{title: ~c"CRASH REPORT"},
    mfa: {:proc_lib, :crash_report, 4},
    report_cb: &:proc_lib.report_cb/2,
    ancestors: [#PID<0.205.0>],
    callers: [#PID<0.205.0>],
    crash_reason: {%RuntimeError{message: "oops"},
     [
       {LoggerHandlerKit.Act, :"-genserver_init_crash/0-fun-0-", 0,
        [
          file: ~c"lib/logger_handler_kit/act.ex",
          line: 840,
          error_info: %{module: Exception}
        ]},
       {:gen_server, :init_it, 2, [file: ~c"gen_server.erl", line: 2229]},
       {:gen_server, :init_it, 6, [file: ~c"gen_server.erl", line: 2184]},
       {:proc_lib, :init_p_do_apply, 3, [file: ~c"proc_lib.erl", line: 329]}
     ]}
  },
  msg: {:string,
   [
     "Process ",
     "#PID<0.214.0>",
     " terminating",
     [
       10,
       "** (RuntimeError) oops",
       ["
    " |
        "(logger_handler_kit 0.1.0) lib/logger_handler_kit/act.ex:840: anonymous fn/0 in LoggerHandlerKit.Act.genserver_init_crash/0"],
       ["
    " | "(stdlib 6.2.1) gen_server.erl:2229: :gen_server.init_it/2"],
       ["
    " | "(stdlib 6.2.1) gen_server.erl:2184: :gen_server.init_it/6"],
       ["
    " |
        "(stdlib 6.2.1) proc_lib.erl:329: :proc_lib.init_p_do_apply/3"]
     ],
     [
       ~c"
",
       "Initial Call: ",
       "LoggerHandlerKit.GenServer.init/1",
       ~c"
",
       "Ancestors: ",
       "[#PID<0.205.0>]",
       [~c"
", "Message Queue Length", 58, 32, "0"],
       [~c"
", "Messages", 58, 32, "[]"],
       [~c"
", "Links", 58, 32, "[]"],
       [~c"
", "Dictionary", 58, 32, "["$callers": [#PID<0.205.0>]]"],
       [~c"
", "Trapping Exits", 58, 32, "false"],
       [~c"
", "Status", 58, 32, ":running"],
       [~c"
", "Heap Size", 58, 32, "233"],
       [~c"
", "Stack Size", 58, 32, "29"],
       [~c"
", "Reductions", 58, 32, "72"]
     ],
     []
   ]},
  level: :error
}

Example Log Event (1.19+)

%{
  meta: %{
    error_logger: %{tag: :error_report, type: :crash_report},
    initial_call: {LoggerHandlerKit.GenServer, :init, 1},
    line: 948,
    pid: #PID<0.326.0>,
    time: 1744844985798744,
    file: ~c"proc_lib.erl",
    gl: #PID<0.69.0>,
    domain: [:otp, :sasl],
    logger_formatter: %{title: ~c"CRASH REPORT"},
    mfa: {:proc_lib, :crash_report, 4},
    report_cb: &Logger.Utils.translated_cb/1,
    ancestors: [#PID<0.315.0>],
    callers: [#PID<0.315.0>],
    crash_reason: {%RuntimeError{message: "oops"},
     [
       {LoggerHandlerKit.Act, :"-genserver_init_crash/0-fun-0-", 0,
        [
          file: ~c"lib/logger_handler_kit/act.ex",
          line: 868,
          error_info: %{module: Exception}
        ]},
       {:gen_server, :init_it, 2, [file: ~c"gen_server.erl", line: 2229]},
       {:gen_server, :init_it, 6, [file: ~c"gen_server.erl", line: 2184]},
       {:proc_lib, :init_p_do_apply, 3, [file: ~c"proc_lib.erl", line: 329]}
     ]}
  },
  msg: {:report,
   %{
     label: {:proc_lib, :crash},
     report: [
       [
         initial_call: {LoggerHandlerKit.GenServer, :init, [:Argument__1]},
         pid: #PID<0.326.0>,
         registered_name: [],
         process_label: :undefined,
         error_info: {:error, %RuntimeError{message: "oops"},
          [
            {LoggerHandlerKit.Act, :"-genserver_init_crash/0-fun-0-", 0,
             [
               file: ~c"lib/logger_handler_kit/act.ex",
               line: 868,
               error_info: %{module: Exception}
             ]},
            {:gen_server, :init_it, 2, [file: ~c"gen_server.erl", line: 2229]},
            {:gen_server, :init_it, 6, [file: ~c"gen_server.erl", line: 2184]},
            {:proc_lib, :init_p_do_apply, 3,
             [file: ~c"proc_lib.erl", line: 329]}
          ]},
         ancestors: [#PID<0.315.0>],
         message_queue_len: 0,
         messages: [],
         links: [],
         dictionary: ["$callers": [#PID<0.315.0>]],
         trap_exit: false,
         status: :running,
         heap_size: 233,
         stack_size: 29,
         reductions: 72
       ],
       []
     ],
     elixir_translation: [...]
   }},
  level: :error
}

proc_lib_crash(flavor \\ :exception)

@spec proc_lib_crash(:exception | :exit | :throw) :: :ok

Unlike bare process crashes, :proc_lib crashes are reported as reports and with plenty of metadata.

:proc_lib is an Erlang module used for working with processes that adhere to OTP design principles.

Example Test

test ":proc_lib crash exception", %{handler_ref: ref} do
  LoggerHandlerKit.Act.proc_lib_crash(:exception)
  LoggerHandlerKit.Assert.assert_logged(ref)

  # handler-specific assertions
end

Example Log Event (< 1.19)

%{
  meta: %{
    error_logger: %{tag: :error_report, type: :crash_report},
    initial_call: {LoggerHandlerKit.Act, :"-proc_lib_crash/0-fun-0-", 0},
    line: 948,
    pid: #PID<0.321.0>,
    time: 1745103540970106,
    file: ~c"proc_lib.erl",
    gl: #PID<0.69.0>,
    domain: [:otp, :sasl],
    logger_formatter: %{title: ~c"CRASH REPORT"},
    mfa: {:proc_lib, :crash_report, 4},
    report_cb: &:proc_lib.report_cb/2,
    ancestors: [#PID<0.312.0>],
    callers: [#PID<0.312.0>],
    crash_reason: {%RuntimeError{message: "oops"},
     [
       {LoggerHandlerKit.Act, :"-proc_lib_crash/0-fun-0-", 1,
        [
          file: ~c"lib/logger_handler_kit/act.ex",
          line: 1350,
          error_info: %{module: Exception}
        ]},
       {:proc_lib, :init_p, 3, [file: ~c"proc_lib.erl", line: 313]}
     ]}
  },
  msg: {:string,
   [
     "Process ",
     "#PID<0.321.0>",
     " terminating",
     [
       10,
       "** (RuntimeError) oops",
       ["
    " |
        "(logger_handler_kit 0.1.0) lib/logger_handler_kit/act.ex:1350: anonymous fn/1 in LoggerHandlerKit.Act.proc_lib_crash/0"],
       ["
    " | "(stdlib 6.2.1) proc_lib.erl:313: :proc_lib.init_p/3"]
     ],
     [
       ~c"
",
       "Initial Call: ",
       "anonymous fn/0 in LoggerHandlerKit.Act.proc_lib_crash/0",
       ~c"
",
       "Ancestors: ",
       "[#PID<0.312.0>]",
       [~c"
", "Message Queue Length", 58, 32, "0"],
       [~c"
", "Messages", 58, 32, "[]"],
       [~c"
", "Links", 58, 32, "[]"],
       [~c"
", "Dictionary", 58, 32, "["$callers": [#PID<0.312.0>]]"],
       [~c"
", "Trapping Exits", 58, 32, "false"],
       [~c"
", "Status", 58, 32, ":running"],
       [~c"
", "Heap Size", 58, 32, "376"],
       [~c"
", "Stack Size", 58, 32, "29"],
       [~c"
", "Reductions", 58, 32, "423"]
     ],
     []
   ]},
  level: :error
}

Example Log Event (1.19+)

%{
  meta: %{
    error_logger: %{tag: :error_report, type: :crash_report},
    initial_call: {LoggerHandlerKit.Act, :"-proc_lib_crash/0-fun-0-", 0},
    line: 948,
    pid: #PID<0.215.0>,
    time: 1745103479744344,
    file: ~c"proc_lib.erl",
    gl: #PID<0.69.0>,
    domain: [:otp, :sasl],
    logger_formatter: %{title: ~c"CRASH REPORT"},
    mfa: {:proc_lib, :crash_report, 4},
    report_cb: &Logger.Utils.translated_cb/1,
    ancestors: [#PID<0.204.0>],
    callers: [#PID<0.204.0>],
    crash_reason: {%RuntimeError{message: "oops"},
     [
       {LoggerHandlerKit.Act, :"-proc_lib_crash/0-fun-0-", 1,
        [
          file: ~c"lib/logger_handler_kit/act.ex",
          line: 1355,
          error_info: %{module: Exception}
        ]},
       {:proc_lib, :init_p, 3, [file: ~c"proc_lib.erl", line: 313]}
     ]}
  },
  msg: {:report,
   %{
     label: {:proc_lib, :crash},
     report: [
       [
         initial_call: {LoggerHandlerKit.Act, :"-proc_lib_crash/0-fun-0-", []},
         pid: #PID<0.215.0>,
         registered_name: [],
         process_label: :undefined,
         error_info: {:error, %RuntimeError{message: "oops"},
          [
            {LoggerHandlerKit.Act, :"-proc_lib_crash/0-fun-0-", 1,
             [
               file: ~c"lib/logger_handler_kit/act.ex",
               line: 1355,
               error_info: %{module: Exception}
             ]},
            {:proc_lib, :init_p, 3, [file: ~c"proc_lib.erl", line: 313]}
          ]},
         ancestors: [#PID<0.204.0>],
         message_queue_len: 0,
         messages: [],
         links: [],
         dictionary: ["$callers": [#PID<0.204.0>]],
         trap_exit: false,
         status: :running,
         heap_size: 376,
         stack_size: 29,
         reductions: 429
       ],
       []
     ],
     elixir_translation: [...]
   }},
  level: :error
}

supervisor_progress_report(flavor \\ :failed_to_start_child)

@spec supervisor_progress_report(
  :failed_to_start_child
  | :child_started
  | :child_terminated
) :: :ok

Supervisor module emits quite a few log reports, which are gated behind the handle_sasl_reports configuration option. They come in different log levels as well!

Example Test

test "supervisor progress report failed to start child", %{handler_ref: ref, io_ref: io_ref} do
  LoggerHandlerKit.Act.supervisor_progress_report(:failed_to_start_child)
  LoggerHandlerKit.Assert.assert_logged(ref)

  # handler-specific assertions
end

Example Log Event (< 1.19)

%{
  meta: %{
    error_logger: %{
      tag: :error_report,
      type: :supervisor_report,
      report_cb: &:supervisor.format_log/1
    },
    line: 937,
    pid: #PID<0.200.0>,
    time: 1745204329480468,
    file: ~c"supervisor.erl",
    gl: #PID<0.69.0>,
    domain: [:otp, :sasl],
    logger_formatter: %{title: ~c"SUPERVISOR REPORT"},
    mfa: {:supervisor, :start_children, 2},
    report_cb: &:supervisor.format_log/2
  },
  msg: {:string,
   [
     "Child ",
     ":task",
     " of Supervisor ",
     ["#PID<0.200.0>", " (", "Supervisor.Default", 41],
     32,
     "failed to start",
     "
** (exit) ",
     ":reason",
     "
Start Call: ",
     "LoggerHandlerKit.Helper.run(#Function<26.21775298/0 in LoggerHandlerKit.Act.supervisor_progress_report/1>)",
     ["
Restart: " | ":permanent"],
     [],
     ["
Shutdown: " | "5000"],
     ["
Type: " | ":worker"]
   ]},
  level: :error
}

Example Log Event (1.19+)

%{
  meta: %{
    error_logger: %{
      tag: :error_report,
      type: :supervisor_report,
      report_cb: &:supervisor.format_log/1
    },
    line: 937,
    pid: #PID<0.326.0>,
    time: 1745204485120228,
    file: ~c"supervisor.erl",
    gl: #PID<0.69.0>,
    domain: [:otp, :sasl],
    logger_formatter: %{title: ~c"SUPERVISOR REPORT"},
    mfa: {:supervisor, :start_children, 2},
    report_cb: &Logger.Utils.translated_cb/1
  },
  msg: {:report,
   %{
     label: {:supervisor, :start_error},
     report: [
       supervisor: {#PID<0.326.0>, Supervisor.Default},
       errorContext: :start_error,
       reason: :reason,
       offender: [
         pid: :undefined,
         id: :task,
         mfargs: {LoggerHandlerKit.Helper, :run,
          [#Function<26.30156712/0 in LoggerHandlerKit.Act.supervisor_progress_report/1>]},
         restart_type: :permanent,
         significant: false,
         shutdown: 5000,
         child_type: :worker
       ]
     ],
     elixir_translation: [...]
   }},
  level: :error
}