diff options
| -rw-r--r-- | config/config.exs | 9 | ||||
| -rw-r--r-- | lib/pleroma/telemetry/logger.ex | 70 | 
2 files changed, 77 insertions, 2 deletions
diff --git a/config/config.exs b/config/config.exs index ec242cadc..2bde5b826 100644 --- a/config/config.exs +++ b/config/config.exs @@ -149,6 +149,8 @@ config :pleroma, Pleroma.Web.Endpoint,    ]  # Configures Elixir's Logger +config :logger, truncate: 65536 +  config :logger, :console,    level: :debug,    format: "\n$time $metadata[$level] $message\n", @@ -854,6 +856,13 @@ config :pleroma, ConcurrentLimiter, [    {Pleroma.Web.ActivityPub.MRF.MediaProxyWarmingPolicy, [max_running: 5, max_waiting: 5]}  ] +config :pleroma, :telemetry, +  slow_queries_logging: [ +    enabled: false, +    min_duration: 500_000, +    exclude_sources: [nil, "oban_jobs"] +  ] +  # Import environment specific config. This must remain at the bottom  # of this file so it overrides the configuration defined above.  import_config "#{Mix.env()}.exs" diff --git a/lib/pleroma/telemetry/logger.ex b/lib/pleroma/telemetry/logger.ex index 10165c1b2..35e245237 100644 --- a/lib/pleroma/telemetry/logger.ex +++ b/lib/pleroma/telemetry/logger.ex @@ -12,10 +12,16 @@ defmodule Pleroma.Telemetry.Logger do      [:pleroma, :connection_pool, :reclaim, :stop],      [:pleroma, :connection_pool, :provision_failure],      [:pleroma, :connection_pool, :client, :dead], -    [:pleroma, :connection_pool, :client, :add] +    [:pleroma, :connection_pool, :client, :add], +    [:pleroma, :repo, :query]    ]    def attach do -    :telemetry.attach_many("pleroma-logger", @events, &handle_event/4, []) +    :telemetry.attach_many( +      "pleroma-logger", +      @events, +      &Pleroma.Telemetry.Logger.handle_event/4, +      [] +    )    end    # Passing anonymous functions instead of strings to logger is intentional, @@ -87,4 +93,64 @@ defmodule Pleroma.Telemetry.Logger do    end    def handle_event([:pleroma, :connection_pool, :client, :add], _, _, _), do: :ok + +  def handle_event( +        [:pleroma, :repo, :query] = _name, +        %{query_time: query_time} = measurements, +        %{source: source} = metadata, +        config +      ) do +    logging_config = Pleroma.Config.get([:telemetry, :slow_queries_logging], []) + +    if logging_config[:enabled] && +         logging_config[:min_duration] && +         query_time > logging_config[:min_duration] and +         (is_nil(logging_config[:exclude_sources]) or +            source not in logging_config[:exclude_sources]) do +      log_slow_query(measurements, metadata, config) +    else +      :ok +    end +  end + +  defp log_slow_query( +         %{query_time: query_time} = _measurements, +         %{source: _source, query: query, params: query_params, repo: repo} = _metadata, +         _config +       ) do +    sql_explain = +      with {:ok, %{rows: explain_result_rows}} <- +             repo.query("EXPLAIN " <> query, query_params, log: false) do +        Enum.map_join(explain_result_rows, "\n", & &1) +      end + +    {:current_stacktrace, stacktrace} = Process.info(self(), :current_stacktrace) + +    pleroma_stacktrace = +      Enum.filter(stacktrace, fn +        {__MODULE__, _, _, _} -> +          false + +        {mod, _, _, _} -> +          mod +          |> to_string() +          |> String.starts_with?("Elixir.Pleroma.") +      end) + +    Logger.warn(fn -> +      """ +      Slow query! + +      Total time: #{round(query_time / 1_000)} ms + +      #{query} + +      #{inspect(query_params, limit: :infinity)} + +      #{sql_explain} + +      #{Exception.format_stacktrace(pleroma_stacktrace)} +      """ +    end) +  end  end  | 
