diff --git a/src/metabase/driver/sql_jdbc/execute.clj b/src/metabase/driver/sql_jdbc/execute.clj index 105f52f4516323a16617698f8a1140da83832f46..ea49bb7e11d19f7513df6c0db0c4d806a721f2a1 100644 --- a/src/metabase/driver/sql_jdbc/execute.clj +++ b/src/metabase/driver/sql_jdbc/execute.clj @@ -1,4 +1,3 @@ - (ns metabase.driver.sql-jdbc.execute "Code related to actually running a SQL query against a JDBC database (including setting the session timezone when appropriate), and for properly encoding/decoding types going in and out of the database." @@ -164,7 +163,8 @@ `(do-with-ensured-connection ~db (fn [~conn-binding] ~@body))) (defn- cancelable-run-query - "Runs `sql` in such a way that it can be interrupted via a `future-cancel`" + "Runs JDBC query, canceling it if an InterruptedException is caught (e.g. if there query is canceled before + finishing)." [db sql params opts] (with-ensured-connection [conn db] ;; This is normally done for us by java.jdbc as a result of our `jdbc/query` call @@ -173,19 +173,17 @@ ;; (Not all drivers support this so ignore Exceptions if they don't) (u/ignore-exceptions (.closeOnCompletion stmt)) - ;; Need to run the query in another thread so that this thread can cancel it if need be (try - (let [query-future (future (jdbc/query conn (into [stmt] params) opts))] - ;; This thread is interruptable because it's awaiting the other thread (the one actually running the - ;; query). Interrupting this thread means that the client has disconnected (or we're shutting down) and so - ;; we can give up on the query running in the future - @query-future) + (jdbc/query conn (into [stmt] params) opts) (catch InterruptedException e (log/warn (tru "Client closed connection, canceling query")) ;; This is what does the real work of canceling the query. We aren't checking the result of ;; `query-future` but this will cause an exception to be thrown, saying the query has been cancelled. (.cancel stmt) - (throw e)))))) + (throw e)) + (catch Exception e + (u/ignore-exceptions (.cancel stmt)) + e))))) (defn- run-query "Run the query itself." @@ -205,10 +203,12 @@ ;;; -------------------------- Running queries: exception handling & disabling auto-commit --------------------------- (defn- exception->nice-error-message ^String [^SQLException e] - (or (->> (.getMessage e) ; error message comes back like 'Column "ZID" not found; SQL statement: ... [error-code]' sometimes - (re-find #"^(.*);") ; the user already knows the SQL, and error code is meaningless - second) ; so just return the part of the exception that is relevant - (.getMessage e))) + ;; error message comes back like 'Column "ZID" not found; SQL statement: ... [error-code]' sometimes + ;; the user already knows the SQL, and error code is meaningless + ;; so just return the part of the exception that is relevant + (->> (.getMessage e) + (re-find #"^(.*);") + second)) (defn do-with-try-catch "Tries to run the function `f`, catching and printing exception chains if SQLException is thrown, @@ -219,7 +219,10 @@ (f) (catch SQLException e (log/error (jdbc/print-sql-exception-chain e)) - (throw (Exception. (exception->nice-error-message e) e))))) + (throw + (if-let [nice-error-message (exception->nice-error-message e)] + (Exception. nice-error-message e) + e))))) (defn- do-with-auto-commit-disabled "Disable auto-commit for this transaction, and make the transaction `rollback-only`, which means when the diff --git a/test/metabase/driver/sql_jdbc/execute_test.clj b/test/metabase/driver/sql_jdbc/execute_test.clj index 4fc8723dd28875c0abdd5e2518dd5cc1d05de69d..6c201b7900e8fbefd67557844d01e7ad8399ef46 100644 --- a/test/metabase/driver/sql_jdbc/execute_test.clj +++ b/test/metabase/driver/sql_jdbc/execute_test.clj @@ -1,10 +1,18 @@ (ns metabase.driver.sql-jdbc.execute-test - (:require [clojure.java.jdbc :as jdbc] + (:require [clojure.core.async :as a] + [clojure.java.jdbc :as jdbc] + [clojure.string :as str] + [expectations :refer [expect]] + [metabase + [query-processor :as qp] + [util :as u]] [metabase.driver.sql-jdbc-test :as sql-jdbc-test] - [metabase.query-processor :as qp] - [metabase.test.data :as data] - [metabase.test.data.datasets :as datasets]) - (:import java.sql.PreparedStatement)) + [metabase.test + [data :as data] + [util :as tu]] + [metabase.test.data.datasets :as datasets] + [metabase.test.util.log :as tu.log]) + (:import [java.sql PreparedStatement ResultSet])) (defn- do-with-max-rows [f] ;; force loading of the test data before swapping out `jdbc/query`, otherwise things might not sync correctly @@ -59,3 +67,121 @@ :type :query :query {:source-table (data/id :venues)}}) :constraints {:max-results 15}}))) + + +;;; +----------------------------------------------------------------------------------------------------------------+ +;;; | Query Cancelation & Resource Closing Tests | +;;; +----------------------------------------------------------------------------------------------------------------+ + +(defrecord ^:private FakePreparedStatement [called-cancel? called-close? fake-resultset] + java.sql.PreparedStatement + (closeOnCompletion [_]) ; no-op + (cancel [_] (some-> called-cancel? (deliver true))) + (close [_] (some-> called-close? (deliver true))) + (executeQuery [_] fake-resultset)) + +(defrecord ^:private FakeResultSet [called-close?] + ResultSet + (close [_] (some-> called-close? (deliver true))) + (next [_] false) + (getMetaData [_] + (reify java.sql.ResultSetMetaData + (getColumnCount [_] 0)))) + +(defn- fake-prepare-statement + "Returns `fake-value` whenenver the `sql` parameter returns a truthy value when passed to `use-fake-value?`." + [& {:keys [use-fake-value? faked-value] + :or {use-fake-value? (constantly false)}}] + (let [original-prepare-statement jdbc/prepare-statement] + (fn [connection sql options] + (if (use-fake-value? sql) + faked-value + (original-prepare-statement connection sql options))))) + +(defn- fake-query + "Function to replace the `clojure.java.jdbc/query` function. Will invoke `on-fake-prepared-statement` when passed an + instance of `FakePreparedStatement`." + [& {:keys [on-fake-prepared-statement]}] + (let [original-query jdbc/query] + (fn + ([conn stmt+params] + (conn stmt+params)) + + ([conn stmt+params opts] + (if (instance? FakePreparedStatement (first stmt+params)) + (when on-fake-prepared-statement (on-fake-prepared-statement)) + (original-query conn stmt+params opts)))))) + +;; make sure queries properly clean up after themselves and close result sets and prepared statements when finished +(expect + {:prepared-statement-closed? true, :result-set-closed? true} + (let [closed-prepared-statement? (promise) + closed-result-set? (promise) + fake-resultset (->FakeResultSet closed-result-set?) + fake-prepared-statement (->FakePreparedStatement nil closed-prepared-statement? fake-resultset) + placeholder-query "SELECT 1;"] + (with-redefs [jdbc/prepare-statement (fake-prepare-statement + :use-fake-value? #(str/includes? % placeholder-query) + :faked-value fake-prepared-statement)] + (let [{{:keys [rows]} :data, :as results} (qp/process-query + {:database (data/id) + :type :native + :native {:query placeholder-query}})] + (when-not rows + (throw (ex-info "Query failed to run!" results))) + ;; make sure results are fully realized! + (mapv vec rows)) + {:prepared-statement-closed? (deref closed-prepared-statement? 1000 false) + :result-set-closed? (deref closed-result-set? 1000 false)}))) + +;; make sure a prepared statement is canceled & closed when the async QP channel is closed +(expect + {:prepared-statement-canceled? true, :prepared-statement-closed? true} + (let [started? (promise) + canceled-prepared-statement? (promise) + closed-prepared-statement? (promise) + fake-prepared-statement (->FakePreparedStatement canceled-prepared-statement? closed-prepared-statement? nil) + placeholder-query "SLEEP PLACEHOLDER"] + (with-redefs [jdbc/prepare-statement (fake-prepare-statement + :use-fake-value? #(str/includes? % placeholder-query) + :faked-value fake-prepared-statement) + jdbc/query (fake-query + :on-fake-prepared-statement + (fn [& _] + (deliver started? true) + (Thread/sleep 2000) + (->FakeResultSet nil)))] + (let [chan (qp/process-query + {:database (data/id) + :type :native + :native {:query placeholder-query} + :async? true})] + (u/deref-with-timeout started? 1000) + (a/close! chan) + {:prepared-statement-canceled? (deref canceled-prepared-statement? 3000 false) + :prepared-statement-closed? (deref closed-prepared-statement? 1000 false)})))) + +;; The test below sort of tests the same thing (I think). But it is written in a much more confusing manner. If you +;; dare, try to work out why happens by reading source `call-with-paused-query`. - Cam +(expect + ::tu/success + ;; this might dump messages about the connection being closed; we don't need to worry about that + (tu.log/suppress-output + (tu/call-with-paused-query + (fn [query-thunk called-query? called-cancel? pause-query] + (let [ ;; This fake prepared statement is cancelable like a prepared statement, but will allow us to tell the + ;; difference between our Prepared statement and the real thing + fake-prep-stmt (->FakePreparedStatement called-cancel? nil nil)] + (future + (try + (with-redefs [jdbc/prepare-statement (fake-prepare-statement + :use-fake-value? (fn [sql] (re-find #"checkins" (str/lower-case sql))) + :faked-value fake-prep-stmt) + jdbc/query (fake-query + :on-fake-prepared-statement + (fn [] + (deliver called-query? true) + @pause-query))] + (query-thunk)) + (catch Throwable e + (throw e))))))))) diff --git a/test/metabase/query_processor_test/failure_test.clj b/test/metabase/query_processor_test/failure_test.clj index 5dfde5b29ee4b618aa4a2cdcbb6c02fe56a9b327..8576b6d2f0960fe84f957da7f1541bfef4eedcb6 100644 --- a/test/metabase/query_processor_test/failure_test.clj +++ b/test/metabase/query_processor_test/failure_test.clj @@ -4,7 +4,9 @@ [medley.core :as m] [metabase.query-processor :as qp] [metabase.query-processor.interface :as qp.i] - [metabase.test.data :as data])) + [metabase.test.data :as data] + [metabase.util.schema :as su] + [schema.core :as s])) (defn- bad-query [] {:database (data/id) @@ -27,12 +29,13 @@ "LIMIT 1048576") :params nil}) -(def ^:private ^{:arglists '([stacktrace])} valid-stacktrace? (every-pred seq (partial every? (every-pred string? seq)))) +(def ^:private ^{:arglists '([stacktrace])} valid-stacktrace? + (complement (partial s/check [su/NonBlankString]))) ;; running a bad query via `process-query` should return stacktrace, query, preprocessed query, and native query (expect {:status :failed - :class java.util.concurrent.ExecutionException + :class Exception :error true :stacktrace true ;; `:database` is removed by the catch-exceptions middleware for historical reasons diff --git a/test/metabase/query_processor_test/query_cancellation_test.clj b/test/metabase/query_processor_test/query_cancellation_test.clj deleted file mode 100644 index 65227793bfe38a3511171e0b969be8d7bc46c843..0000000000000000000000000000000000000000 --- a/test/metabase/query_processor_test/query_cancellation_test.clj +++ /dev/null @@ -1,65 +0,0 @@ -(ns metabase.query-processor-test.query-cancellation-test - "TODO - This is sql-jdbc specific, so it should go in a sql-jdbc test namespace." - (:require [clojure.java.jdbc :as jdbc] - [clojure.string :as str] - [expectations :refer [expect]] - [metabase.test.util :as tu] - [metabase.test.util.log :as tu.log])) - -(defrecord ^:private FakePreparedStatement [called-cancel?] - java.sql.PreparedStatement - (closeOnCompletion [_]) ; no-op - (cancel [_] (deliver called-cancel? true)) - (close [_] true)) - -(defn- make-fake-prep-stmt - "Returns `fake-value` whenenver the `sql` parameter returns a truthy value when passed to `use-fake-value?`." - [orig-make-prep-stmt & {:keys [use-fake-value? faked-value] - :or {use-fake-value? (constantly false)}}] - (fn [connection sql options] - (if (use-fake-value? sql) - faked-value - (orig-make-prep-stmt connection sql options)))) - -(defn- fake-query - "Function to replace the `clojure.java.jdbc/query` function. Will invoke `on-fake-prepared-statement` when passed an - instance of `FakePreparedStatement`." - {:style/indent 1} - [orig-jdbc-query & {:keys [on-fake-prepared-statement]}] - (fn - ([conn stmt+params] - (orig-jdbc-query conn stmt+params)) - - ([conn stmt+params opts] - (if (instance? FakePreparedStatement (first stmt+params)) - (when on-fake-prepared-statement (on-fake-prepared-statement)) - (orig-jdbc-query conn stmt+params opts))))) - -(expect - ::tu/success - ;; this might dump messages about the connection being closed; we don't need to worry about that - (tu.log/suppress-output - (tu/call-with-paused-query - (fn [query-thunk called-query? called-cancel? pause-query] - (let [ ;; This fake prepared statement is cancelable like a prepared statement, but will allow us to tell the - ;; difference between our Prepared statement and the real thing - fake-prep-stmt (->FakePreparedStatement called-cancel?) - ;; Much of the underlying plumbing of MB requires a working jdbc/query and jdbc/prepared-statement (such - ;; as queryies for the application database). Let binding the original versions of the functions allows - ;; us to delegate to them when it's not the query we're trying to test - orig-jdbc-query jdbc/query - orig-prep-stmt jdbc/prepare-statement] - (future - (try - (with-redefs [jdbc/prepare-statement (make-fake-prep-stmt - orig-prep-stmt - :use-fake-value? (fn [sql] (re-find #"checkins" (str/lower-case sql))) - :faked-value fake-prep-stmt) - jdbc/query (fake-query orig-jdbc-query - :on-fake-prepared-statement - (fn [] - (deliver called-query? true) - @pause-query))] - (query-thunk)) - (catch Throwable e - (throw e)))))))))