diff --git a/lib/logger_json/formatters/datadog.ex b/lib/logger_json/formatters/datadog.ex index 8b5bf98..541a9c9 100644 --- a/lib/logger_json/formatters/datadog.ex +++ b/lib/logger_json/formatters/datadog.ex @@ -197,7 +197,7 @@ defmodule LoggerJSON.Formatters.Datadog do defp safe_chardata_to_string(other), do: other if Code.ensure_loaded?(Plug.Conn) do - defp format_http_request(%{conn: %Plug.Conn{} = conn} = meta) do + defp format_http_request(%{conn: %Plug.Conn{} = conn, duration_us: duration_us} = meta) do request_url = Plug.Conn.request_url(conn) user_agent = LoggerJSON.Formatter.Plug.get_header(conn, "user-agent") remote_ip = LoggerJSON.Formatter.Plug.remote_ip(conn) @@ -223,8 +223,14 @@ defmodule LoggerJSON.Formatters.Datadog do ), network: Jason.Helpers.json_map(client: Jason.Helpers.json_map(ip: remote_ip)) } + |> maybe_put(:duration, to_nanosecs(duration_us)) end + + defp format_http_request(%{conn: %Plug.Conn{} = conn}), do: format_http_request(%{conn: conn, duration_us: nil}) end defp format_http_request(_meta), do: nil + + defp to_nanosecs(duration_us) when is_number(duration_us), do: duration_us * 1000 + defp to_nanosecs(_), do: nil end diff --git a/lib/logger_json/formatters/elastic.ex b/lib/logger_json/formatters/elastic.ex index 0397942..0c692c2 100644 --- a/lib/logger_json/formatters/elastic.ex +++ b/lib/logger_json/formatters/elastic.ex @@ -261,7 +261,8 @@ defmodule LoggerJSON.Formatters.Elastic do # - http.*: https://www.elastic.co/guide/en/ecs/8.11/ecs-http.html # - url.path: https://www.elastic.co/guide/en/ecs/8.11/ecs-url.html # - user_agent.original: https://www.elastic.co/guide/en/ecs/8.11/ecs-user_agent.html - defp format_http_request(%{conn: %Plug.Conn{} = conn}) do + # - event.duration (note: ns, not μs): https://www.elastic.co/guide/en/ecs/current/ecs-event.html#field-event-duration + defp format_http_request(%{conn: %Plug.Conn{} = conn, duration_us: duration_us}) do %{ "client.ip": LoggerJSON.Formatter.Plug.remote_ip(conn), "http.version": Plug.Conn.get_http_protocol(conn), @@ -271,7 +272,10 @@ defmodule LoggerJSON.Formatters.Elastic do "url.path": conn.request_path, "user_agent.original": LoggerJSON.Formatter.Plug.get_header(conn, "user-agent") } + |> maybe_put(:"event.duration", to_nanosecs(duration_us)) end + + defp format_http_request(%{conn: %Plug.Conn{} = conn}), do: format_http_request(%{conn: conn, duration_us: nil}) end defp format_http_request(_meta), do: nil @@ -289,4 +293,7 @@ defmodule LoggerJSON.Formatters.Elastic do end defp safe_chardata_to_string(other), do: other + + defp to_nanosecs(duration_us) when is_number(duration_us), do: duration_us * 1000 + defp to_nanosecs(_), do: nil end diff --git a/test/logger_json/formatters/datadog_test.exs b/test/logger_json/formatters/datadog_test.exs index 2606480..215c530 100644 --- a/test/logger_json/formatters/datadog_test.exs +++ b/test/logger_json/formatters/datadog_test.exs @@ -307,7 +307,7 @@ defmodule LoggerJSON.Formatters.DatadogTest do |> Plug.Conn.put_req_header("x-forwarded-for", "127.0.0.1") |> Plug.Conn.send_resp(200, "Hi!") - Logger.metadata(conn: conn) + Logger.metadata(conn: conn, duration_us: 1337) log = capture_log(fn -> @@ -332,6 +332,47 @@ defmodule LoggerJSON.Formatters.DatadogTest do }, "useragent" => "Mozilla/5.0" } + + assert log["duration"] == 1_337_000 + end + + test "logs exception http context" do + conn = + Plug.Test.conn("patch", "/", "") + |> Plug.Conn.put_req_header("user-agent", "Mozilla/5.0") + |> Plug.Conn.put_req_header("referer", "http://www.example.com/") + |> Plug.Conn.put_req_header("x-forwarded-for", "127.0.0.1") + |> Plug.Conn.send_resp(503, "oops") + + Logger.metadata(crash_reason: {{:EXIT, self()}, :foo}, conn: conn) + + log = + capture_log(fn -> + Logger.debug("Hello") + end) + |> decode_or_print_error() + + assert log["error"] == %{"message" => "Hello"} + + assert log["network"] == %{"client" => %{"ip" => "127.0.0.1"}} + + assert log["http"] == %{ + "referer" => "http://www.example.com/", + "method" => "PATCH", + "request_id" => nil, + "status_code" => 503, + "url" => "http://www.example.com/", + "url_details" => %{ + "host" => "www.example.com", + "path" => "/", + "port" => 80, + "queryString" => "", + "scheme" => "http" + }, + "useragent" => "Mozilla/5.0" + } + + assert log["duration"] == nil end test "logs throws" do diff --git a/test/logger_json/formatters/elastic_test.exs b/test/logger_json/formatters/elastic_test.exs index 003cf10..62ed653 100644 --- a/test/logger_json/formatters/elastic_test.exs +++ b/test/logger_json/formatters/elastic_test.exs @@ -368,7 +368,7 @@ defmodule LoggerJSON.Formatters.ElasticTest do |> Plug.Conn.put_req_header("x-forwarded-for", "") |> Plug.Conn.send_resp(200, "Hi!") - Logger.metadata(conn: conn) + Logger.metadata(conn: conn, duration_us: 1337) log_entry = capture_log(fn -> @@ -378,6 +378,7 @@ defmodule LoggerJSON.Formatters.ElasticTest do assert %{ "client.ip" => "", + "event.duration" => 1_337_000, "http.version" => "HTTP/1.1", "http.request.method" => "GET", "http.request.referrer" => "http://www.example2.com/",