diff options
Diffstat (limited to 'lib/pleroma/telemetry/logger.ex')
-rw-r--r-- | lib/pleroma/telemetry/logger.ex | 108 |
1 files changed, 49 insertions, 59 deletions
diff --git a/lib/pleroma/telemetry/logger.ex b/lib/pleroma/telemetry/logger.ex index 384c70fbc..b237f6811 100644 --- a/lib/pleroma/telemetry/logger.ex +++ b/lib/pleroma/telemetry/logger.ex @@ -8,11 +8,7 @@ defmodule Pleroma.Telemetry.Logger do require Logger @events [ - [:pleroma, :connection_pool, :reclaim, :start], - [:pleroma, :connection_pool, :reclaim, :stop], - [:pleroma, :connection_pool, :provision_failure], - [:pleroma, :connection_pool, :client, :dead], - [:pleroma, :connection_pool, :client, :add] + [:pleroma, :repo, :query] ] def attach do :telemetry.attach_many("pleroma-logger", @events, &handle_event/4, []) @@ -23,68 +19,62 @@ defmodule Pleroma.Telemetry.Logger do # out anyway due to higher log level configured def handle_event( - [:pleroma, :connection_pool, :reclaim, :start], - _, - %{max_connections: max_connections, reclaim_max: reclaim_max}, - _ + [:pleroma, :repo, :query] = _name, + %{query_time: query_time} = measurements, + %{source: source} = metadata, + config ) do - Logger.debug(fn -> - "Connection pool is exhausted (reached #{max_connections} connections). Starting idle connection cleanup to reclaim as much as #{reclaim_max} connections" - end) - end + logging_config = Pleroma.Config.get([:telemetry, :slow_queries_logging], []) - def handle_event( - [:pleroma, :connection_pool, :reclaim, :stop], - %{reclaimed_count: 0}, - _, - _ - ) do - Logger.error(fn -> - "Connection pool failed to reclaim any connections due to all of them being in use. It will have to drop requests for opening connections to new hosts" - end) + 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 - def handle_event( - [:pleroma, :connection_pool, :reclaim, :stop], - %{reclaimed_count: reclaimed_count}, - _, - _ - ) do - Logger.debug(fn -> "Connection pool cleaned up #{reclaimed_count} idle connections" 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 - def handle_event( - [:pleroma, :connection_pool, :provision_failure], - %{opts: [key | _]}, - _, - _ - ) do - Logger.error(fn -> - "Connection pool had to refuse opening a connection to #{key} due to connection limit exhaustion" - end) - 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) - def handle_event( - [:pleroma, :connection_pool, :client, :dead], - %{client_pid: client_pid, reason: reason}, - %{key: key}, - _ - ) do Logger.warn(fn -> - "Pool worker for #{key}: Client #{inspect(client_pid)} died before releasing the connection with #{inspect(reason)}" - end) - end + """ + Slow query! - def handle_event( - [:pleroma, :connection_pool, :client, :add], - %{clients: [_, _ | _] = clients}, - %{key: key, protocol: :http}, - _ - ) do - Logger.info(fn -> - "Pool worker for #{key}: #{length(clients)} clients are using an HTTP1 connection at the same time, head-of-line blocking might occur." + Total time: #{round(query_time / 1_000)} ms + + #{query} + + #{inspect(query_params, limit: :infinity)} + + #{sql_explain} + + #{Exception.format_stacktrace(pleroma_stacktrace)} + """ end) end - - def handle_event([:pleroma, :connection_pool, :client, :add], _, _, _), do: :ok end |