[dev tool] monitor all toucan2 queries (#45176)

dev/src/dev/render_png.clj

@@ -4,8 +4,8 @@
   (:require
     [clojure.data.csv :as csv]
     [clojure.java.io :as io]
-    [clojure.java.shell :as sh]
     [hiccup.core :as hiccup]
+    [dev.util :as dev.u]
     [metabase.email.messages :as messages]
     [metabase.models :refer [Card]]
     [metabase.models.card :as card]
@@ -23,33 +23,6 @@
 (set! *warn-on-reflection* true)
 
 ;; taken from https://github.com/aysylu/loom/blob/master/src/loom/io.clj
-(defn- os
-  "Returns :win, :mac, :unix, or nil"
-  []
-  (condp
-   #(<= 0 (.indexOf ^String %2 ^String %1))
-   (.toLowerCase (System/getProperty "os.name"))
-   "win" :win
-   "mac" :mac
-   "nix" :unix
-   "nux" :unix
-   nil))
-
-;; taken from https://github.com/aysylu/loom/blob/master/src/loom/io.clj
-(defn- open
-  "Opens the given file (a string, File, or file URI) in the default
-  application for the current desktop environment. Returns nil"
-  [f]
-  (let [f (io/file f)]
-    ;; There's an 'open' method in java.awt.Desktop but it hangs on Windows
-    ;; using Clojure Box and turns the process into a GUI process on Max OS X.
-    ;; Maybe it's ok for Linux?
-    (condp = (os)
-      :mac  (sh/sh "open" (str f))
-      :win  (sh/sh "cmd" (str "/c start " (-> f .toURI .toURL str)))
-      :unix (sh/sh "xdg-open" (str f)))
-    nil))
-
 (defn render-card-to-png
   "Given a card ID, renders the card to a png and opens it. Be aware that the png rendered on a dev machine may not
   match what's rendered on another system, like a docker container."
@@ -67,7 +40,7 @@
     (with-open [w (java.io.FileOutputStream. tmp-file)]
       (.write w ^bytes png-bytes))
     (.deleteOnExit tmp-file)
-    (open tmp-file)))
+    (dev.u/os-open tmp-file)))
 
 (defn render-pulse-card
   "Render a pulse card as a data structure"
@@ -87,7 +60,7 @@
     (with-open [w (io/writer tmp-file)]
       (.write w ^String html-str))
     (.deleteOnExit tmp-file)
-    (open tmp-file)))
+    (dev.u/os-open tmp-file)))
 
 (defn open-hiccup-as-html
   "Take a hiccup data structure, render it as html, then open it in the browser."
@@ -118,7 +91,7 @@
         (with-open [w (java.io.FileOutputStream. tmp-file)]
           (.write w ^bytes png-bytes))
         (.deleteOnExit tmp-file)
-        (open tmp-file)))))
+        (dev.u/os-open tmp-file)))))
 
 (def ^:private table-style-map
   {:border          "1px solid black"
@@ -208,7 +181,7 @@
     (with-open [w (io/writer tmp-file)]
       (.write w ^String html-str))
     (.deleteOnExit tmp-file)
-    (open tmp-file)))
+    (dev.u/os-open tmp-file)))
 
 (comment
   ;; This form has 3 cards:

dev/src/dev/toucan2_monitor.clj

+(ns dev.toucan2-monitor
+  "Utilities to track and monitor queries made by toucan2.
+
+  Usage:
+    (start!) ;; start tracking
+    ;; do some query using toucan 2 or via UI
+    (queries) ;; get all queries and its execution time
+    ;; => [[[\"SELECT * FROM report_card\"] 100]]
+    (stop!)
+    (to-csv!)
+    ;; to save all queries to a csv file"
+  (:require
+   [clojure.data.csv :as csv]
+   [clojure.java.io :as io]
+   [dev.util :as dev.u]
+   [metabase.test.util.log :as tu.log]
+   [metabase.util.log :as log]
+   [methodical.core :as methodical]
+   [toucan2.pipeline :as t2.pipeline])
+  (:import
+   (java.io File)))
+
+(set! *warn-on-reflection* true)
+
+(def queries*
+  "An atom to store all the queries and its execution time."
+  (atom []))
+
+(defn queries
+  "Get all the queries and its execution time in ms.
+
+  Usage:
+    (queries)
+    ;; => [[[\"SELECT * FROM report_card\"] 100]]"
+  []
+  @queries*)
+
+(defn reset-queries!
+  "Reset all the queries and its execution time."
+  []
+  (reset! queries* []))
+
+(defn summary
+  "Get the total number of queries and total execution time in ms."
+  []
+  (let [qs (queries)]
+    {:total-queries           (count qs)
+     :total-execution-time-ms (->> qs (map second) (apply +) int)}))
+
+(defn- track-query-execution-fn
+  [next-method rf conn query-type model query]
+  (let [start  (System/nanoTime)
+        result (next-method rf conn query-type model query)
+        end    (System/nanoTime)]
+    (swap! queries* (fnil conj []) [query (/ (- end start) 1e6)])
+   result))
+
+(def ^:private log-thread-ref (volatile! nil))
+
+(defn- create-log-thread! []
+  (Thread.
+   (fn []
+     (while (not (Thread/interrupted))
+       (let [{:keys [total-queries total-execution-time-ms]} (summary)]
+         (log/infof "Total queries: %d, Total execution time: %dms" total-queries total-execution-time-ms)
+         (Thread/sleep 1000))))))
+
+(defn- start-log! []
+  (tu.log/set-ns-log-level! *ns* :debug)
+  (when-not (some? @log-thread-ref)
+    (let [new-thread (create-log-thread!)]
+      (vreset! log-thread-ref new-thread)
+      (.start new-thread))))
+
+(defn- stop-log! []
+  (when-let [thread @log-thread-ref]
+    (.interrupt thread)
+    (vreset! log-thread-ref nil)))
+
+(defn start!
+  "Start tracking queries."
+  []
+  (stop-log!)
+  (start-log!)
+  (methodical/add-aux-method-with-unique-key!
+   #'t2.pipeline/transduce-execute-with-connection
+   :around
+   :default
+   track-query-execution-fn
+   ::monitor))
+
+(defn stop!
+  "Stop tracking queries."
+  []
+  (stop-log!)
+  (methodical/remove-aux-method-with-unique-key!
+   #'t2.pipeline/transduce-execute-with-connection
+   :around
+   :default
+   ::monitor))
+
+(defn to-csv!
+  "Save all the queries and its execution time to a csv file with 3 columns: query, params, execution time."
+  []
+  (let [qs        (queries)
+        format-q  (fn [[q t]]
+                    [(-> q first #_mdb.query/format-sql) (-> q rest vec) t])
+        temp-file (File/createTempFile "queries" ".csv")]
+    (with-open [w (io/writer temp-file)]
+      (csv/write-csv w (cons ["query" "params" "execution-time(ms)"] (map format-q qs))))
+    (dev.u/os-open temp-file)))
+
+(comment
+ (start!)
+ (queries)
+ (stop!)
+ (reset-queries!)
+ (summary)
+ (to-csv!)
+ (doseq [q (querles)]
+   (println q)))

dev/src/dev/util.clj

+(ns dev.util
+  (:require
+   [clojure.java.io :as io]
+   [clojure.java.shell :as sh]))
+
+(set! *warn-on-reflection* true)
+
+(defn- os
+  "Returns :win, :mac, :unix, or nil"
+  []
+  (condp
+   #(<= 0 (.indexOf ^String %2 ^String %1))
+   (.toLowerCase (System/getProperty "os.name"))
+   "win" :win
+   "mac" :mac
+   "nix" :unix
+   "nux" :unix
+   nil))
+
+;; taken from https://github.com/aysylu/loom/blob/master/src/loom/io.clj
+(defn os-open
+  "Opens the given file (a string, File, or file URI) in the default
+  application for the current desktop environment. Returns nil"
+  [f]
+  (let [f (io/file f)]
+    ;; There's an 'open' method in java.awt.Desktop but it hangs on Windows
+    ;; using Clojure Box and turns the process into a GUI process on Max OS X.
+    ;; Maybe it's ok for Linux?
+    (condp = (os)
+      :mac  (sh/sh "open" (str f))
+      :win  (sh/sh "cmd" (str "/c start " (-> f .toURI .toURL str)))
+      :unix (sh/sh "xdg-open" (str f)))
+    nil))