Skip to content
Snippets Groups Projects
Commit 89870679 authored by Cam Saül's avatar Cam Saül
Browse files

Use rolling averages for query execution times :timer:

parent d0e0b9a1
No related branches found
No related tags found
No related merge requests found
databaseChangeLog:
- changeSet:
id: 53
author: camsaul
changes:
- createTable:
tableName: query
remarks: 'Information (such as average execution time) for different queries that have been previously ran.'
columns:
- column:
name: query_hash
type: binary(32)
remarks: 'The hash of the query dictionary. (This is a 256-bit SHA3 hash of the query dict.)'
constraints:
primaryKey: true
nullable: false
- column:
name: average_execution_time
type: int
remarks: 'Average execution time for the query, round to nearest number of milliseconds. This is updated as a rolling average.'
constraints:
nullable: false
......@@ -19,6 +19,7 @@
[interface :as mi]
[label :refer [Label]]
[permissions :as perms]
[query :as query]
[table :refer [Table]]
[view-log :refer [ViewLog]])
[metabase.public-settings :as public-settings]
......@@ -362,11 +363,11 @@
"Compute a 'magic' cache TTL time (in seconds) for QUERY by multipling its historic average execution times by the `query-caching-ttl-ratio`.
If the TTL is less than a second, this returns `nil` (i.e., the cache should not be utilized.)"
[query]
(when-let [average-duration (qputil/query-average-duration query)]
(when-let [average-duration (query/average-execution-time-ms (qputil/query-hash query))]
(let [ttl-seconds (Math/round (float (/ (* average-duration (public-settings/query-caching-ttl-ratio))
1000)))]
1000.0)))]
(when-not (zero? ttl-seconds)
(log/info (format "Question's average execution duration is %d ms; using 'magic' TTL of %d seconds" (Math/round average-duration) ttl-seconds) (u/emoji "💾"))
(log/info (format "Question's average execution duration is %d ms; using 'magic' TTL of %d seconds" average-duration ttl-seconds) (u/emoji "💾"))
ttl-seconds))))
(defn- query-for-card [card parameters constraints]
......
......@@ -8,6 +8,7 @@
[hydrate :refer [hydrate]])
(metabase.models [card :refer [Card]]
[database :refer [Database]]
[query :as query]
[query-execution :refer [QueryExecution]])
[metabase.query-processor :as qp]
[metabase.query-processor.util :as qputil]
......@@ -41,8 +42,8 @@
(read-check Database database)
;; try calculating the average for the query as it was given to us, otherwise with the default constraints if there's no data there.
;; if we still can't find relevant info, just default to 0
{:average (or (qputil/query-average-duration query)
(qputil/query-average-duration (assoc query :constraints default-query-constraints))
{:average (or (query/average-execution-time-ms (qputil/query-hash) query)
(query/average-execution-time-ms (qputil/query-hash) (assoc query :constraints default-query-constraints))
0)})
(defn as-csv
......
......@@ -46,7 +46,6 @@
[pulse-card :refer [PulseCard]]
[pulse-channel :refer [PulseChannel]]
[pulse-channel-recipient :refer [PulseChannelRecipient]]
[query-execution :refer [QueryExecution]]
[raw-column :refer [RawColumn]]
[raw-table :refer [RawTable]]
[revision :refer [Revision]]
......@@ -89,7 +88,6 @@
DashboardCard
DashboardCardSeries
Activity
QueryExecution
Pulse
PulseCard
PulseChannel
......
(ns metabase.models.query
(:require (toucan [db :as db]
[models :as models])
[metabase.util :as u]
[metabase.util.honeysql-extensions :as hx]))
(models/defmodel Query :query)
;;; Helper Fns
(defn average-execution-time-ms
"Fetch the average execution time (in milliseconds) for query with QUERY-HASH if available.
Returns `nil` if no information is available."
^Integer [^bytes query-hash]
(db/select-one-field :average_execution_time Query :query_hash query-hash))
(defn update-average-execution-time!
"Update the recorded average execution time for query with QUERY-HASH."
^Integer [^bytes query-hash, ^Integer execution-time-ms]
(or
;; if there's already a matching Query update the rolling average
(db/update-where! Query {:query_hash query-hash}
:average_execution_time (hx/cast :integer (hx/round (hx/+ (hx/* 0.9 :average_execution_time)
(* 0.1 execution-time-ms))
0)))
;; otherwise add a new entry, using the value of EXECUTION-TIME-MS as a starting point
(db/insert! Query
:query_hash query-hash
:average_execution_time execution-time-ms)))
......@@ -4,7 +4,8 @@
[schema.core :as s]
[toucan.db :as db]
[metabase.driver :as driver]
[metabase.models.query-execution :refer [QueryExecution], :as query-execution]
(metabase.models [query :as query]
[query-execution :refer [QueryExecution], :as query-execution])
[metabase.query-processor.util :as qputil]
(metabase.query-processor.middleware [add-implicit-clauses :as implicit-clauses]
[add-row-count-and-status :as row-count-and-status]
......@@ -102,9 +103,10 @@
;;; +----------------------------------------------------------------------------------------------------+
(defn- save-query-execution!
"Save a `QueryExecution`."
"Save a `QueryExecution` and update the average execution time for the corresponding `Query`."
[query-execution]
(u/prog1 query-execution
(query/update-average-execution-time! (:hash query-execution) (:running_time query-execution))
(db/insert! QueryExecution (dissoc query-execution :json_query))))
(defn- save-and-return-failed-query!
......
......@@ -3,8 +3,7 @@
(:require (buddy.core [codecs :as codecs]
[hash :as hash])
[cheshire.core :as json]
[toucan.db :as db]
[metabase.models.query-execution :refer [QueryExecution]]))
[toucan.db :as db]))
(defn mbql-query?
"Is the given query an MBQL query?"
......@@ -50,17 +49,3 @@
"Return a 256-bit SHA3 hash of QUERY as a key for the cache. (This is returned as a byte array.)"
[query]
(hash/sha3-256 (json/generate-string (select-keys-for-hashing query))))
;;; ------------------------------------------------------------ Historic Duration Info ------------------------------------------------------------
(defn query-average-duration
"Return the average running time of QUERY over the last 10 executions in milliseconds.
Returns `nil` if there's not available data."
^Float [query]
(when-let [running-times (db/select-field :running_time QueryExecution
:hash (query-hash query)
{:order-by [[:started_at :desc]]
:limit 10})]
(float (/ (reduce + running-times)
(count running-times)))))
......@@ -92,10 +92,15 @@
(hsql/call :cast x (hsql/raw (name c))))
(defn format
"SQL `FORMAT` function."
"SQL `format` function."
[format-str expr]
(hsql/call :format expr (literal format-str)))
(defn round
"SQL `round` function."
[x decimal-places]
(hsql/call :round x decimal-places))
(defn ->date "CAST X to a `date`." [x] (cast :date x))
(defn ->datetime "CAST X to a `datetime`." [x] (cast :datetime x))
(defn ->timestamp "CAST X to a `timestamp`." [x] (cast :timestamp x))
......
......@@ -14,7 +14,9 @@
(def ^:private models-to-exclude
"Models that should *not* be migrated in `load-from-h2`."
#{"LegacyQueryExecution"
"QueryCache"})
"Query"
"QueryCache"
"QueryExecution"})
(defn- all-model-names []
(set (for [ns (ns-find/find-namespaces (classpath/classpath))
......
0% Loading or .
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment