Auto detect log format

.changesets/auto-detect-log-format.md

@@ -0,0 +1,10 @@
+---
+bump: patch
+type: change
+---
+
+Detect the log format automatically. We now detect if a log line is in the JSON, Logfmt or plaintext formats. No further config needed when calling our logger, like so:
+
+```elixir
+Appsignal.Logger.info("group", "message")
+```

lib/appsignal/logger.ex

@@ -4,7 +4,7 @@ defmodule Appsignal.Logger do
   @type log_level ::
           :debug | :info | :notice | :warning | :error | :critical | :alert | :emergency
 
-  @type format :: :json | :logfmt | :plaintext
+  @type format :: :json | :logfmt | :plaintext | :autodetect
 
   @spec debug(String.t(), String.t(), %{} | format()) :: :ok
   def debug(group, message, metadata_or_format \\ %{})
@@ -95,7 +95,7 @@ defmodule Appsignal.Logger do
   end
 
   @spec log(log_level(), String.t(), String.t(), %{}, format()) :: :ok
-  def log(log_level, group, message, metadata, format \\ :plaintext) do
+  def log(log_level, group, message, metadata, format \\ :autodetect) do
     encoded_metadata = Appsignal.Utils.DataEncoder.encode(metadata)
 
     @nif.log(group, severity(log_level), format(format), message, encoded_metadata)
@@ -112,8 +112,9 @@ defmodule Appsignal.Logger do
   defp severity(:emergency), do: 9
   defp severity(_), do: 3
 
+  defp format(:autodetect), do: 3
   defp format(:json), do: 2
   defp format(:logfmt), do: 1
   defp format(:plaintext), do: 0
-  defp format(_), do: 0
+  defp format(_), do: 3
 end

lib/appsignal/logger/handler.ex

@@ -21,14 +21,14 @@
     )
   end
 
-  def add(group, format \\ :plaintext) do
+  def add(group, format \\ :autodetect) do
     :logger.add_handler(:appsignal_log, __MODULE__, %{
       config: %{
         group: group,
         format: format
       },
       formatter:
         Logger.Formatter.new(
           format: "$message",
           colors: [enabled: false]
         )

test/appsignal/logger/backend_test.exs

@@ -34,7 +34,7 @@ defmodule Appsignal.Logger.BackendTest do
       group: "phoenix"
     )
 
-    assert [{"phoenix", 3, 0, "foo bar baz", _}] = Appsignal.Test.Nif.get!(:log)
+    assert [{"phoenix", 3, 3, "foo bar baz", _}] = Appsignal.Test.Nif.get!(:log)
   end
 
   test "handle_event/2 sends logfmt logs to the extension" do

test/appsignal/logger/handler_test.exs

@@ -18,7 +18,7 @@ defmodule Appsignal.Logger.HandlerTest do
         Logger.error("A bad thing happened!")
 
         assert [
-                 {"some_group", 6, 0, "A bad thing happened!", _}
+                 {"some_group", 6, 3, "A bad thing happened!", _}
                ] = Appsignal.Test.Nif.get!(:log)
       end
 

test/appsignal/logger_test.exs

@@ -22,16 +22,16 @@ defmodule Appsignal.LoggerTest do
     Logger.log(:rhubarb, "app", "This is a... rhubarb?", metadata)
 
     assert [
-             {"app", 2, 0, "This is a debug", _},
-             {"app", 3, 0, "This is an info", _},
-             {"app", 4, 0, "This is a notice", _},
-             {"app", 5, 0, "This is a warning", _},
-             {"app", 5, 0, "This is a warn", _},
-             {"app", 6, 0, "This is an error", _},
-             {"app", 7, 0, "This is a critical", _},
-             {"app", 8, 0, "This is an alert", _},
-             {"app", 9, 0, "This is an emergency", _},
-             {"app", 3, 0, "This is a... rhubarb?", _}
+             {"app", 2, 3, "This is a debug", _},
+             {"app", 3, 3, "This is an info", _},
+             {"app", 4, 3, "This is a notice", _},
+             {"app", 5, 3, "This is a warning", _},
+             {"app", 5, 3, "This is a warn", _},
+             {"app", 6, 3, "This is an error", _},
+             {"app", 7, 3, "This is a critical", _},
+             {"app", 8, 3, "This is an alert", _},
+             {"app", 9, 3, "This is an emergency", _},
+             {"app", 3, 3, "This is a... rhubarb?", _}
            ] = Enum.reverse(Test.Nif.get!(:log))
   end
 
@@ -42,124 +42,158 @@ defmodule Appsignal.LoggerTest do
     Logger.log(:debug, "app", "Hi this is also plaintext", %{}, :plaintext)
     Logger.log(:debug, "app", "msg=\"Hi\" this=logfmt", %{}, :logfmt)
     Logger.log(:debug, "app", "{\"msg\":\"Hi\",\"this\":\"json\"", %{}, :json)
+    Logger.log(:debug, "app", "{\"msg\":\"Hi\",\"this\":\"json\"", %{}, :autodetect)
 
     assert [
-             {"app", 2, 0, "Hi this is plaintext", _},
+             {"app", 2, 3, "Hi this is plaintext", _},
              {"app", 2, 0, "Hi this is also plaintext", _},
              {"app", 2, 1, "msg=\"Hi\" this=logfmt", _},
-             {"app", 2, 2, "{\"msg\":\"Hi\",\"this\":\"json\"", _}
+             {"app", 2, 2, "{\"msg\":\"Hi\",\"this\":\"json\"", _},
+             {"app", 2, 3, "{\"msg\":\"Hi\",\"this\":\"json\"", _}
            ] = Enum.reverse(Test.Nif.get!(:log))
   end
 
   test "debug/3 sends the debug log call through the extension" do
     metadata = %{some: "metadata"}
 
     Logger.debug("app", "This is a debug", metadata)
+    Logger.debug("app", "This is a debug", :plaintext)
     Logger.debug("app", "this=debug", :logfmt)
     Logger.debug("app", "{\"this\":\"debug\"}", :json)
+    Logger.debug("app", "{\"this\":\"debug\"}", :autodetect)
 
     assert [
+             {"app", 2, 3, "This is a debug", _},
              {"app", 2, 0, "This is a debug", _},
              {"app", 2, 1, "this=debug", _},
-             {"app", 2, 2, "{\"this\":\"debug\"}", _}
+             {"app", 2, 2, "{\"this\":\"debug\"}", _},
+             {"app", 2, 3, "{\"this\":\"debug\"}", _}
            ] = Enum.reverse(Test.Nif.get!(:log))
   end
 
   test "info/3 sends the info log call through the extension" do
     metadata = %{some: "metadata"}
 
     Logger.info("app", "This is an info", metadata)
+    Logger.info("app", "This is an info", :plaintext)
     Logger.info("app", "this=info", :logfmt)
     Logger.info("app", "{\"this\":\"info\"}", :json)
+    Logger.info("app", "{\"this\":\"info\"}", :autodetect)
 
     assert [
+             {"app", 3, 3, "This is an info", _},
              {"app", 3, 0, "This is an info", _},
              {"app", 3, 1, "this=info", _},
-             {"app", 3, 2, "{\"this\":\"info\"}", _}
+             {"app", 3, 2, "{\"this\":\"info\"}", _},
+             {"app", 3, 3, "{\"this\":\"info\"}", _}
            ] = Enum.reverse(Test.Nif.get!(:log))
   end
 
   test "notice/3 sends the notice log call through the extension" do
     metadata = %{some: "metadata"}
 
     Logger.notice("app", "This is a notice", metadata)
+    Logger.notice("app", "This is a notice", :plaintext)
     Logger.notice("app", "this=notice", :logfmt)
     Logger.notice("app", "{\"this\":\"notice\"}", :json)
+    Logger.notice("app", "{\"this\":\"notice\"}", :autodetect)
 
     assert [
+             {"app", 4, 3, "This is a notice", _},
              {"app", 4, 0, "This is a notice", _},
              {"app", 4, 1, "this=notice", _},
-             {"app", 4, 2, "{\"this\":\"notice\"}", _}
+             {"app", 4, 2, "{\"this\":\"notice\"}", _},
+             {"app", 4, 3, "{\"this\":\"notice\"}", _}
            ] = Enum.reverse(Test.Nif.get!(:log))
   end
 
   test "warning/3 sends the warning log call through the extension" do
     metadata = %{some: "metadata"}
 
     Logger.warning("app", "This is a warning", metadata)
+    Logger.warning("app", "This is a warning", :plaintext)
     Logger.warning("app", "this=warning", :logfmt)
     Logger.warning("app", "{\"this\":\"warning\"}", :json)
+    Logger.warning("app", "{\"this\":\"warning\"}", :autodetect)
 
     assert [
+             {"app", 5, 3, "This is a warning", _},
              {"app", 5, 0, "This is a warning", _},
              {"app", 5, 1, "this=warning", _},
-             {"app", 5, 2, "{\"this\":\"warning\"}", _}
+             {"app", 5, 2, "{\"this\":\"warning\"}", _},
+             {"app", 5, 3, "{\"this\":\"warning\"}", _}
            ] = Enum.reverse(Test.Nif.get!(:log))
   end
 
   test "error/3 sends the error log call through the extension" do
     metadata = %{some: "metadata"}
 
     Logger.error("app", "This is an error", metadata)
+    Logger.error("app", "This is an error", :plaintext)
     Logger.error("app", "this=error", :logfmt)
     Logger.error("app", "{\"this\":\"error\"}", :json)
+    Logger.error("app", "{\"this\":\"error\"}", :autodetect)
 
     assert [
+             {"app", 6, 3, "This is an error", _},
              {"app", 6, 0, "This is an error", _},
              {"app", 6, 1, "this=error", _},
-             {"app", 6, 2, "{\"this\":\"error\"}", _}
+             {"app", 6, 2, "{\"this\":\"error\"}", _},
+             {"app", 6, 3, "{\"this\":\"error\"}", _}
            ] = Enum.reverse(Test.Nif.get!(:log))
   end
 
   test "critical/3 sends the critical log call through the extension" do
     metadata = %{some: "metadata"}
 
     Logger.critical("app", "This is a critical", metadata)
+    Logger.critical("app", "This is a critical", :plaintext)
     Logger.critical("app", "this=critical", :logfmt)
     Logger.critical("app", "{\"this\":\"critical\"}", :json)
+    Logger.critical("app", "{\"this\":\"critical\"}", :autodetect)
 
     assert [
+             {"app", 7, 3, "This is a critical", _},
              {"app", 7, 0, "This is a critical", _},
              {"app", 7, 1, "this=critical", _},
-             {"app", 7, 2, "{\"this\":\"critical\"}", _}
+             {"app", 7, 2, "{\"this\":\"critical\"}", _},
+             {"app", 7, 3, "{\"this\":\"critical\"}", _}
            ] = Enum.reverse(Test.Nif.get!(:log))
   end
 
   test "alert/3 sends the alert log call through the extension" do
     metadata = %{some: "metadata"}
 
     Logger.alert("app", "This is an alert", metadata)
+    Logger.alert("app", "This is an alert", :plaintext)
     Logger.alert("app", "this=alert", :logfmt)
     Logger.alert("app", "{\"this\":\"alert\"}", :json)
+    Logger.alert("app", "{\"this\":\"alert\"}", :autodetect)
 
     assert [
+             {"app", 8, 3, "This is an alert", _},
              {"app", 8, 0, "This is an alert", _},
              {"app", 8, 1, "this=alert", _},
-             {"app", 8, 2, "{\"this\":\"alert\"}", _}
+             {"app", 8, 2, "{\"this\":\"alert\"}", _},
+             {"app", 8, 3, "{\"this\":\"alert\"}", _}
            ] = Enum.reverse(Test.Nif.get!(:log))
   end
 
   test "emergency/3 sends the emergency log call through the extension" do
     metadata = %{some: "metadata"}
 
     Logger.emergency("app", "This is an emergency", metadata)
+    Logger.emergency("app", "This is an emergency", :plaintext)
     Logger.emergency("app", "this=emergency", :logfmt)
     Logger.emergency("app", "{\"this\":\"emergency\"}", :json)
+    Logger.emergency("app", "{\"this\":\"emergency\"}", :autodetect)
 
     assert [
+             {"app", 9, 3, "This is an emergency", _},
              {"app", 9, 0, "This is an emergency", _},
              {"app", 9, 1, "this=emergency", _},
-             {"app", 9, 2, "{\"this\":\"emergency\"}", _}
+             {"app", 9, 2, "{\"this\":\"emergency\"}", _},
+             {"app", 9, 3, "{\"this\":\"emergency\"}", _}
            ] = Enum.reverse(Test.Nif.get!(:log))
   end
 end