Logger backend (#829)

* Expose Appsignal.Logger.log/4

Previously, Appsignal.Logger only exposed the named functions (like
debug/3). Since we need the log/4 function to provide a backend, this
patch eposes it.

* Add Appsignal.Logger.Backend

Appsignal.Logger.Backend is attached to Elixir's logger to send logs to
AppSignal. Use Logger.add_backend/1 to set it up:

    Logger.add_backend({Appsignal.Logger.Backend, "phoenix"})

The second argument in the tuple is the log group name, which could be
"phoenix" for a Phoenix application, for example.

* Add changeset to describe logger backend

> Add Logger backend to redirect Elixir logs to AppSignal.

* Update lib/appsignal/logger/backend.ex

Co-authored-by: Noemi <45180344+unflxw@users.noreply.github.com>

* Use keyword list in Logger.Backend

Instead of taking a string as the log group, take a keyword list with a
single key, for possible extension later.

* Handle :warn warnings in Appsignal.Logger

Deprecated, but still used in older versions of Elixir, warnings named
:warn previously broke the logger. This patch accepts them as warnings.

* Handle unexpected log levels

Although this shouldn't happen, not finding a severity in the list
caused Appsignal.Logger.Backend to crash. This patch adds a rescue
clause to turn everything that doesn't match the list to a severity of
3 (info).

---------

Co-authored-by: Noemi <45180344+unflxw@users.noreply.github.com>

.changesets/add-logger-backend.md

@@ -0,0 +1,6 @@
+---
+bump: "minor"
+type: "add"
+---
+
+Add Logger backend to redirect Elixir logs to AppSignal.

lib/appsignal/logger.ex

@@ -2,16 +2,6 @@ defmodule Appsignal.Logger do
   require Appsignal.Utils
 
   @nif Appsignal.Utils.compile_env(:appsignal, :appsignal_tracer_nif, Appsignal.Nif)
-  @severity %{
-    debug: 2,
-    info: 3,
-    notice: 4,
-    warning: 5,
-    error: 6,
-    critical: 7,
-    alert: 8,
-    emergency: 9
-  }
 
   @type log_level ::
           :debug | :info | :notice | :warning | :error | :critical | :alert | :emergency
@@ -57,15 +47,20 @@ defmodule Appsignal.Logger do
   end
 
   @spec log(log_level(), String.t(), String.t(), %{}) :: :ok
-  defp log(log_level, group, message, metadata) do
-    severity = @severity[log_level]
+  def log(log_level, group, message, metadata) do
     encoded_metadata = Appsignal.Utils.DataEncoder.encode(metadata)
 
-    @nif.log(
-      group,
-      severity,
-      message,
-      encoded_metadata
-    )
+    @nif.log(group, severity(log_level), message, encoded_metadata)
   end
+
+  defp severity(:debug), do: 2
+  defp severity(:info), do: 3
+  defp severity(:notice), do: 4
+  defp severity(:warn), do: 5
+  defp severity(:warning), do: 5
+  defp severity(:error), do: 6
+  defp severity(:critical), do: 7
+  defp severity(:alert), do: 8
+  defp severity(:emergency), do: 9
+  defp severity(_), do: 3
 end

lib/appsignal/logger/backend.ex

@@ -0,0 +1,22 @@
+defmodule Appsignal.Logger.Backend do
+  @behaviour :gen_event
+
+  def init({__MODULE__, options}) do
+    {:ok, Keyword.merge([group: "app"], options)}
+  end
+
+  def handle_event({level, _gl, {Logger, message, _timestamp, metadata}}, options) do
+    Appsignal.Logger.log(
+      level,
+      options[:group],
+      IO.chardata_to_string(message),
+      Enum.into(metadata, %{})
+    )
+
+    {:ok, options}
+  end
+
+  def handle_call(_messsage, options) do
+    {:ok, nil, options}
+  end
+end

test/appsignal/logger/backend_test.exs

@@ -0,0 +1,39 @@
+defmodule Appsignal.Logger.BackendTest do
+  use ExUnit.Case
+
+  setup do
+    start_supervised!(Appsignal.Test.Nif)
+    :ok
+  end
+
+  test "handle_event/2 sends logs to the extension" do
+    Appsignal.Logger.Backend.handle_event(
+      {
+        :info,
+        self(),
+        {
+          Logger,
+          ~c"foo bar baz",
+          {{2023, 2, 23}, {14, 25, 56, 241}},
+          [
+            erl_level: :info,
+            application: :phoenix,
+            domain: [:elixir],
+            file: "lib/phoenix/logger.ex",
+            function: "phoenix_endpoint_start/4",
+            gl: self(),
+            line: 211,
+            mfa: {Phoenix.Logger, :phoenix_endpoint_start, 4},
+            module: Phoenix.Logger,
+            pid: self(),
+            request_id: "F0Z3jGx7KNZWD9gAAAFD",
+            time: 1_677_159_356_241_326
+          ]
+        }
+      },
+      group: "phoenix"
+    )
+
+    assert [{"phoenix", 3, "foo bar baz", _}] = Appsignal.Test.Nif.get!(:log)
+  end
+end

test/appsignal/logger_test.exs

@@ -7,6 +7,34 @@ defmodule Appsignal.LoggerTest do
     :ok
   end
 
+  test "log/4 sends the log calls through the extension" do
+    metadata = %{some: "metadata"}
+
+    Logger.log(:debug, "app", "This is a debug", metadata)
+    Logger.log(:info, "app", "This is an info", metadata)
+    Logger.log(:notice, "app", "This is a notice", metadata)
+    Logger.log(:warning, "app", "This is a warning", metadata)
+    Logger.log(:warn, "app", "This is a warn", metadata)
+    Logger.log(:error, "app", "This is an error", metadata)
+    Logger.log(:critical, "app", "This is a critical", metadata)
+    Logger.log(:alert, "app", "This is an alert", metadata)
+    Logger.log(:emergency, "app", "This is an emergency", metadata)
+    Logger.log(:rhubarb, "app", "This is a... rhubarb?", metadata)
+
+    assert [
+             {"app", 3, "This is a... rhubarb?", _},
+             {"app", 9, "This is an emergency", _},
+             {"app", 8, "This is an alert", _},
+             {"app", 7, "This is a critical", _},
+             {"app", 6, "This is an error", _},
+             {"app", 5, "This is a warn", _},
+             {"app", 5, "This is a warning", _},
+             {"app", 4, "This is a notice", _},
+             {"app", 3, "This is an info", _},
+             {"app", 2, "This is a debug", _}
+           ] = Test.Nif.get!(:log)
+  end
+
   test "debug/3 sends the debug log call through the extension" do
     metadata = %{some: "metadata"}