From 1a72c797d9ce6b837f90fc85b3330e9064c2948f Mon Sep 17 00:00:00 2001 From: Andrew Dryga Date: Tue, 21 May 2024 17:10:16 -0600 Subject: [PATCH] Do not write warnings when telemetry, Ecto or Plug are not available --- lib/logger_json/ecto.ex | 158 +++++++++++++------------- lib/logger_json/formatters/basic.ex | 3 +- lib/logger_json/formatters/datadog.ex | 3 +- lib/logger_json/formatters/elastic.ex | 3 +- lib/logger_json/plug.ex | 2 +- 5 files changed, 87 insertions(+), 82 deletions(-) diff --git a/lib/logger_json/ecto.ex b/lib/logger_json/ecto.ex index efd453e..eec3c63 100644 --- a/lib/logger_json/ecto.ex +++ b/lib/logger_json/ecto.ex @@ -1,94 +1,96 @@ -defmodule LoggerJSON.Ecto do - @moduledoc """ - A telemetry handler that logs Ecto query metrics in JSON format. +if Code.ensure_loaded?(Ecto) and Code.ensure_loaded?(:telemetry) do + defmodule LoggerJSON.Ecto do + @moduledoc """ + A telemetry handler that logs Ecto query metrics in JSON format. - This module is not recommended to be used in production, as it can be - costly to log every single database query. - """ - require Logger + This module is not recommended to be used in production, as it can be + costly to log every single database query. + """ + require Logger - @doc """ - Attaches the telemetry handler to the given event. + @doc """ + Attaches the telemetry handler to the given event. - ### Available options + ### Available options - * `:level` - log level which is used to log requests. Defaults to `:info`. + * `:level` - log level which is used to log requests. Defaults to `:info`. - ### Dynamic log level + ### Dynamic log level - In some cases you may wish to set the log level dynamically - on a per-query basis. To do so, set the `:level` option to - a tuple, `{Mod, Fun, Args}`. The query and map of time measures - will be prepended to the provided list of arguments. + In some cases you may wish to set the log level dynamically + on a per-query basis. To do so, set the `:level` option to + a tuple, `{Mod, Fun, Args}`. The query and map of time measures + will be prepended to the provided list of arguments. - When invoked, your function must return a - [`Logger.level()`](`t:Logger.level()/0`) or `false` to - disable logging for the request. + When invoked, your function must return a + [`Logger.level()`](`t:Logger.level()/0`) or `false` to + disable logging for the request. - ### Examples + ### Examples - Attaching the telemetry handler to the `MyApp.Repo` events with the `:info` log level: + Attaching the telemetry handler to the `MyApp.Repo` events with the `:info` log level: - LoggerJSON.Ecto.attach("logger-json-queries", [:my_app, :repo, :query], :info) + LoggerJSON.Ecto.attach("logger-json-queries", [:my_app, :repo, :query], :info) - For more details on event and handler naming see - (`Ecto.Repo` documentation)[https://hexdocs.pm/ecto/Ecto.Repo.html#module-telemetry-events]. - """ - @spec attach( - name :: String.t(), - event :: [atom()], - level :: - Logger.level() - | {module :: module(), function :: atom(), arguments :: [term()]} - | false - ) :: :ok | {:error, :already_exists} - def attach(name, event, level) do - :telemetry.attach(name, event, &__MODULE__.telemetry_logging_handler/4, level) - end + For more details on event and handler naming see + (`Ecto.Repo` documentation)[https://hexdocs.pm/ecto/Ecto.Repo.html#module-telemetry-events]. + """ + @spec attach( + name :: String.t(), + event :: [atom()], + level :: + Logger.level() + | {module :: module(), function :: atom(), arguments :: [term()]} + | false + ) :: :ok | {:error, :already_exists} + def attach(name, event, level) do + :telemetry.attach(name, event, &__MODULE__.telemetry_logging_handler/4, level) + end - @doc """ - A telemetry handler that logs Ecto query along with it's metrics in a structured format. - """ - @spec telemetry_logging_handler( - event_name :: [atom()], - measurements :: %{ - query_time: non_neg_integer(), - queue_time: non_neg_integer(), - decode_time: non_neg_integer(), - total_time: non_neg_integer() - }, - metadata :: %{required(:query) => String.t(), required(:repo) => module()}, - level :: - Logger.level() - | {module :: module(), function :: atom(), arguments :: [term()]} - | false - ) :: :ok - def telemetry_logging_handler(_event_name, measurements, %{query: query, repo: repo}, level) do - query_time = Map.get(measurements, :query_time) |> format_time(:nanosecond) - queue_time = Map.get(measurements, :queue_time) |> format_time(:nanosecond) - decode_time = Map.get(measurements, :decode_time) |> format_time(:nanosecond) - latency = Map.get(measurements, :total_time) |> format_time(:nanosecond) - - metadata = [ - query: %{ - repo: inspect(repo), - execution_time_μs: query_time, - decode_time_μs: decode_time, - queue_time_μs: queue_time, - latency_μs: latency - } - ] - - if level = level(level, query, measurements) do - Logger.log(level, query, metadata) - else - :ok + @doc """ + A telemetry handler that logs Ecto query along with it's metrics in a structured format. + """ + @spec telemetry_logging_handler( + event_name :: [atom()], + measurements :: %{ + query_time: non_neg_integer(), + queue_time: non_neg_integer(), + decode_time: non_neg_integer(), + total_time: non_neg_integer() + }, + metadata :: %{required(:query) => String.t(), required(:repo) => module()}, + level :: + Logger.level() + | {module :: module(), function :: atom(), arguments :: [term()]} + | false + ) :: :ok + def telemetry_logging_handler(_event_name, measurements, %{query: query, repo: repo}, level) do + query_time = Map.get(measurements, :query_time) |> format_time(:nanosecond) + queue_time = Map.get(measurements, :queue_time) |> format_time(:nanosecond) + decode_time = Map.get(measurements, :decode_time) |> format_time(:nanosecond) + latency = Map.get(measurements, :total_time) |> format_time(:nanosecond) + + metadata = [ + query: %{ + repo: inspect(repo), + execution_time_μs: query_time, + decode_time_μs: decode_time, + queue_time_μs: queue_time, + latency_μs: latency + } + ] + + if level = level(level, query, measurements) do + Logger.log(level, query, metadata) + else + :ok + end end - end - defp level({m, f, a}, query, measurements), do: apply(m, f, [query, measurements | a]) - defp level(level, _query, _measurements) when is_atom(level), do: level + defp level({m, f, a}, query, measurements), do: apply(m, f, [query, measurements | a]) + defp level(level, _query, _measurements) when is_atom(level), do: level - defp format_time(nil, _unit), do: 0 - defp format_time(time, unit), do: System.convert_time_unit(time, unit, :microsecond) + defp format_time(nil, _unit), do: 0 + defp format_time(time, unit), do: System.convert_time_unit(time, unit, :microsecond) + end end diff --git a/lib/logger_json/formatters/basic.ex b/lib/logger_json/formatters/basic.ex index 97d36ac..72c5b2d 100644 --- a/lib/logger_json/formatters/basic.ex +++ b/lib/logger_json/formatters/basic.ex @@ -14,7 +14,6 @@ defmodule LoggerJSON.Formatters.Basic do "time" => "2024-04-11T21:31:01.403Z" } """ - import Jason.Helpers, only: [json_map: 1] import LoggerJSON.Formatter.{MapBuilder, DateTime, Message, Metadata, RedactorEncoder} @behaviour LoggerJSON.Formatter @@ -72,6 +71,8 @@ defmodule LoggerJSON.Formatters.Basic do end if Code.ensure_loaded?(Plug.Conn) do + import Jason.Helpers, only: [json_map: 1] + defp format_http_request(%{conn: %Plug.Conn{} = conn}) do json_map( connection: diff --git a/lib/logger_json/formatters/datadog.ex b/lib/logger_json/formatters/datadog.ex index 15fa98f..588b07d 100644 --- a/lib/logger_json/formatters/datadog.ex +++ b/lib/logger_json/formatters/datadog.ex @@ -41,7 +41,6 @@ defmodule LoggerJSON.Formatters.Datadog do } } """ - import Jason.Helpers, only: [json_map: 1] import LoggerJSON.Formatter.{MapBuilder, DateTime, Message, Metadata, Code, RedactorEncoder} @behaviour LoggerJSON.Formatter @@ -195,6 +194,8 @@ defmodule LoggerJSON.Formatters.Datadog do defp safe_chardata_to_string(other), do: other if Code.ensure_loaded?(Plug.Conn) do + import Jason.Helpers, only: [json_map: 1] + defp format_http_request(%{conn: %Plug.Conn{} = conn} = meta) do request_url = Plug.Conn.request_url(conn) user_agent = LoggerJSON.Formatter.Plug.get_header(conn, "user-agent") diff --git a/lib/logger_json/formatters/elastic.ex b/lib/logger_json/formatters/elastic.ex index 2fd87ca..aa1a12e 100644 --- a/lib/logger_json/formatters/elastic.ex +++ b/lib/logger_json/formatters/elastic.ex @@ -96,7 +96,6 @@ defmodule LoggerJSON.Formatters.Elastic do } ``` """ - import Jason.Helpers, only: [json_map: 1] import LoggerJSON.Formatter.{MapBuilder, DateTime, Message, Metadata, RedactorEncoder} @behaviour LoggerJSON.Formatter @@ -223,6 +222,8 @@ defmodule LoggerJSON.Formatters.Elastic do defp format_logger_fields(_meta), do: nil if Code.ensure_loaded?(Plug.Conn) do + import Jason.Helpers, only: [json_map: 1] + # See the formats for the following fields in ECS: # - client.ip: https://www.elastic.co/guide/en/ecs/8.11/ecs-client.html # - http.*: https://www.elastic.co/guide/en/ecs/8.11/ecs-http.html diff --git a/lib/logger_json/plug.ex b/lib/logger_json/plug.ex index d7551b0..70ee25b 100644 --- a/lib/logger_json/plug.ex +++ b/lib/logger_json/plug.ex @@ -1,4 +1,4 @@ -if Code.ensure_loaded?(Plug) do +if Code.ensure_loaded?(Plug) and Code.ensure_loaded?(:telemetry) do defmodule LoggerJSON.Plug do @moduledoc """ A telemetry handler that logs request information in JSON format.