diff --git a/dev/src/dev.clj b/dev/src/dev.clj index 08ec9eceb08cace13335dbcd4328fa956591d9ee..2f06f48958a73a444f6d0dac944bbf5a082b61ad 100644 --- a/dev/src/dev.clj +++ b/dev/src/dev.clj @@ -87,6 +87,7 @@ `(require [(symbol (str "metabase.models." (quote ~model-sym))) :as (quote ~model-sym)])) (defmacro with-permissions + "Execute the body with the given permissions." [permissions & body] `(binding [api/*current-user-permissions-set* (delay ~permissions)] ~@body)) diff --git a/dev/src/user.clj b/dev/src/user.clj index 793f7fb977f20ad249a9e668342447e08f2d783a..28668a874d20f420675a6446404dd336e2d6ef16 100644 --- a/dev/src/user.clj +++ b/dev/src/user.clj @@ -1,16 +1,17 @@ (ns user (:require [hawk.assert-exprs] + [metabase.bootstrap] [metabase.test-runner.assert-exprs])) -;; make sure stuff like `schema=` and what not are loaded -(comment hawk.assert-exprs/keep-me +(comment metabase.bootstrap/keep-me + ;; make sure stuff like `schema=` and what not are loaded + hawk.assert-exprs/keep-me metabase.test-runner.assert-exprs/keep-me) (defn dev "Load and switch to the 'dev' namespace." [] - (require 'metabase.bootstrap) (require 'dev) (in-ns 'dev) :loaded) diff --git a/src/metabase/api/common.clj b/src/metabase/api/common.clj index b34a8aaed65df1155a1eb6cdc2926bf9421f94e3..e475de17684fe3b2a4e657db662412a4a6b05561 100644 --- a/src/metabase/api/common.clj +++ b/src/metabase/api/common.clj @@ -1,6 +1,7 @@ (ns metabase.api.common "Dynamic variables and utility functions/macros for writing API functions." (:require + [clojure.set :as set] [clojure.spec.alpha :as s] [clojure.string :as str] [clojure.tools.logging :as log] @@ -16,6 +17,7 @@ route-fn-name validate-params wrap-response-if-needed]] + [metabase.config :as config] [metabase.models.interface :as mi] [metabase.util :as u] [metabase.util.i18n :as i18n :refer [deferred-tru tru]] @@ -261,16 +263,50 @@ (ns-name *ns*) fn-name))) (assoc parsed :fn-name fn-name, :route route, :docstr docstr)))) +(defn validate-param-values + "Log a warning if the request body contains any parameters not included in `expected-params` (which is presumably + populated by the defendpoint schema)" + [{route :compojure/route body :body} expected-params] + (when (and (not config/is-prod?) + (map? body)) + (let [extraneous-params (set/difference (set (keys body)) + (set expected-params))] + (when (seq extraneous-params) + (log/warnf "Unexpected parameters at %s: %s\nPlease add them to the schema or remove them from the API client" + route (vec extraneous-params)))))) + + +(defn method-symbol->keyword + "Convert Compojure-style HTTP method symbols (PUT, POST, etc.) to the keywords used internally by + Compojure (:put, :post, ...)" + [method-symbol] + (-> method-symbol + name + u/lower-case-en + keyword)) + (defmacro defendpoint* "Impl macro for [[defendpoint]]; don't use this directly." - [{:keys [method route fn-name docstr args body]}] + [{:keys [method route fn-name docstr args body arg->schema]}] {:pre [(or (string? route) (vector? route))]} - `(def ~(vary-meta fn-name - assoc - :doc docstr - :is-endpoint? true) - (~(symbol "compojure.core" (name method)) ~route ~args - ~@body))) + (let [method-kw (method-symbol->keyword method) + allowed-params (keys arg->schema) + prep-route #'compojure/prepare-route] + `(def ~(vary-meta fn-name + assoc + :doc docstr + :is-endpoint? true) + ;; The next form is a copy of `compojure/compile-route`, with the sole addition of the call to + ;; `validate-param-values`. This is because to validate the request body we need to intercept the request + ;; before the destructuring takes place. I.e., we need to validate the value of `(:body request#)`, and that's + ;; not available if we called `compile-route` ourselves. + (compojure/make-route + ~method-kw + ~(prep-route route) + (fn [request#] + (validate-param-values request# (quote ~allowed-params)) + (compojure/let-request [~args request#] + ~@body)))))) ;; TODO - several of the things `defendpoint` does could and should just be done by custom Ring middleware instead ;; e.g. `auto-parse` diff --git a/src/metabase/logger.clj b/src/metabase/logger.clj index 31c05babf744e3214eff5c0c2a70846d8936df99..d719b5952dd18e1380a567da014a4f82cc6691a0 100644 --- a/src/metabase/logger.clj +++ b/src/metabase/logger.clj @@ -6,13 +6,16 @@ [amalloy.ring-buffer :refer [ring-buffer]] [clj-time.coerce :as time.coerce] [clj-time.format :as time.format] - [metabase.config :as config]) + [metabase.config :as config] + [metabase.plugins.classloader :as classloader]) (:import (org.apache.commons.lang3.exception ExceptionUtils) (org.apache.logging.log4j LogManager) (org.apache.logging.log4j.core Appender LogEvent LoggerContext) (org.apache.logging.log4j.core.config LoggerConfig))) +(set! *warn-on-reflection* true) + (def ^:private ^:const max-log-entries 2500) (defonce ^:private messages* (atom (ring-buffer max-log-entries))) @@ -47,13 +50,11 @@ (when-not *compile-files* (when-not @has-added-appender? (reset! has-added-appender? true) - (let [^LoggerContext ctx (LogManager/getContext false) - config (.getConfiguration ctx) - appender (metabase-appender) - ^org.apache.logging.log4j.Level level nil - ^org.apache.logging.log4j.core.Filter filter nil] + (let [^LoggerContext ctx (LogManager/getContext (classloader/the-classloader) false) + config (.getConfiguration ctx) + appender (metabase-appender)] (.start appender) (.addAppender config appender) (doseq [[_ ^LoggerConfig logger-config] (.getLoggers config)] - (.addAppender logger-config appender level filter)) - (.updateLoggers ctx)))) + (.addAppender logger-config appender (.getLevel logger-config) (.getFilter logger-config)) + (.updateLoggers ctx))))) diff --git a/test/metabase/api/common/internal_test.clj b/test/metabase/api/common/internal_test.clj index f2922186da0829c699e2b0f7058142ff54f266ad..5862b453c0545dc275c834b122dc3a643a7a616b 100644 --- a/test/metabase/api/common/internal_test.clj +++ b/test/metabase/api/common/internal_test.clj @@ -2,6 +2,7 @@ (:require [cheshire.core :as json] [clj-http.client :as http] + [clojure.string :as str] [clojure.test :refer :all] [compojure.core :refer [POST]] [malli.util :as mut] @@ -9,7 +10,9 @@ [metabase.api.common :as api] [metabase.api.common.internal :as internal] [metabase.config :as config] + [metabase.logger :as mb.logger] [metabase.server.middleware.exceptions :as mw.exceptions] + [metabase.test :as mt] [metabase.util :as u] [ring.adapter.jetty :as jetty])) @@ -68,59 +71,64 @@ (deftest defendpoint-test (let [server (jetty/run-jetty (json-mw (exception-mw #'routes)) {:port 0 :join? false}) - port (.. server getURI getPort) - post! (fn [route body] - (http/post (str "http://localhost:" port route) - {:throw-exceptions false - :accept :json - :as :json - :coerce :always - :body (json/generate-string body)}))] + port (.. server getURI getPort) + post! (fn [route body] + (http/post (str "http://localhost:" port route) + {:throw-exceptions false + :accept :json + :as :json + :coerce :always + :body (json/generate-string body)}))] (is (= {:a 1 :b 2} (:body (post! "/post/any" {:a 1 :b 2})))) (is (= {:id 1} (:body (post! "/post/id-int" {:id 1})))) - (is (= {:errors {:id "integer"}, + (is (= {:errors {:id "integer"}, :specific-errors {:id ["should be an int"]}} (:body (post! "/post/id-int" {:id "1"})))) - (is (= {:id "myid" - :tags ["abc"] - :address {:street "abc" :city "sdasd" :zip 2999 :lonlat [0.0 0.0]}} - (:body (post! "/post/test-address" - {:id "myid" - :tags ["abc"] - :address {:street "abc" - :city "sdasd" - :zip 2999 - :lonlat [0.0 0.0]}})))) + (mt/with-log-level [metabase.api.common :warn] + (is (= {:id "myid" + :tags ["abc"] + :address {:street "abc" :city "sdasd" :zip 2999 :lonlat [0.0 0.0]}} + (:body (post! "/post/test-address" + {:id "myid" + :tags ["abc"] + :address {:street "abc" + :city "sdasd" + :zip 2999 + :lonlat [0.0 0.0]}})))) + (is (some (fn [{message :msg, :as entry}] + (when (str/includes? (str message) "Unexpected parameters") + entry)) + (mb.logger/messages)))) (is (= {:errors {:address "map (titled: ‘Address’) where {:id -> <string>, :tags -> <vector of string>, :address -> <map where {:street -> <string>, :city -> <string>, :zip -> <integer>, :lonlat -> <vector with exactly 2 items of type: double, double>}>}"}, - :specific-errors {:address {:id ["missing required key"], - :tags ["missing required key"], + :specific-errors {:address {:id ["missing required key"], + :tags ["missing required key"], :address ["missing required key"]}}} (:body (post! "/post/test-address" {:x "1"})))) (is (= {:errors {:address "map (titled: ‘Address’) where {:id -> <string>, :tags -> <vector of string>, :address -> <map where {:street -> <string>, :city -> <string>, :zip -> <integer>, :lonlat -> <vector with exactly 2 items of type: double, double>}>}"}, :specific-errors {:address - {:id ["should be a string"] - :tags ["invalid type"] + {:id ["should be a string"] + :tags ["invalid type"] :address {:street ["missing required key"] - :zip ["should be an int"]}}}} - (:body (post! "/post/test-address" {:id 1288 - :tags "a,b,c" + :zip ["should be an int"]}}}} + (:body (post! "/post/test-address" {:id 1288 + :tags "a,b,c" :address {:streeqt "abc" - :city "sdasd" - :zip "12342" - :lonlat [0.0 0.0]}})))) + :city "sdasd" + :zip "12342" + :lonlat [0.0 0.0]}})))) (is (= {:errors {:address "map (titled: ‘Address’) where {:id -> <string>, :tags -> <vector of string>, :address -> <map where {:street -> <string>, :city -> <string>, :zip -> <integer>, :lonlat -> <vector with exactly 2 items of type: double, double>} with no other keys>} with no other keys"}, :specific-errors {:address {:address ["missing required key"], - :a ["disallowed key"], - :b ["disallowed key"]}}} + :a ["disallowed key"], + :b ["disallowed key"]}}} (:body (post! "/post/closed-test-address" {:id "1" :tags [] :a 1 :b 2})))))) (deftest route-fn-name-test diff --git a/test/metabase/api/common_test.clj b/test/metabase/api/common_test.clj index 965606a427ff6fa8626767b8d07089bf73123c3d..707c4959b23cf8a6dc738d64074e16559a2d7a39 100644 --- a/test/metabase/api/common_test.clj +++ b/test/metabase/api/common_test.clj @@ -1,11 +1,13 @@ (ns metabase.api.common-test (:require [clojure.test :refer :all] + [hawk.assert-exprs.approximately-equal :as hawk.approx] [metabase.api.common :as api] [metabase.api.common.internal :as api.internal] [metabase.server.middleware.exceptions :as mw.exceptions] [metabase.server.middleware.misc :as mw.misc] - [metabase.server.middleware.security :as mw.security])) + [metabase.server.middleware.security :as mw.security] + [methodical.core :as methodical])) ;;; TESTS FOR CHECK (ETC) @@ -92,18 +94,27 @@ ;; compare easily. (update-in [:route 2] str))))) +(methodical/defmethod hawk.approx/=?-diff [java.util.regex.Pattern clojure.lang.Symbol] + [expected-re sym] + (hawk.approx/=?-diff expected-re (name sym))) + (deftest ^:parallel defendpoint-test ;; replace regex `#"[0-9]+"` with str `"#[0-9]+" so expectations doesn't barf (binding [api.internal/*auto-parse-types* (update-in api.internal/*auto-parse-types* [:int :route-param-regex] (partial str "#"))] - (is (= '(def GET_:id - (compojure.core/GET - ["/:id" :id "#[0-9]+"] - [id] - (metabase.api.common.internal/auto-parse [id] - (metabase.api.common.internal/validate-param 'id id metabase.util.schema/IntGreaterThanZero) - (metabase.api.common.internal/wrap-response-if-needed - (do - (select-one Card :id id)))))) - (macroexpand '(metabase.api.common/defendpoint-schema compojure.core/GET "/:id" [id] - {id metabase.util.schema/IntGreaterThanZero} - (select-one Card :id id))))))) + (is (=? '(def + GET_:id + (compojure.core/make-route + :get + {:source "/:id", :re #"/(#[0-9]+)", :keys [:id], :absolute? false} + (clojure.core/fn + [#"request__\d+__auto__"] + (metabase.api.common/validate-param-values #"request__\d+__auto__" '(id)) + (compojure.core/let-request + [[id] #"request__\d+__auto__"] + (metabase.api.common.internal/auto-parse + [id] + (metabase.api.common.internal/validate-param 'id id metabase.util.schema/IntGreaterThanZero) + (metabase.api.common.internal/wrap-response-if-needed (do (select-one Card :id id)))))))) + (macroexpand '(metabase.api.common/defendpoint-schema compojure.core/GET "/:id" [id] + {id metabase.util.schema/IntGreaterThanZero} + (select-one Card :id id))))))) diff --git a/test/metabase/api/table_test.clj b/test/metabase/api/table_test.clj index 7de0314b2b93fce88ec71668fb413754f13f58d4..cb31752dfbfea9438cad8bb4b7918c7fa03de0b5 100644 --- a/test/metabase/api/table_test.clj +++ b/test/metabase/api/table_test.clj @@ -829,7 +829,7 @@ {:field_order :database}) :fields (map :name))))) - (testing "Cane we set custom field ordering?" + (testing "Can we set custom field ordering?" (let [custom-field-order [(mt/id :venues :price) (mt/id :venues :longitude) (mt/id :venues :id) (mt/id :venues :category_id) (mt/id :venues :name) (mt/id :venues :latitude)]] (mt/user-http-request :crowberto :put 200 (format "table/%s/fields/order" (mt/id :venues)) diff --git a/test/metabase/logger_test.clj b/test/metabase/logger_test.clj index b5a028d8560d638c2c84e9c7bc7523957e49b5d1..84a132a4b1784a6eb0b8121b43ce84e58c9290fc 100644 --- a/test/metabase/logger_test.clj +++ b/test/metabase/logger_test.clj @@ -1,40 +1,58 @@ (ns metabase.logger-test (:require + [clojure.string :as str] [clojure.test :refer :all] [clojure.tools.logging :as log] [clojure.tools.logging.impl :as log.impl] [metabase.logger :as mb.logger] - [metabase.test :as mt])) + [metabase.test :as mt]) + (:import + (org.apache.logging.log4j.core Logger))) + +(set! *warn-on-reflection* true) + +(defn logger + (^Logger [] + (logger 'metabase.logger-test)) + (^Logger [ns-symb] + (log.impl/get-logger log/*logger-factory* ns-symb))) (deftest added-appender-tests (testing "appender is added to the logger" - (let [logger (log.impl/get-logger log/*logger-factory* *ns*)] - (is (contains? (.getAppenders logger) "metabase-appender") - "Logger does not contain `metabase-appender` logger"))) + (is (contains? (.getAppenders (logger)) "metabase-appender") + "Logger does not contain `metabase-appender` logger")) (testing "logging adds to in-memory ringbuffer" - (mt/with-log-level :warn - (let [before (count (mb.logger/messages))] - (log/warn "testing in-memory logger") - (let [after (count (mb.logger/messages))] - ;; it either increases (could have many logs from other tests) or it is the max capacity of the ring buffer - (is (or (> after before) - (= before (var-get #'mb.logger/max-log-entries))) - "In memory ring buffer did not receive log message"))))) + (mt/with-log-level :debug + (log/debug "testing in-memory logger") + (is (some (fn [{message :msg, :as entry}] + (when (str/includes? (str message) "testing in-memory logger") + entry)) + (mb.logger/messages)) + "In memory ring buffer did not receive log message"))) (testing "set isAdditive = false if parent logger is root to prevent logging to console (#26468)" (testing "make sure it's true to starts with" - (is (true? (.isAdditive (log.impl/get-logger log/*logger-factory* 'metabase))))) + (is (.isAdditive (logger 'metabase)))) (testing "set to false if parent logger is root" (mt/with-log-level :warn - (is (false? (.isAdditive (log.impl/get-logger log/*logger-factory* 'metabase)))))) + (is (not (.isAdditive (logger 'metabase)))))) (testing "still true if the parent logger is not root" (mt/with-log-level [metabase.logger :warn] - (is (true? (.isAdditive (log.impl/get-logger log/*logger-factory* 'metabase.logger)))))))) + (is (.isAdditive (logger 'metabase.logger))))))) -(deftest logger-test +(deftest ^:parallel logger-test (testing "Using log4j2 logger" - (is (= (log.impl/name log/*logger-factory*) - "org.apache.logging.log4j") + (is (= "org.apache.logging.log4j" + (log.impl/name log/*logger-factory*)) "Not using log4j2 logger factory. This could add two orders of magnitude of time to logging calls"))) + +(deftest logger-respect-configured-log-level-test + (testing "The appender that we programmatically added should respect the log levels in the config file" + ;; whether we're in the REPL or in test mode this should not show up + (log/debug "THIS SHOULD NOT SHOW UP") + (is (not (some (fn [{message :msg, :as entry}] + (when (str/includes? (str message) "THIS SHOULD NOT SHOW UP") + entry)) + (mb.logger/messages)))))) diff --git a/test/metabase/test/util/log.clj b/test/metabase/test/util/log.clj index 897be54129ea43a408e1ecf23cff3a125f6a7e7a..fc8fb5c155b0b3f170ed0f20ed413b71f8042601 100644 --- a/test/metabase/test/util/log.clj +++ b/test/metabase/test/util/log.clj @@ -5,11 +5,15 @@ [clojure.tools.logging :as log] [clojure.tools.logging.impl :as log.impl] [hawk.parallel] + [metabase.plugins.classloader :as classloader] [potemkin :as p] [schema.core :as s]) - (:import [org.apache.logging.log4j Level LogManager] - [org.apache.logging.log4j.core Appender LifeCycle LogEvent Logger LoggerContext] - [org.apache.logging.log4j.core.config Configuration LoggerConfig])) + (:import + (org.apache.logging.log4j Level LogManager) + (org.apache.logging.log4j.core Appender LifeCycle LogEvent Logger LoggerContext) + (org.apache.logging.log4j.core.config Configuration LoggerConfig))) + +(set! *warn-on-reflection* true) (def ^:private keyword->Level {:off Level/OFF @@ -45,7 +49,7 @@ (name a-namespace))) (defn- logger-context ^LoggerContext [] - (LogManager/getContext false)) + (LogManager/getContext (classloader/the-classloader) false)) (defn- configuration ^Configuration [] (.getConfiguration (logger-context))) @@ -90,6 +94,9 @@ (into-array org.apache.logging.log4j.core.config.Property (.getPropertyList parent-logger)) (configuration) (.getFilter parent-logger))] + ;; copy the appenders from the parent logger, e.g. the [[metabase.logger/metabase-appender]] + (doseq [[_name ^Appender appender] (.getAppenders parent-logger)] + (.addAppender new-logger appender (.getLevel new-logger) (.getFilter new-logger))) (.addLogger (configuration) (logger-name a-namespace) new-logger) (.updateLoggers (logger-context)) #_{:clj-kondo/ignore [:discouraged-var]} @@ -110,6 +117,14 @@ (let [logger (exact-ns-logger a-namespace) new-level (->Level new-level)] (.setLevel logger new-level) + ;; it seems like changing the level doesn't update the level for the appenders + ;; e.g. [[metabase.logger/metabase-appender]], so if we want the new level to be reflected there the only way I can + ;; figure out to make it work is to remove the appender and then add it back with the updated level. See JavaDoc + ;; https://logging.apache.org/log4j/2.x/log4j-core/apidocs/org/apache/logging/log4j/core/config/LoggerConfig.html + ;; for more info. There's probably a better way to do this, but I don't know what it is. -- Cam + (doseq [[^String appender-name ^Appender appender] (.getAppenders logger)] + (.removeAppender logger appender-name) + (.addAppender logger appender new-level (.getFilter logger))) (.updateLoggers (logger-context))))) (defn do-with-log-level [a-namespace level thunk] diff --git a/test/metabase/test_runner/assert_exprs.clj b/test/metabase/test_runner/assert_exprs.clj index 83d431e5b8b1fb28462dcecc446eb6645f36bfe1..ce3f57a3e1f666be1c5d5f254217fe634489a2a2 100644 --- a/test/metabase/test_runner/assert_exprs.clj +++ b/test/metabase/test_runner/assert_exprs.clj @@ -1,6 +1,8 @@ (ns metabase.test-runner.assert-exprs - "Custom implementations of [[clojure.test/is]] expressions (i.e., implementations of [[clojure.test/assert-expr]]). - `re=`, `schema=`, `query=`, `sql=`, `=?`, and more." + "Custom implementations of a few [[clojure.test/is]] expressions (i.e., implementations of [[clojure.test/assert-expr]]): + `query=` and `sql=`. + + Other expressions (`re=`, `schema=`, `=?`, and so forth) are implemented with the Hawk test-runner." (:require [clojure.data :as data] [clojure.test :as t]