From: Ivan Tashkinov <ivantashkinov@gmail.com>
Date: Sun, 19 Dec 2021 17:35:00 +0000 (+0300)
Subject: Slow queries logging improvements: added EXPLAIN results, listed params, improved... 
X-Git-Url: https://git.squeep.com/?a=commitdiff_plain;h=e009950845c6d1e7864bb68ea1258c58438ee3aa;p=akkoma

Slow queries logging improvements: added EXPLAIN results, listed params, improved stacktrace.
---

diff --git a/lib/pleroma/telemetry/logger.ex b/lib/pleroma/telemetry/logger.ex
index 1dea13acd..c079f34f2 100644
--- a/lib/pleroma/telemetry/logger.ex
+++ b/lib/pleroma/telemetry/logger.ex
@@ -101,13 +101,19 @@ defmodule Pleroma.Telemetry.Logger do
   def handle_event(
         [:pleroma, :repo, :query] = _name,
         %{query_time: query_time} = _measurements,
-        %{source: source, query: query} = _metadata,
+        %{source: source, query: query, params: query_params, repo: repo} = _metadata,
         _config
       )
       when query_time > 500_000 and source not in [nil, "oban_jobs"] do
     {:current_stacktrace, stacktrace} = Process.info(self(), :current_stacktrace)
 
-    stacktrace =
+    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
+
+    pleroma_stacktrace =
       Enum.filter(stacktrace, fn
         {__MODULE__, _, _, _} ->
           false
@@ -120,13 +126,17 @@ defmodule Pleroma.Telemetry.Logger do
 
     Logger.warn(fn ->
       """
-      Query took longer than 500ms!
+      Slow query!
 
       Total time: #{query_time / 1_000}ms
 
-      #{inspect(query)}
+      #{query}
+
+      #{inspect(query_params)}
+
+      #{sql_explain}
 
-      #{inspect(stacktrace, pretty: true)}
+      #{Exception.format_stacktrace(pleroma_stacktrace)}
       """
     end)
   end