From d959430ab900c196575639fd6b963cd4821fccb1 Mon Sep 17 00:00:00 2001
From: Cam Saul <1455846+camsaul@users.noreply.github.com>
Date: Fri, 16 Aug 2024 07:17:45 -0700
Subject: [PATCH] Beautiful log message capturing :star: :heart_eyes_cat:
(#28827)
* Beautiful log message capturing :star: :heart_eyes_cat:
* Don't have log.cljs try to load log.capture, don't know how to make that work
* Remove restriction against use in parallel tests
* Fix tests using invalid syntax
* Port legacy tests
* Make this stuff work with Cljs
* Fix bad syntax
* Convert usages of old version of with-log-messages-for-level to new version
* Update other stuff to use the updated macro
* Fix stuff
* Fix Cljs tests
* Fix world's largest test
* Appease Kondo
* Fix comment
* ClojureScript: only emit capture code in dev builds
---
.clj-kondo/config.edn | 58 +++--
.clj-kondo/src/hooks/clojure/test.clj | 2 -
.../src/hooks/metabase/util/log/capture.clj | 26 +++
.../hooks/metabase/util/log/capture_test.clj | 19 ++
.../advanced_config/file/settings_test.clj | 11 +-
.../advanced_config/file_test.clj | 32 +--
.../serialization/v2/e2e_test.clj | 18 +-
.../serialization/v2/entity_ids_test.clj | 9 +-
.../serialization/v2/extract_test.clj | 31 +--
.../serialization/v2/load_test.clj | 36 +--
src/metabase/config.clj | 49 +++-
src/metabase/driver/util.clj | 2 +-
src/metabase/util/log.clj | 22 +-
src/metabase/util/log.cljs | 3 +-
src/metabase/util/log/capture.cljc | 205 +++++++++++++++++
test/metabase/api/dashboard_test.clj | 13 +-
test/metabase/api/database_test.clj | 17 +-
test/metabase/api/session_test.clj | 20 +-
test/metabase/config_test.clj | 12 +
test/metabase/config_test.cljs | 17 ++
.../sql_jdbc/sync/describe_table_test.clj | 25 +-
test/metabase/driver/util_test.clj | 48 ++--
test/metabase/driver_test.clj | 17 +-
test/metabase/lib/swap_test.cljc | 16 +-
test/metabase/models/interface_test.clj | 35 +--
.../public_settings/premium_features_test.clj | 104 +++++----
test/metabase/pulse/render/style_test.clj | 16 +-
.../server/middleware/session_test.clj | 46 ++--
.../metabase/shared/formatting/date_test.cljc | 127 +++++++----
test/metabase/test.clj | 12 +-
test/metabase/test/util/log.clj | 99 +-------
test/metabase/test/util/log.cljs | 34 +--
test/metabase/util/encryption_test.clj | 28 +--
test/metabase/util/log/capture_test.cljc | 214 ++++++++++++++++++
test/metabase/util/log_test.cljc | 51 -----
35 files changed, 963 insertions(+), 511 deletions(-)
create mode 100644 .clj-kondo/src/hooks/metabase/util/log/capture.clj
create mode 100644 .clj-kondo/test/hooks/metabase/util/log/capture_test.clj
create mode 100644 src/metabase/util/log/capture.cljc
create mode 100644 test/metabase/config_test.cljs
create mode 100644 test/metabase/util/log/capture_test.cljc
delete mode 100644 test/metabase/util/log_test.cljc
diff --git a/.clj-kondo/config.edn b/.clj-kondo/config.edn
index 430c86fc126..d9890ea380e 100644
--- a/.clj-kondo/config.edn
+++ b/.clj-kondo/config.edn
@@ -615,13 +615,11 @@
clojure.core.logic/defne clj-kondo.lint-as/def-catch-all
clojure.test.check.clojure-test/defspec clojure.test/deftest
clojurewerkz.quartzite.jobs/defjob clojure.core/defn
- honeysql.helpers/defhelper clj-kondo.lint-as/def-catch-all
- honeysql.util/defalias clojure.core/def
- metabase-enterprise.serialization.test-util/with-random-dump-dir clojure.core/let
metabase-enterprise.serialization.test-util/with-dbs clojure.core/fn
+ metabase-enterprise.serialization.test-util/with-random-dump-dir clojure.core/let
metabase.actions.test-util/with-actions clojure.core/let
- metabase.api.common/let-404 clojure.core/let
metabase.api.common/defroutes clojure.core/def
+ metabase.api.common/let-404 clojure.core/let
metabase.api.search-test/do-test-users clojure.core/let
metabase.async.api-response-test/with-response clojure.core/let
metabase.dashboard-subscription-test/with-dashboard-sub-for-card clojure.core/let
@@ -630,9 +628,9 @@
metabase.db.data-migrations/defmigration clojure.core/def
metabase.db.liquibase/with-liquibase clojure.core/let
metabase.db.schema-migrations-test.impl/with-temp-empty-app-db clojure.core/let
- metabase.driver.mongo.query-processor/mongo-let clojure.core/let
metabase.driver.mongo.connection/with-mongo-client clojure.core/let
metabase.driver.mongo.connection/with-mongo-database clojure.core/let
+ metabase.driver.mongo.query-processor/mongo-let clojure.core/let
metabase.driver.sql-jdbc.actions/with-jdbc-transaction clojure.core/let
metabase.driver.sql-jdbc.connection/with-connection-spec-for-testing-connection clojure.core/let
metabase.driver.sql-jdbc.execute.diagnostic/capturing-diagnostic-info clojure.core/fn
@@ -644,12 +642,12 @@
metabase.public-settings.premium-features/defenterprise-schema clj-kondo.lint-as/def-catch-all
metabase.public-settings.premium-features/define-premium-feature clojure.core/def
metabase.pulse-test/with-pulse-for-card clojure.core/let
+ metabase.query-processor-test.pipeline-queries-test/pmbql-query clojure.core/->
+ metabase.query-processor-test.pipeline-queries-test/run-pmbql-query clojure.core/->
metabase.query-processor.error-type/deferror clojure.core/def
- metabase.query-processor.setup/with-qp-setup clojure.core/let
metabase.query-processor.middleware.cache.impl/with-reducible-deserialized-results clojure.core/let
metabase.query-processor.middleware.process-userland-query-test/with-query-execution clojure.core/let
- metabase.query-processor-test.pipeline-queries-test/pmbql-query clojure.core/->
- metabase.query-processor-test.pipeline-queries-test/run-pmbql-query clojure.core/->
+ metabase.query-processor.setup/with-qp-setup clojure.core/let
metabase.shared.util.namespaces/import-fns potemkin/import-vars
metabase.sync.util/sum-for clojure.core/for
metabase.sync.util/with-emoji-progress-bar clojure.core/let
@@ -658,13 +656,13 @@
metabase.test/defdataset clojure.core/def
metabase.test/let-url clojure.core/let
metabase.test/with-actions clojure.core/let
+ metabase.test/with-grouper-batches! clojure.core/fn
metabase.test/with-open-channels clojure.core/let
metabase.test/with-single-admin-user clojure.core/fn
metabase.test/with-temp-dir clojure.core/let
metabase.test/with-temp-empty-app-db clojure.core/let
metabase.test/with-temp-file clojure.core/let
metabase.test/with-user-in-groups clojure.core/let
- metabase.test/with-grouper-batches! clojure.core/fn
metabase.upload-test/with-upload-table! clojure.core/let
metabase.util.files/with-open-path-to-resource clojure.core/let
metabase.util.malli.defn/defn schema.core/defn
@@ -688,20 +686,21 @@
:hooks
{:analyze-call
- {clojure.core/ns hooks.clojure.core/lint-ns
- cljs.test/deftest hooks.clojure.test/deftest
+ {cljs.test/deftest hooks.clojure.test/deftest
cljs.test/is hooks.clojure.test/is
cljs.test/use-fixtures hooks.clojure.test/use-fixtures
+ clojure.core/ns hooks.clojure.core/lint-ns
clojure.test/deftest hooks.clojure.test/deftest
clojure.test/is hooks.clojure.test/is
clojure.test/use-fixtures hooks.clojure.test/use-fixtures
- metabase-enterprise.cache.config-test/with-temp-persist-models hooks.common/with-seven-bindings
metabase-enterprise.advanced-permissions.models.permissions.application-permissions-test/with-new-group-and-current-graph hooks.common/with-two-top-level-bindings
metabase-enterprise.audit-app.pages-test/with-temp-objects hooks.common/with-one-binding
+ metabase-enterprise.cache.config-test/with-temp-persist-models hooks.common/with-seven-bindings
metabase-enterprise.serialization.test-util/with-temp-dpc hooks.toucan2.tools.with-temp/with-temp
metabase.analytics.prometheus-test/with-prometheus-system hooks.common/with-two-bindings
- metabase.api.automagic-dashboards-test/with-indexed-model hooks.metabase.api.automagic-dashboards-test/with-indexed-model
metabase.api.alert-test/with-alert-in-collection hooks.common/with-four-bindings
+ metabase.api.automagic-dashboards-test/with-indexed-model hooks.metabase.api.automagic-dashboards-test/with-indexed-model
+ metabase.api.card-test/with-card-param-values-fixtures hooks.common/let-one-with-optional-value
metabase.api.card-test/with-persistence-setup hooks.common/with-one-top-level-binding
metabase.api.card-test/with-temp-native-card! hooks.common/with-two-bindings
metabase.api.card-test/with-temp-native-card-with-params! hooks.common/with-two-bindings
@@ -711,7 +710,6 @@
metabase.api.common/defendpoint-async-schema hooks.metabase.api.common/defendpoint
metabase.api.dashboard-test/with-chain-filter-fixtures hooks.common/let-one-with-optional-value
metabase.api.dashboard-test/with-simple-dashboard-with-tabs hooks.common/with-one-binding
- metabase.api.card-test/with-card-param-values-fixtures hooks.common/let-one-with-optional-value
metabase.api.embed-test/do-response-formats hooks.common/with-two-bindings
metabase.api.embed-test/with-chain-filter-fixtures hooks.common/let-one-with-optional-value
metabase.api.embed-test/with-temp-card hooks.common/let-one-with-optional-value
@@ -725,23 +723,23 @@
metabase.api.search-test/with-search-items-in-root-collection hooks.common/do*
metabase.api.user-test/with-temp-user-email hooks.common/with-one-binding
metabase.async.streaming-response-test/with-start-execution-chan hooks.common/with-one-binding
- metabase.db.schema-migrations-test.impl/test-migrations hooks.metabase.db.schema-migrations-test.impl/test-migrations
metabase.dashboard-subscription-test/with-link-card-fixture-for-dashboard hooks.common/let-second
+ metabase.db.schema-migrations-test.impl/test-migrations hooks.metabase.db.schema-migrations-test.impl/test-migrations
metabase.driver.bigquery-cloud-sdk-test/calculate-bird-scarcity hooks.metabase.query-processor-test.expressions-test/calculate-bird-scarcity
metabase.driver/register! hooks.metabase.driver/register!
metabase.legacy-mbql.schema.macros/defclause hooks.metabase.legacy-mbql.schemas.macros/defclause
- metabase.lib.schema.mbql-clause/define-mbql-clause hooks.metabase.lib.schema.mbql-clause/define-mbql-clause
metabase.lib.schema.mbql-clause/define-catn-mbql-clause hooks.metabase.lib.schema.mbql-clause/define-mbql-clause
+ metabase.lib.schema.mbql-clause/define-mbql-clause hooks.metabase.lib.schema.mbql-clause/define-mbql-clause
metabase.lib.schema.mbql-clause/define-tuple-mbql-clause hooks.metabase.lib.schema.mbql-clause/define-mbql-clause
metabase.lib.test-util.macros/$ids hooks.metabase.test.data/$ids
metabase.lib.test-util.macros/mbql-query hooks.metabase.test.data/mbql-query
metabase.lib.test-util.macros/with-testing-against-standard-queries hooks.metabase.lib.test-util.macros/with-testing-against-standard-queries
metabase.models.collection-test/with-collection-hierarchy hooks.common/let-one-with-optional-value
metabase.models.collection-test/with-personal-and-impersonal-collections hooks.common/with-two-bindings
- metabase.models.dashboard-test/with-dash-in-collection hooks.common/with-three-bindings
metabase.models.dashboard-tab-test/with-dashtab-in-personal-collection hooks.common/with-one-top-level-binding
- metabase.models.interface/define-simple-hydration-method hooks.metabase.models.interface/define-hydration-method
+ metabase.models.dashboard-test/with-dash-in-collection hooks.common/with-three-bindings
metabase.models.interface/define-batched-hydration-method hooks.metabase.models.interface/define-hydration-method
+ metabase.models.interface/define-simple-hydration-method hooks.metabase.models.interface/define-hydration-method
metabase.models.pulse-test/with-dashboard-subscription-in-collection hooks.common/with-four-bindings
metabase.models.pulse-test/with-pulse-in-collection hooks.common/with-four-bindings
metabase.models.setting.multi-setting/define-multi-setting hooks.metabase.models.setting/define-multi-setting
@@ -752,6 +750,7 @@
metabase.query-processor-test.filter-test/count-with-filter-clause hooks.metabase.test.data/$ids
metabase.query-processor.middleware.cache-test/with-mock-cache hooks.common/with-two-bindings
metabase.sample-data-test/with-temp-sample-database-db hooks.common/with-one-binding
+ metabase.stale-test/with-stale-items hooks.toucan2.tools.with-temp/with-temp
metabase.test.data.users/with-group hooks.common/let-one-with-optional-value
metabase.test.data/$ids hooks.metabase.test.data/$ids
metabase.test.data/dataset hooks.metabase.test.data/dataset
@@ -759,7 +758,6 @@
metabase.test.data/run-mbql-query hooks.metabase.test.data/mbql-query
metabase.test.util.async/with-open-channels hooks.common/let-with-optional-value-for-last-binding
metabase.test.util.log/with-log-level hooks.common/with-ignored-first-arg
- metabase.test.util.log/with-log-messages-for-level hooks.common/with-ignored-first-arg
metabase.test.util/discard-setting-changes hooks.common/with-ignored-first-arg
metabase.test.util/with-column-remappings hooks.common/with-ignored-first-arg
metabase.test.util/with-non-admin-groups-no-root-collection-perms hooks.common/do*
@@ -770,31 +768,31 @@
metabase.test/discard-setting-changes hooks.common/with-ignored-first-arg
metabase.test/mbql-query hooks.metabase.test.data/mbql-query
metabase.test/query hooks.metabase.test.data/mbql-query
- metabase.test/test-drivers hooks.common/do*
metabase.test/run-mbql-query hooks.metabase.test.data/mbql-query
+ metabase.test/test-drivers hooks.common/do*
metabase.test/with-column-remappings hooks.common/with-ignored-first-arg
metabase.test/with-group hooks.common/let-one-with-optional-value
metabase.test/with-log-level hooks.common/with-ignored-first-arg
- metabase.test/with-log-messages-for-level hooks.common/with-ignored-first-arg
+ metabase.test/with-log-messages-for-level hooks.metabase.util.log.capture/with-log-messages-for-level
metabase.test/with-non-admin-groups-no-root-collection-perms hooks.common/do*
metabase.test/with-temp hooks.toucan2.tools.with-temp/with-temp
- metabase.stale-test/with-stale-items hooks.toucan2.tools.with-temp/with-temp
metabase.test/with-temp-file hooks.metabase.test.util/with-temp-file
metabase.test/with-temporary-setting-values hooks.metabase.test.util/with-temporary-setting-values
- metabase.util/format-color hooks.metabase.util/format-color
- metabase.util.log/trace hooks.metabase.util.log/info
- metabase.util.log/tracef hooks.metabase.util.log/infof
+ metabase.util.log.capture/with-log-messages-for-level hooks.metabase.util.log.capture/with-log-messages-for-level
metabase.util.log/debug hooks.metabase.util.log/info
metabase.util.log/debugf hooks.metabase.util.log/infof
- metabase.util.log/info hooks.metabase.util.log/info
- metabase.util.log/infof hooks.metabase.util.log/infof
- metabase.util.log/warn hooks.metabase.util.log/info
- metabase.util.log/warnf hooks.metabase.util.log/infof
metabase.util.log/error hooks.metabase.util.log/info
metabase.util.log/errorf hooks.metabase.util.log/infof
metabase.util.log/fatal hooks.metabase.util.log/info
metabase.util.log/fatalf hooks.metabase.util.log/infof
- metabase.util.malli.registry/def hooks.metabase.util.malli.registry/def}
+ metabase.util.log/info hooks.metabase.util.log/info
+ metabase.util.log/infof hooks.metabase.util.log/infof
+ metabase.util.log/trace hooks.metabase.util.log/info
+ metabase.util.log/tracef hooks.metabase.util.log/infof
+ metabase.util.log/warn hooks.metabase.util.log/info
+ metabase.util.log/warnf hooks.metabase.util.log/infof
+ metabase.util.malli.registry/def hooks.metabase.util.malli.registry/def
+ metabase.util/format-color hooks.metabase.util/format-color}
:macroexpand
{clojurewerkz.quartzite.jobs/build macros.quartz/build-job
diff --git a/.clj-kondo/src/hooks/clojure/test.clj b/.clj-kondo/src/hooks/clojure/test.clj
index 7464347fab0..54e50edf3b3 100644
--- a/.clj-kondo/src/hooks/clojure/test.clj
+++ b/.clj-kondo/src/hooks/clojure/test.clj
@@ -29,7 +29,6 @@
metabase.test.data.users/with-group-for-user
metabase.test.persistence/with-persistence-enabled
metabase.test.util.log/with-log-level
- metabase.test.util.log/with-log-messages-for-level
metabase.test.util.misc/with-single-admin-user
metabase.test.util/with-all-users-permission
metabase.test.util/with-discarded-collections-perms-changes
@@ -57,7 +56,6 @@
metabase.test/with-group-for-user
metabase.test/with-locale
metabase.test/with-log-level
- metabase.test/with-log-messages-for-level
metabase.test/with-non-admin-groups-no-root-collection-for-namespace-perms
metabase.test/with-non-admin-groups-no-root-collection-perms
metabase.test/with-persistence-enabled
diff --git a/.clj-kondo/src/hooks/metabase/util/log/capture.clj b/.clj-kondo/src/hooks/metabase/util/log/capture.clj
new file mode 100644
index 00000000000..b8e1fe12f69
--- /dev/null
+++ b/.clj-kondo/src/hooks/metabase/util/log/capture.clj
@@ -0,0 +1,26 @@
+(ns hooks.metabase.util.log.capture
+ (:require
+ [clj-kondo.hooks-api :as api]))
+
+(defn with-log-messages-for-level [x]
+ (letfn [(update-binding [[lhs-node _rhs-node]]
+ [lhs-node (api/list-node
+ (list
+ (api/token-node 'clojure.core/fn)
+ (api/vector-node [])))])
+ (update-bindings [bindings-node]
+ (-> (api/vector-node
+ (into []
+ (comp (partition-all 2)
+ (mapcat update-binding))
+ (:children bindings-node)))
+ (with-meta (meta bindings-node))))
+ (update-node [node]
+ (let [[_with-log-messages-for-level bindings & body] (:children node)]
+ (-> (api/list-node
+ (list*
+ (api/token-node 'clojure.core/let)
+ (update-bindings bindings)
+ body))
+ (with-meta (meta node)))))]
+ (update x :node update-node)))
diff --git a/.clj-kondo/test/hooks/metabase/util/log/capture_test.clj b/.clj-kondo/test/hooks/metabase/util/log/capture_test.clj
new file mode 100644
index 00000000000..9d7f33b31ed
--- /dev/null
+++ b/.clj-kondo/test/hooks/metabase/util/log/capture_test.clj
@@ -0,0 +1,19 @@
+(ns hooks.metabase.util.log.capture-test
+ (:require
+ [clj-kondo.hooks-api :as api]
+ [clojure.test :refer :all]
+ [hooks.metabase.util.log.capture]))
+
+(deftest ^:parallel with-log-messages-for-level-test
+ (is (= '(clojure.core/let [messages-1 (clojure.core/fn [])
+ messages-2 (clojure.core/fn [])]
+ (concat (messages-1)
+ (messages-2)))
+ (-> (hooks.metabase.util.log.capture/with-log-messages-for-level
+ {:node (-> '(with-log-messages-for-level [messages-1 [my.namespace :debug]
+ messages-2 :info]
+ (concat (messages-1) (messages-2)))
+ pr-str
+ api/parse-string)})
+ :node
+ api/sexpr))))
diff --git a/enterprise/backend/test/metabase_enterprise/advanced_config/file/settings_test.clj b/enterprise/backend/test/metabase_enterprise/advanced_config/file/settings_test.clj
index d2658f0dc1f..9ed4550a4f6 100644
--- a/enterprise/backend/test/metabase_enterprise/advanced_config/file/settings_test.clj
+++ b/enterprise/backend/test/metabase_enterprise/advanced_config/file/settings_test.clj
@@ -38,9 +38,8 @@
(testing "Invalid Setting (does not exist) should log a warning and continue."
(binding [advanced-config.file/*config* {:version 1
:config {:settings {:config-from-file-settings-test-setting-FAKE 1000}}}]
-
- (let [log-messages (mt/with-log-messages-for-level [metabase-enterprise.advanced-config.file.settings :warn]
- (is (= :ok
- (advanced-config.file/initialize!))))]
- (is (= [[:warn nil (u/colorize :yellow "Ignoring unknown setting in config: config-from-file-settings-test-setting-FAKE.")]]
- log-messages)))))))
+ (mt/with-log-messages-for-level [messages [metabase-enterprise.advanced-config.file.settings :warn]]
+ (is (= :ok
+ (advanced-config.file/initialize!)))
+ (is (=? [{:level :warn, :message (u/colorize :yellow "Ignoring unknown setting in config: config-from-file-settings-test-setting-FAKE.")}]
+ (messages))))))))
diff --git a/enterprise/backend/test/metabase_enterprise/advanced_config/file_test.clj b/enterprise/backend/test/metabase_enterprise/advanced_config/file_test.clj
index 9a45478af0e..c2967b4bc18 100644
--- a/enterprise/backend/test/metabase_enterprise/advanced_config/file_test.clj
+++ b/enterprise/backend/test/metabase_enterprise/advanced_config/file_test.clj
@@ -30,14 +30,16 @@
(binding [advanced-config.file/*env* (assoc @#'advanced-config.file/*env* :mb-config-file-path filename)]
(is (= {:version 1
:config {:settings {:my-setting "abc123"}}}
- (#'advanced-config.file/config))))))
+ (#'advanced-config.file/config)))))))
+
+(deftest ^:parallel config-test-2
(testing "Support overriding config with dynamic var for mocking purposes"
(binding [advanced-config.file/*config* mock-yaml]
(is (= {:version 1
:config {:settings {:my-setting "abc123"}}}
(#'advanced-config.file/config))))))
-(deftest validate-config-test
+(deftest ^:parallel validate-config-test
(testing "Config should throw an error"
(testing "if it is not a map"
(binding [advanced-config.file/*config* [1 2 3 4]]
@@ -71,14 +73,16 @@
(defn- mock-config-with-setting [s]
{:version 1.0, :config {:settings {:my-setting s}}})
-(deftest expand-template-forms-test
+(deftest ^:parallel expand-template-forms-test
(testing "Ignore single curly brackets, or brackets with spaces between them"
(are [s] (= (mock-config-with-setting s)
(binding [advanced-config.file/*config* (mock-config-with-setting s)]
(#'advanced-config.file/config)))
"{}}"
"{}}"
- "{ {}}"))
+ "{ {}}")))
+
+(deftest ^:parallel expand-template-forms-test-2
(testing "Invalid template forms"
(are [template error-pattern] (thrown-with-msg?
clojure.lang.ExceptionInfo
@@ -95,14 +99,14 @@
;; unknown template type
"{{bird \"Parrot Hilton\"}}" (re-quote "bird - failed: valid-template-type?"))))
-(deftest recursive-template-form-expansion-test
+(deftest ^:parallel recursive-template-form-expansion-test
(testing "Recursive expansion is unsupported, for now."
(binding [advanced-config.file/*env* (assoc @#'advanced-config.file/*env* :x "{{env Y}}", :y "Y")
advanced-config.file/*config* (mock-config-with-setting "{{env X}}")]
(is (= (mock-config-with-setting "{{env Y}}")
(#'advanced-config.file/config))))))
-(deftest expand-template-env-var-values-test
+(deftest ^:parallel expand-template-env-var-values-test
(testing "env var values"
(binding [advanced-config.file/*env* (assoc @#'advanced-config.file/*env* :config-file-bird-name "Parrot Hilton")]
(testing "Nothing weird"
@@ -128,7 +132,7 @@
(is (= (mock-config-with-setting "Parrot Hilton")
(#'advanced-config.file/config))))))))
-(deftest expand-template-env-var-values-validation-test
+(deftest ^:parallel expand-template-env-var-values-validation-test
(testing "(config) should walk the config map and expand {{template}} forms"
(testing "env var values"
(testing "validation"
@@ -144,7 +148,7 @@
;; wrong env var type
"{{env :SOME_ENV_VAR}}" (re-quote "SOME_ENV_VAR - failed: symbol?"))))))
-(deftest optional-template-test
+(deftest ^:parallel optional-template-test
(testing "[[optional {{template}}]] values"
(binding [advanced-config.file/*env* (assoc @#'advanced-config.file/*env* :my-sensitive-password "~~~SeCrEt123~~~")]
(testing "env var exists"
@@ -173,11 +177,11 @@
(deftest initialize-section-test
(testing "Ignore unknown sections"
(binding [advanced-config.file/*config* {:version 1.0, :config {:unknown-section {}}}]
- (let [log-messages (mt/with-log-messages-for-level [metabase-enterprise.advanced-config.file.interface :warn]
- (is (= :ok
- (advanced-config.file/initialize!))))]
- (is (= [[:warn nil (u/colorize :yellow "Ignoring unknown config section :unknown-section.")]]
- log-messages))))))
+ (mt/with-log-messages-for-level [messages [metabase-enterprise.advanced-config.file.interface :warn]]
+ (is (= :ok
+ (advanced-config.file/initialize!)))
+ (is (=? [{:level :warn, :message (u/colorize :yellow "Ignoring unknown config section :unknown-section.")}]
+ (messages)))))))
(deftest require-advanced-config-test
(testing "Config files should require the `:config-text-file` token feature"
@@ -188,7 +192,7 @@
#"Metabase config files require a Premium token with the :config-text-file feature"
(advanced-config.file/initialize!)))))))
-(deftest error-validation-do-not-leak-env-vars-test
+(deftest ^:parallel error-validation-do-not-leak-env-vars-test
(testing "spec errors should not include contents of env vars -- expand templates after spec validation."
(binding [advanced-config.file/*env* (assoc @#'advanced-config.file/*env* :my-sensitive-password "~~~SeCrEt123~~~")
advanced-config.file/*config* {:version 1
diff --git a/enterprise/backend/test/metabase_enterprise/serialization/v2/e2e_test.clj b/enterprise/backend/test/metabase_enterprise/serialization/v2/e2e_test.clj
index 6b42fe0429a..e9a34efdc4a 100644
--- a/enterprise/backend/test/metabase_enterprise/serialization/v2/e2e_test.clj
+++ b/enterprise/backend/test/metabase_enterprise/serialization/v2/e2e_test.clj
@@ -835,13 +835,13 @@
(spit (io/file dump-dir "collections" "unreadable.yaml") "\0")
(testing "No exceptions when loading despite unreadable files"
- (let [logs (mt/with-log-messages-for-level ['metabase-enterprise :error]
- (let [files (->> (#'ingest/ingest-all (io/file dump-dir))
- (map (comp second second))
- (map #(.getName ^File %))
- set)]
- (testing "Hidden YAML wasn't read even though it's not throwing errors"
- (is (not (contains? files ".hidden.yaml"))))))]
+ (mt/with-log-messages-for-level [logs [metabase-enterprise :error]]
+ (let [files (->> (#'ingest/ingest-all (io/file dump-dir))
+ (map (comp second second))
+ (map #(.getName ^File %))
+ set)]
+ (testing "Hidden YAML wasn't read even though it's not throwing errors"
+ (is (not (contains? files ".hidden.yaml")))))
(testing ".yaml files not containing valid yaml are just logged and do not break ingestion process"
- (is (=? [[:error Throwable "Error reading file unreadable.yaml"]]
- logs))))))))))
+ (is (=? [{:level :error, :e Throwable, :message "Error reading file unreadable.yaml"}]
+ (logs)))))))))))
diff --git a/enterprise/backend/test/metabase_enterprise/serialization/v2/entity_ids_test.clj b/enterprise/backend/test/metabase_enterprise/serialization/v2/entity_ids_test.clj
index 92df54817a0..4b342449590 100644
--- a/enterprise/backend/test/metabase_enterprise/serialization/v2/entity_ids_test.clj
+++ b/enterprise/backend/test/metabase_enterprise/serialization/v2/entity_ids_test.clj
@@ -53,10 +53,11 @@
:entity_id nil}]
;; update table directly so checks for collection existence don't trigger
(t2/update! :collection (:id c3) {:location "/13371338/"})
- (is (=? [[:error Throwable #"Error updating entity ID for \w+ \d+:.*is an orphan.*\{:parent-id \d+\}"]]
- (mt/with-log-messages-for-level ['metabase-enterprise :error]
- (is (= false
- (v2.entity-ids/seed-entity-ids!)))))))))))))
+ (mt/with-log-messages-for-level [messages [metabase-enterprise :error]]
+ (is (= false
+ (v2.entity-ids/seed-entity-ids!)))
+ (is (=? [{:level :error, :e Throwable, :message #"Error updating entity ID for \w+ \d+:.*is an orphan.*\{:parent-id \d+\}"}]
+ (messages)))))))))))
(deftest drop-entity-ids-test
(mt/with-empty-h2-app-db
diff --git a/enterprise/backend/test/metabase_enterprise/serialization/v2/extract_test.clj b/enterprise/backend/test/metabase_enterprise/serialization/v2/extract_test.clj
index f490e28bea4..9e9afab15f8 100644
--- a/enterprise/backend/test/metabase_enterprise/serialization/v2/extract_test.clj
+++ b/enterprise/backend/test/metabase_enterprise/serialization/v2/extract_test.clj
@@ -1645,22 +1645,23 @@
:dataset_query {:query {:source-table (str "card__" card1-id)
:aggregation [[:count]]}}}]
(testing "Complain about card not available for exporting"
- (is (some #(str/starts-with? % "Failed to export Dashboard")
- (into #{}
- (map (fn [[_log-level _error message]] message))
- (mt/with-log-messages-for-level ['metabase-enterprise :warn]
- (extract/extract {:targets [["Collection" coll1-id]]
- :no-settings true
- :no-data-model true}))))))
-
+ (mt/with-log-messages-for-level [messages [metabase-enterprise :warn]]
+ (extract/extract {:targets [["Collection" coll1-id]]
+ :no-settings true
+ :no-data-model true})
+ (is (some #(str/starts-with? % "Failed to export Dashboard")
+ (into #{}
+ (map :message)
+ (messages))))))
(testing "Complain about card depending on an outside card"
- (is (some #(str/starts-with? % "Failed to export Cards")
- (into #{}
- (map (fn [[_log-level _error message]] message))
- (mt/with-log-messages-for-level ['metabase-enterprise :warn]
- (extract/extract {:targets [["Collection" coll2-id]]
- :no-settings true
- :no-data-model true})))))))))
+ (mt/with-log-messages-for-level [messages [metabase-enterprise :warn]]
+ (extract/extract {:targets [["Collection" coll2-id]]
+ :no-settings true
+ :no-data-model true})
+ (is (some #(str/starts-with? % "Failed to export Cards")
+ (into #{}
+ (map :message)
+ (messages)))))))))
(deftest recursive-colls-test
(mt/with-empty-h2-app-db
diff --git a/enterprise/backend/test/metabase_enterprise/serialization/v2/load_test.clj b/enterprise/backend/test/metabase_enterprise/serialization/v2/load_test.clj
index 35ad573b920..5398b4f6bd5 100644
--- a/enterprise/backend/test/metabase_enterprise/serialization/v2/load_test.clj
+++ b/enterprise/backend/test/metabase_enterprise/serialization/v2/load_test.clj
@@ -1205,7 +1205,7 @@
(merge entity (get changes (:entity_id entity))))))
logs-extract (fn [re logs]
(keep #(rest (re-find re %))
- (map (fn [[_log-level _error message]] message) logs)))]
+ (map :message logs)))]
(mt/with-empty-h2-app-db
(mt/with-temp [Collection coll {:name "coll"}
Card c1 {:name "card1" :collection_id (:id coll)}
@@ -1217,26 +1217,28 @@
(if (= (:entity_id instance) (:entity_id c1))
(throw (ex-info "Skip me" {}))
(extract-one model-name opts instance)))]
- (is (= [["Card" (str (:id c1))]]
- (logs-extract #"Skipping (\w+) (\d+)"
- (mt/with-log-messages-for-level ['metabase.models.serialization :warn]
- (let [ser (vec (serdes.extract/extract {:no-settings true
- :no-data-model true
- :continue-on-error true}))
- {errors true
- others false} (group-by #(instance? Exception %) ser)]
- (is (= 1 (count errors)))
- (is (= 3 (count others)))))))))))
+ (mt/with-log-messages-for-level [messages [metabase.models.serialization :warn]]
+ (let [ser (vec (serdes.extract/extract {:no-settings true
+ :no-data-model true
+ :continue-on-error true}))
+ {errors true
+ others false} (group-by #(instance? Exception %) ser)]
+ (is (= 1 (count errors)))
+ (is (= 3 (count others))))
+ (is (= [["Card" (str (:id c1))]]
+ (logs-extract #"Skipping (\w+) (\d+)"
+ (messages))))))))
(testing "It's possible to skip a few errors during load"
(let [ser (vec (serdes.extract/extract {:no-settings true
:no-data-model true}))
changed (change-ser ser {(:entity_id c2) {:collection_id "does-not-exist"}})]
- (is (= [["Failed to read file for Collection does-not-exist"]]
- (logs-extract #"Skipping deserialization error: (.*) \{.*\}$"
- (mt/with-log-messages-for-level ['metabase-enterprise :warn]
- (let [report (serdes.load/load-metabase! (ingestion-in-memory changed) {:continue-on-error true})]
- (is (= 1 (count (:errors report))))
- (is (= 3 (count (:seen report)))))))))))))))
+ (mt/with-log-messages-for-level [messages [metabase-enterprise :warn]]
+ (let [report (serdes.load/load-metabase! (ingestion-in-memory changed) {:continue-on-error true})]
+ (is (= 1 (count (:errors report))))
+ (is (= 3 (count (:seen report)))))
+ (is (= [["Failed to read file for Collection does-not-exist"]]
+ (logs-extract #"Skipping deserialization error: (.*) \{.*\}$"
+ (messages)))))))))))
(deftest with-dbs-works-as-expected-test
(ts/with-dbs [source-db dest-db]
diff --git a/src/metabase/config.clj b/src/metabase/config.clj
index 991e952616f..95349704190 100644
--- a/src/metabase/config.clj
+++ b/src/metabase/config.clj
@@ -4,7 +4,7 @@
[clojure.java.io :as io]
[clojure.string :as str]
[environ.core :as env]
- [metabase.plugins.classloader :as classloader])
+ [net.cgrand.macrovich :as macros])
(:import
(clojure.lang Keyword)))
@@ -13,7 +13,7 @@
;; this existed long before 0.39.0, but that's when it was made public
(def ^{:doc "Indicates whether Enterprise Edition extensions are available" :added "0.39.0"} ee-available?
(try
- (classloader/require 'metabase-enterprise.core)
+ (require 'metabase-enterprise.core)
true
(catch Throwable _
false)))
@@ -22,7 +22,7 @@
"Whether code from `./test` is available. This is mainly to facilitate certain things like test QP middleware that we
want to load only when test code is present."
(try
- (classloader/require 'metabase.test.core)
+ (require 'metabase.test.core)
true
(catch Throwable _
false)))
@@ -165,5 +165,46 @@
(not (false? (config-bool :mb-load-sample-content))))
(def ^:dynamic *request-id*
- "A unique identifier for the current request. This is bound by `metabase.server.middleware.request-id/wrap-request-id`."
+ "A unique identifier for the current request. This is bound by
+ `metabase.server.middleware.request-id/wrap-request-id`."
nil)
+
+(defmacro build-type-case
+ "Sort of like [[macros/case]] but emits different code for dev or release builds. Useful if you want macros to emit
+ extra stuff for debugging only in dev builds -- for example [[metabase.util.log]] macros emit extra code for
+ capturing logs in tests only in `:dev` builds.
+
+ Accepts the following keys:
+
+ * `:clj/dev` -- form will only be emitted if this is a Clj dev build (running from the REPL or running tests).
+
+ * `:cljs/dev` -- form will only be emitted if this is a Cljs dev build (running Cljs REPL or tests, or was triggered
+ by a yarn `build` command other than `build-release`.
+
+ * `:dev` -- form will only be emitted if this is a Clj or Cljs dev build. Cannot be used in combination with
+ `:clj/dev` or `:cljs/dev`.
+
+ * `:clj/release` -- form will only be emitted for non-dev Clj builds (i.e. the uberjar or `clj -M:run`) -- whenever
+ dev/test code is not available on the classpath)
+
+ * `:cljs/release` -- form will only be emitted for release Cljs builds (i.e., `yarn build-release` and friends)
+
+ * `:release` -- form will be emitted if this is a Clj or Cljs release build. Cannot be used in combination with
+ `:clj/release` or `:cljs/release`."
+ {:style/indent 0}
+ [& {:keys [dev release], cljs-dev :cljs/dev, cljs-release :cljs/release, clj-dev :clj/dev, clj-release :clj/release}]
+ (assert (not (and dev (or clj-dev cljs-dev)))
+ "Cannot specify dev in combination with clj-dev/cljs-dev")
+ (assert (not (and release (or clj-release cljs-release)))
+ "Cannot specify release in combination with clj-release/cljs-release")
+ (let [build-type (macros/case :clj (if tests-available?
+ :clj/dev
+ :clj/release)
+ :cljs (case (:shadow.build/mode &env)
+ :dev :cljs/dev
+ :release :cljs/release))]
+ (case build-type
+ :clj/dev (or dev clj-dev)
+ :cljs/dev (or dev cljs-dev)
+ :clj/release (or release clj-release)
+ :cljs/release (or release cljs-release))))
diff --git a/src/metabase/driver/util.clj b/src/metabase/driver/util.clj
index 6532d32bdc4..4c1dc85d2b0 100644
--- a/src/metabase/driver/util.clj
+++ b/src/metabase/driver/util.clj
@@ -245,7 +245,7 @@
(u/with-timeout supports?-timeout-ms
(driver/database-supports? driver feature database))
(catch Throwable e
- (log/error e (u/format-color 'red "Failed to check feature '%s' for database '%s'" (name feature) (:name database)))
+ (log/error e (u/format-color 'red "Failed to check feature '%s' for database '%s'" (u/qualified-name feature) (:name database)))
false))))
(def ^:private memoized-supports?*
diff --git a/src/metabase/util/log.clj b/src/metabase/util/log.clj
index 85d750714cd..13d8e05d6f5 100644
--- a/src/metabase/util/log.clj
+++ b/src/metabase/util/log.clj
@@ -8,6 +8,8 @@
#_{:clj-kondo/ignore [:discouraged-namespace]}
[clojure.tools.logging]
[clojure.tools.logging.impl]
+ [metabase.config :as config]
+ [metabase.util.log.capture]
[net.cgrand.macrovich :as macros]))
;;; --------------------------------------------- CLJ-side macro helpers ---------------------------------------------
@@ -78,17 +80,25 @@
You shouldn't have to use this directly; prefer the level-specific macros like [[info]]."
{:arglists '([level message & more] [level throwable message & more])}
[level x & more]
- (macros/case
- :cljs (glogi-logp (str *ns*) level x more)
- :clj (tools-logp *ns* level x more)))
+ `(do
+ ~(config/build-type-case
+ :dev
+ `(metabase.util.log.capture/capture-logp ~(str *ns*) ~level ~x ~@more))
+ ~(macros/case
+ :cljs (glogi-logp (str *ns*) level x more)
+ :clj (tools-logp *ns* level x more))))
(defmacro logf
"Implementation for printf-style `logf`.
You shouldn't have to use this directly; prefer the level-specific macros like [[infof]]."
[level x & args]
- (macros/case
- :cljs (glogi-logf (str *ns*) level x args)
- :clj (tools-logf *ns* level x args)))
+ `(do
+ ~(config/build-type-case
+ :dev
+ `(metabase.util.log.capture/capture-logf ~(str *ns*) ~level ~x ~@args))
+ ~(macros/case
+ :cljs (glogi-logf (str *ns*) level x args)
+ :clj (tools-logf *ns* level x args))))
;;; --------------------------------------------------- Public API ---------------------------------------------------
(defmacro trace
diff --git a/src/metabase/util/log.cljs b/src/metabase/util/log.cljs
index 6b128333330..f2d0552ff98 100644
--- a/src/metabase/util/log.cljs
+++ b/src/metabase/util/log.cljs
@@ -4,7 +4,8 @@
[goog.string :as gstring]
[goog.string.format :as gstring.format]
[lambdaisland.glogi :as log]
- [lambdaisland.glogi.console :as glogi-console])
+ [lambdaisland.glogi.console :as glogi-console]
+ [metabase.util.log.capture])
(:require-macros
[metabase.util.log]))
diff --git a/src/metabase/util/log/capture.cljc b/src/metabase/util/log/capture.cljc
new file mode 100644
index 00000000000..560d52d37ad
--- /dev/null
+++ b/src/metabase/util/log/capture.cljc
@@ -0,0 +1,205 @@
+(ns metabase.util.log.capture
+ "Only used in tests and dev runs.
+
+ Basic idea is we have a dynamic variable called [[*capture-logs-fn*]] with the signature
+
+ (f namespace-str level-int)
+
+ and if the logs should be captured at that level, it returns a function with the signature
+
+ (f e message)
+
+ that you should call with the logged exception (if any) and logged message to capture the message.
+
+ Then the actual implementation can basically compose [[*capture-logs-fn*]] so you can have multiple functions capturing
+ logs.
+
+ The impl can store the logs in an atom or whatever that you can get later."
+ (:require
+ [clojure.set :as set]
+ [clojure.spec.alpha :as s]
+ [clojure.string :as str]
+ #?@(:cljs
+ [[goog.string :as gstring]])))
+
+(def ^:dynamic *capture-logs-fn*
+ "Function with the signature that given a namespace string and log level (as an int), returns a function that should
+ be used to capture a log message, if messages at that level should be captured. Its signature is
+
+ (f namespace-str level-int) => (f e message) "
+ (constantly nil))
+
+;;; Code below converts log levels to integers right away, because a simple int comparison like `(<= 5 4)` is super
+;;; quick, and definitely quicker than `(<= (level->int :trace) (level->int :debug))`. So we do the conversions at
+;;; macroexpansion time
+
+(def ^:private level->int
+ {:explode 0
+ :fatal 1
+ :error 2
+ :warn 3
+ :info 4
+ :debug 5
+ :trace 6
+ :whisper 7})
+
+(def ^:private int->level
+ (set/map-invert level->int))
+
+(defn- capture-logs-fn [logs captured-namespace captured-level-int]
+ ;; the prefix stuff is calculated outside of the function so we can be SUPER OPTIMIZED and not do anything
+ ;; allocation in cases where we're not going to capture anything.
+ (let [captured-namespace-prefix (str captured-namespace \.)]
+ (fn [message-namespace message-level-int]
+ ;; similarly, the level comparison is done first, because it's faster and will hopefully filter out a lot of
+ ;; things we weren't going to capture anyway before we do the more expensive namespace check
+ (when (and (<= message-level-int captured-level-int)
+ (or (= message-namespace captured-namespace)
+ (str/starts-with? message-namespace captured-namespace-prefix)))
+ ;; VERY IMPORTANT! Only return the capturing function if we actually want to capture a log message.
+ (fn capture-fn [e message]
+ (swap! logs conj {:namespace (symbol message-namespace)
+ :level (int->level message-level-int)
+ :e e
+ :message message}))))))
+
+(defn do-with-log-messages-for-level
+ "Impl for [[with-log-messages-for-level]]."
+ [captured-namespace captured-level-int f]
+ (let [logs (atom [])
+ old-capture-fn *capture-logs-fn*
+ capture-fn (capture-logs-fn logs captured-namespace captured-level-int)]
+ (binding [*capture-logs-fn* (fn composed-fn [a-message message-level-int]
+ (let [f1 (old-capture-fn a-message message-level-int)
+ f2 (capture-fn a-message message-level-int)]
+ (cond
+ (and f1 f2) (fn [e message]
+ (f1 e message)
+ (f2 e message))
+ f1 f1
+ f2 f2)))]
+ (f (fn [] @logs)))))
+
+(s/def ::namespace
+ (some-fn symbol? string?))
+
+(s/def ::level
+ #{:explode :fatal :error :warn :info :debug :trace :whisper})
+
+(s/def ::with-log-messages-for-level-args
+ (s/cat :bindings (s/spec (s/+ (s/cat :messages-fn-binding symbol?
+ :ns-level (s/or :ns-level (s/spec (s/cat :ns-str ::namespace
+ :level ::level))
+ :ns ::namespace
+ :level ::level))))
+ :body (s/+ any?)))
+
+(defmacro with-log-messages-for-level
+ "Capture log messages at a given level in a given namespace and all 'child' namespaces inside `body`.
+
+ Captured logs can be accessed by invoking `messages-fn-binding`. `ns-level` can be either a namespace, level, or
+ both, i.e. one of the following options:
+
+ 1. A namespace string or symbol; assumes level `:trace`. Capture all log message in that namespace and any 'child'
+ namespaces
+
+ 2. A level keyword like `:trace`; assumes namespace is `metabase`, i.e. captures log messages from any namespace
+ that starts with `metabase.`
+
+ 3. A vector of [namespace level], e.g. `[my.namespace :debug]`, which would capture all `:debug` and `:trace`
+ messages inside `my.namespace`, `my.namespace.x`, etc.
+
+ A code example is worth a thousand-word docstring, so here is an example
+
+ (log.capture/with-log-messages-for-level [messages [metabase.util.log.capture-test :trace]]
+ (is (= []
+ (messages)))
+ (log/trace \"message\")
+ (is (= [{:namespace 'metabase.util.log.capture-test
+ :level :trace
+ :e nil
+ :message \"message\"}]
+ (messages))))
+
+ See [[metabase.util.log.capture-test]] for more example usages.
+
+ You can pass multiple bindings to this macro without them affecting one another, regardless of whether the things
+ they capture overlap or not. See [[metabase.util.log.capture-test/multiple-captures-test]] for an example."
+ {:arglists '([[messages-fn-binding ns-level & more-bindings] & body])}
+ [& args]
+ (let [{:keys [bindings body]} (s/conform ::with-log-messages-for-level-args args)]
+ (reduce
+ (fn [form bindings]
+ (let [{:keys [messages-fn-binding ns-level]} bindings
+ [ns-level-type ns-level] ns-level
+ {:keys [ns-str level]} (case ns-level-type
+ :ns-level ns-level
+ :ns {:ns-str ns-level, :level :trace}
+ :level {:ns-str "metabase", :level ns-level})]
+ `(do-with-log-messages-for-level ~(str ns-str) ~(level->int level) (fn [~messages-fn-binding] ~form))))
+ `(do ~@body)
+ bindings)))
+
+(s/fdef with-log-messages-for-level
+ :args ::with-log-messages-for-level-args
+ :ret any?)
+
+;;; The macroexpansion of something like
+;;;
+;;; (log/trace "a picture")
+;;;
+;;; becomes
+;;;
+;;; (do
+;;; (metabase.util.log.capture/capture-logp
+;;; "metabase.util.log.capture-test"
+;;; :trace
+;;; "a picture")
+;;; ;; clojure.tools.logging stuff
+;;; ...)
+;;;
+;;; becomes
+;;;
+;;; (do
+;;; (when-let [f# (metabase.util.log.capture/*capture-logs-fn*
+;;; "metabase.util.log.capture-test"
+;;; 5)]
+;;; (metabase.util.log.capture/capture-logp! f# "a picture"))
+;;; ...)
+;;;
+;;; VERY VERY IMPORTANT! [[*capture-logs-fn*]] only returns a function if logs for that namespace AND level are to be
+;;; captured! Only then is [[capture-logp!]] or [[capture-logf!]], which ultimately call the returned function `f#`,
+;;; called with the args to the logging macro -- and only then do they get evaluated! It's super important not to
+;;; evaluate the log args unless we actually want to capture them! They might be very expensive!
+
+(defn- parse-args [[x & more]]
+ (if (instance? #?(:clj Throwable :cljs js/Error) x)
+ {:e x, :args more}
+ {:args (cons x more)}))
+
+(defn capture-logp!
+ "Impl for log message capturing for [[metabase.util.log/logp]]."
+ [f & args]
+ (let [{:keys [e args]} (parse-args args)]
+ (f e (str/join \space (map print-str args)))))
+
+(defn capture-logf!
+ "Impl for log message capturing for [[metabase.util.log/logf]]."
+ [f & args]
+ (let [{e :e, [format-string & args] :args} (parse-args args)]
+ #_{:clj-kondo/ignore [:unresolved-namespace]}
+ (f e (apply #?(:clj format
+ :cljs gstring/format)
+ format-string args))))
+
+(defmacro capture-logp
+ "Impl for log message capturing for [[metabase.util.log/logp]]."
+ [namespace-str level & args]
+ `(when-let [f# (*capture-logs-fn* ~namespace-str ~(level->int level))]
+ (capture-logp! f# ~@args)))
+
+(defmacro capture-logf
+ "Impl for log message capturing for [[metabase.util.log/logf]]."
+ [namespace-str level & args]
+ `(when-let [f# (*capture-logs-fn* ~namespace-str ~(level->int level))]
+ (capture-logf! f# ~@args)))
diff --git a/test/metabase/api/dashboard_test.clj b/test/metabase/api/dashboard_test.clj
index db3a7d69267..8081a8521c4 100644
--- a/test/metabase/api/dashboard_test.clj
+++ b/test/metabase/api/dashboard_test.clj
@@ -665,13 +665,13 @@
(into {} (for [[field-id m] response]
[field-id (update m :values (partial take 3))]))))))))))
-(deftest fetch-a-dashboard-with-param-linked-to-a-field-filter-that-is-not-existed
+(deftest ^:parallel fetch-a-dashboard-with-param-linked-to-a-field-filter-that-is-not-existed
(testing "when fetching a dashboard that has a param linked to a field filter that no longer exists, we shouldn't throw an error (#15494)"
(mt/with-temp
[:model/Card {card-id :id} {:name "Native card"
:database_id (mt/id)
:dataset_query (mt/native-query
- {:query "SELECT category FROM products LIMIT 10;"})
+ {:query "SELECT category FROM products LIMIT 10;"})
:type :model}
:model/Dashboard {dash-id :id} {:parameters [{:name "Text"
:slug "text"
@@ -683,10 +683,11 @@
:parameter_mappings [{:parameter_id "_TEXT_"
:card_id card-id
:target [:dimension [:template-tag "not-existed-filter"]]}]}]
- (is (= (repeat 2 [:error nil
- "Could not find matching field clause for target: [:dimension [:template-tag not-existed-filter]]"])
- (mt/with-log-messages-for-level ['metabase.models.params :error]
- (is (some? (mt/user-http-request :rasta :get 200 (str "dashboard/" dash-id))))))))))
+ (mt/with-log-messages-for-level [messages [metabase.models.params :error]]
+ (is (some? (mt/user-http-request :rasta :get 200 (str "dashboard/" dash-id))))
+ (is (=? (repeat 2 {:level :error
+ :message "Could not find matching field clause for target: [:dimension [:template-tag not-existed-filter]]"})
+ (messages)))))))
(deftest param-values-not-fetched-on-load-test
(testing "Param values are not needed on initial dashboard load and should not be fetched. #38826"
diff --git a/test/metabase/api/database_test.clj b/test/metabase/api/database_test.clj
index 027cf337e7f..d30e5845344 100644
--- a/test/metabase/api/database_test.clj
+++ b/test/metabase/api/database_test.clj
@@ -2094,16 +2094,17 @@
:unaggregated-query-row-limit (symbol "nil #_\"key is not present.\"")}
(settings)))))))))
-(deftest log-an-error-if-contains-undefined-setting-test
+(deftest ^:paralell log-an-error-if-contains-undefined-setting-test
(testing "should log an error message if database contains undefined settings"
(t2.with-temp/with-temp [Database {db-id :id} {:settings {:undefined-setting true}}]
- (is (= "Error checking the readability of :undefined-setting setting. The setting will be hidden in API response."
- (-> (mt/with-log-messages-for-level :error
- (testing "does not includes undefined keys by default"
- (is (not (contains? (:settings (mt/user-http-request :crowberto :get 200 (str "database/" db-id)))
- :undefined-setting)))))
- first
- last))))))
+ (mt/with-log-messages-for-level [messages :error]
+ (testing "does not includes undefined keys by default"
+ (is (not (contains? (:settings (mt/user-http-request :crowberto :get 200 (str "database/" db-id)))
+ :undefined-setting))))
+ (is (= "Error checking the readability of :undefined-setting setting. The setting will be hidden in API response."
+ (-> (messages)
+ first
+ :message)))))))
(deftest persist-database-test-2
(mt/test-drivers (mt/normal-drivers-with-feature :persist-models)
diff --git a/test/metabase/api/session_test.clj b/test/metabase/api/session_test.clj
index 2bf18a01715..0d3e1bbb3c5 100644
--- a/test/metabase/api/session_test.clj
+++ b/test/metabase/api/session_test.clj
@@ -4,6 +4,7 @@
[cheshire.core :as json]
[clj-http.client :as http]
[clojure.test :refer :all]
+ [medley.core :as m]
[metabase.api.session :as api.session]
[metabase.driver.h2 :as h2]
[metabase.email.messages :as messages]
@@ -73,12 +74,12 @@
(is (nil? (get-in response [:cookies session-cookie :expires]))))))
(testing "failure should log an error(#14317)"
(t2.with-temp/with-temp [User user]
- (is (=? [:error clojure.lang.ExceptionInfo "Authentication endpoint error"]
- (->> (mt/with-log-messages-for-level :error
- (mt/client :post 400 "session" {:email (:email user), :password "wooo"}))
- ;; geojson can throw errors and we want the authentication error
- (filter (fn [[_log-level _error message]] (= message "Authentication endpoint error")))
- first))))))
+ (mt/with-log-messages-for-level [messages :error]
+ (mt/client :post 400 "session" {:email (:email user), :password "wooo"})
+ (is (=? {:level :error, :e clojure.lang.ExceptionInfo, :message "Authentication endpoint error"}
+ (->> (messages)
+ ;; geojson can throw errors and we want the authentication error
+ (m/find-first #(= (:message %) "Authentication endpoint error")))))))))
(deftest login-validation-test
(reset-throttlers!)
@@ -115,9 +116,10 @@
(is (re= #"^Too many attempts! You must wait \d+ seconds before trying again\.$"
(login))))
(testing "Error should be logged (#14317)"
- (is (=? [:error clojure.lang.ExceptionInfo "Authentication endpoint error"]
- (first (mt/with-log-messages-for-level :error
- (login))))))
+ (mt/with-log-messages-for-level [messages :error]
+ (login)
+ (is (=? {:level :error, :e clojure.lang.ExceptionInfo, :message "Authentication endpoint error"}
+ (first (messages))))))
(is (re= #"^Too many attempts! You must wait \d+ seconds before trying again\.$"
(login))
"Trying to login immediately again should still return throttling error"))))
diff --git a/test/metabase/config_test.clj b/test/metabase/config_test.clj
index 6b65b68d7d8..9c9f879bc92 100644
--- a/test/metabase/config_test.clj
+++ b/test/metabase/config_test.clj
@@ -16,3 +16,15 @@
(with-redefs [env/env (assoc env/env :max-session-age nil)]
(is (= "20160"
(config/config-str :max-session-age))))))
+
+(deftest ^:parallel build-type-case-test
+ (testing "Make sure [[config/build-type-case]] works correctly for Clojure."
+ (is (= :dev
+ (config/build-type-case
+ :dev :dev
+ :release :release)))
+ (is (= :clj/dev
+ (config/build-type-case
+ :clj/dev :clj/dev
+ :cljs/dev :cljs/dev
+ :release :release)))))
diff --git a/test/metabase/config_test.cljs b/test/metabase/config_test.cljs
new file mode 100644
index 00000000000..d7ab7ed1052
--- /dev/null
+++ b/test/metabase/config_test.cljs
@@ -0,0 +1,17 @@
+(ns metabase.config-test
+ (:require
+ [clojure.test :refer [deftest is testing]])
+ (:require-macros
+ [metabase.config :as config]))
+
+(deftest ^:parallel build-type-case-test
+ (testing "Make sure [[config/build-type-case]] works correctly for ClojureScript."
+ (is (= :dev
+ (config/build-type-case
+ :dev :dev
+ :release :release)))
+ (is (= :cljs/dev
+ (config/build-type-case
+ :clj/dev :clj/dev
+ :cljs/dev :cljs/dev
+ :release :release)))))
diff --git a/test/metabase/driver/sql_jdbc/sync/describe_table_test.clj b/test/metabase/driver/sql_jdbc/sync/describe_table_test.clj
index 1089fd73272..fc32711e03e 100644
--- a/test/metabase/driver/sql_jdbc/sync/describe_table_test.clj
+++ b/test/metabase/driver/sql_jdbc/sync/describe_table_test.clj
@@ -379,24 +379,25 @@
[{:field-name "big_json" :base-type :type/JSON}]
[[(json/generate-string (into {} (for [x (range 300)] [x :dobbs])))]]]])
-(deftest describe-big-nested-field-columns-test
+(deftest ^:parallel describe-big-nested-field-columns-test
(mt/test-drivers (mt/normal-drivers-with-feature :nested-field-columns)
(mt/dataset big-json
(when-not (mysql/mariadb? (mt/db))
(testing "limit if huge. limit it and yell warning (#23635)"
(is (= sql-jdbc.describe-table/max-nested-field-columns
(count
- (sql-jdbc.sync/describe-nested-field-columns
- driver/*driver*
- (mt/db)
- {:name "big_json_table" :id (mt/id "big_json_table")}))))
- (is (str/includes?
- (get-in (mt/with-log-messages-for-level :warn
- (sql-jdbc.sync/describe-nested-field-columns
- driver/*driver*
- (mt/db)
- {:name "big_json_table" :id (mt/id "big_json_table")})) [0 2])
- "More nested field columns detected than maximum.")))))))
+ (sql-jdbc.sync/describe-nested-field-columns
+ driver/*driver*
+ (mt/db)
+ {:name "big_json_table" :id (mt/id "big_json_table")}))))
+ (mt/with-log-messages-for-level [messages :warn]
+ (sql-jdbc.sync/describe-nested-field-columns
+ driver/*driver*
+ (mt/db)
+ {:name "big_json_table" :id (mt/id "big_json_table")})
+ (is (str/includes?
+ (-> (messages) first :message)
+ "More nested field columns detected than maximum."))))))))
(deftest ^:parallel big-nested-field-column-test
(mt/test-drivers (mt/normal-drivers-with-feature :nested-field-columns)
diff --git a/test/metabase/driver/util_test.clj b/test/metabase/driver/util_test.clj
index fa4f3cfb500..ea821da7c4c 100644
--- a/test/metabase/driver/util_test.clj
+++ b/test/metabase/driver/util_test.clj
@@ -292,30 +292,40 @@
(let [fake-test-db (mt/db)]
(testing "supports? returns false when `driver/database-supports?` throws an exception"
(with-redefs [driver/database-supports? (fn [_ _ _] (throw (Exception. "test exception message")))]
- (let [db (assoc fake-test-db :name (mt/random-name))
- log-messages (mt/with-log-messages-for-level [metabase.driver.util :error]
- (is (false? (driver.u/supports? :test-driver :expressions db))))]
- (is (some (fn [[level ^Throwable exception message]]
- (and (= level :error)
- (= (.getMessage exception) "test exception message")
- (= message (u/format-color 'red "Failed to check feature 'expressions' for database '%s'" (:name db)))))
- log-messages)))))
+ (let [db (assoc fake-test-db :name (mt/random-name))
+ feature (keyword (name (ns-name *ns*)) (mt/random-name))]
+ (mt/with-log-messages-for-level [log-messages [metabase.driver.util :error]]
+ (is (false? (driver.u/supports? :test-driver feature db)))
+ (is (some (fn [{:keys [level e message]}]
+ (and (= level :error)
+ (= (ex-message e) "test exception message")
+ (= message (u/format-color 'red "Failed to check feature '%s' for database '%s'"
+ (u/qualified-name feature)
+ (:name db)))))
+ (log-messages)))))))))
+
+(deftest supports?-failure-test-2
+ (let [fake-test-db (mt/db)]
(binding [driver.u/*memoize-supports?* true]
(testing "supports? returns false when `driver/database-supports?` takes longer than the timeout"
- (let [db (assoc fake-test-db :name (mt/random-name))]
+ (let [db (assoc fake-test-db :name (mt/random-name))
+ feature (keyword (name (ns-name *ns*)) (mt/random-name))]
(with-redefs [driver.u/supports?-timeout-ms 100
driver/database-supports? (fn [_ _ _] (Thread/sleep 200) true)]
- (let [log-messages (mt/with-log-messages-for-level [metabase.driver.util :error]
- (is (false? (driver.u/supports? :test-driver :expressions db))))]
- (is (some (fn [[level ^Throwable exception message]]
- (and (= level :error)
- (= (.getMessage exception) "Timed out after 100.0 ms")
- (= message (u/format-color 'red "Failed to check feature 'expressions' for database '%s'" (:name db)))))
- log-messages))))
+ (mt/with-log-messages-for-level [log-messages [metabase.driver.util :error]]
+ (is (false? (driver.u/supports? :test-driver feature db)))
+ (is (some (fn [{:keys [level e message]}]
+ (and (= level :error)
+ (= (ex-message e) "Timed out after 100.0 ms")
+ (= message (u/format-color 'red "Failed to check feature '%s' for database '%s'"
+ (u/qualified-name feature)
+ (:name db)))))
+ (log-messages)))))
(testing "we memoize the results for the same database, so we don't log the error again"
- (let [log-messages (mt/with-log-messages-for-level [metabase.driver.util :error]
- (is (false? (driver.u/supports? :test-driver :expressions db))))]
- (is (nil? log-messages)))))))))
+ (mt/with-log-messages-for-level [log-messages [metabase.driver.util :error]]
+ (is (false? (driver.u/supports? :test-driver feature db)))
+ (is (= []
+ (log-messages))))))))))
(defmethod auth-provider/fetch-auth ::test-me
[_provider _db-id details]
diff --git a/test/metabase/driver_test.clj b/test/metabase/driver_test.clj
index b7a39e0ca81..4dff1b08e83 100644
--- a/test/metabase/driver_test.clj
+++ b/test/metabase/driver_test.clj
@@ -121,14 +121,15 @@
(mt/dataset dbdef
(let [db (mt/db)
cant-sync-logged? (fn []
- (some?
- (some
- (fn [[log-level throwable message]]
- (and (= log-level :warn)
- (instance? clojure.lang.ExceptionInfo throwable)
- (re-matches #"^Cannot sync Database ([\s\S]+): ([\s\S]+)" message)))
- (mt/with-log-messages-for-level :warn
- (#'task.sync-databases/sync-and-analyze-database*! (u/the-id db))))))]
+ (mt/with-log-messages-for-level [messages :warn]
+ (#'task.sync-databases/sync-and-analyze-database*! (u/the-id db))
+ (some?
+ (some
+ (fn [{:keys [level e message]}]
+ (and (= level :warn)
+ (instance? clojure.lang.ExceptionInfo e)
+ (re-matches #"^Cannot sync Database ([\s\S]+): ([\s\S]+)" message)))
+ (messages)))))]
(testing "sense checks before deleting the database"
(testing "sense check 1: sync-and-analyze-database! should not log a warning"
(is (false? (cant-sync-logged?))))
diff --git a/test/metabase/lib/swap_test.cljc b/test/metabase/lib/swap_test.cljc
index ec480030bb1..eb1459c3d72 100644
--- a/test/metabase/lib/swap_test.cljc
+++ b/test/metabase/lib/swap_test.cljc
@@ -8,7 +8,7 @@
[metabase.lib.core :as lib]
[metabase.lib.options :as lib.options]
[metabase.lib.test-metadata :as meta]
- [metabase.test.util.log :as tu.log]
+ [metabase.util.log.capture :as log.capture]
#?@(:cljs ([metabase.test-runner.assert-exprs.approximately-equal]))))
#?(:cljs (comment metabase.test-runner.assert-exprs.approximately-equal/keep-me))
@@ -96,9 +96,10 @@
(lib/aggregate (lib/sum (meta/field-metadata :orders :subtotal)))
(lib/aggregate (lib/min (meta/field-metadata :orders :total))))
[a1 a2 _a3] (lib/aggregations query)]
- (is (=? [[:warn nil #"No matching clause in swap-clauses \[:count .*"]]
- (tu.log/with-log-messages-for-level ['metabase.lib.swap :warn]
- (lib/swap-clauses query -1 a2 (lib.options/update-options a1 assoc :lib/uuid (str (random-uuid))))))))))
+ (log.capture/with-log-messages-for-level [messages [metabase.lib.swap :warn]]
+ (lib/swap-clauses query -1 a2 (lib.options/update-options a1 assoc :lib/uuid (str (random-uuid))))
+ (is (=? [{:level :warn, :message #"No matching clause in swap-clauses \[:count .*"}]
+ (messages)))))))
(deftest ^:synchronized swap-clauses-ambiguous-test
(testing "swap-clauses emits a warning if multiple matching clauses are found"
@@ -109,6 +110,7 @@
(lib/aggregate (lib/min (meta/field-metadata :orders :total))))
[a1 a2 _a3] (lib/aggregations query)
query (update-in query [:stages 0 :aggregation] conj a2)]
- (is (=? [[:warn nil #"Ambiguous match for clause in swap-clauses \[:sum .*"]]
- (tu.log/with-log-messages-for-level ['metabase.lib.swap :warn]
- (lib/swap-clauses query -1 a1 a2)))))))
+ (log.capture/with-log-messages-for-level [messages [metabase.lib.swap :warn]]
+ (lib/swap-clauses query -1 a1 a2)
+ (is (=? [{:level :warn, :message #"Ambiguous match for clause in swap-clauses \[:sum .*"}]
+ (messages)))))))
diff --git a/test/metabase/models/interface_test.clj b/test/metabase/models/interface_test.clj
index b43869fd005..58f8d5aa103 100644
--- a/test/metabase/models/interface_test.clj
+++ b/test/metabase/models/interface_test.clj
@@ -7,7 +7,7 @@
[metabase.models.field :refer [Field]]
[metabase.models.interface :as mi]
[metabase.models.table :refer [Table]]
- [metabase.test.util.log :as tu.log]
+ [metabase.test :as mt]
[metabase.util :as u]
[metabase.util.encryption :as encryption]
[metabase.util.encryption-test :as encryption-test]
@@ -146,21 +146,26 @@
(mi/encrypted-json-out
(encryption/encrypt (encryption/secret-key->hash "qwe") "{\"a\": 1}"))))))
(testing "Logs an error message when incoming data looks encrypted"
- (is (=? [[:error JsonParseException "Could not decrypt encrypted field! Have you forgot to set MB_ENCRYPTION_SECRET_KEY?"]]
- (tu.log/with-log-messages-for-level :error
- (mi/encrypted-json-out
- (encryption/encrypt (encryption/secret-key->hash "qwe") "{\"a\": 1}"))))))
+ (mt/with-log-messages-for-level [messages :error]
+ (mi/encrypted-json-out
+ (encryption/encrypt (encryption/secret-key->hash "qwe") "{\"a\": 1}"))
+ (is (=? [{:level :error
+ :e JsonParseException
+ :message "Could not decrypt encrypted field! Have you forgot to set MB_ENCRYPTION_SECRET_KEY?"}]
+ (messages)))))
(testing "Invalid JSON throws correct error"
- (is (=? [[:error JsonParseException "Error parsing JSON"]]
- (tu.log/with-log-messages-for-level :error
- (mi/encrypted-json-out "{\"a\": 1"))))
- (is (=? [[:error JsonParseException "Error parsing JSON"]]
- (tu.log/with-log-messages-for-level :error
- (encryption-test/with-secret-key "qwe"
- (mi/encrypted-json-out
- (encryption/encrypt (encryption/secret-key->hash "qwe") "{\"a\": 1")))))))))
+ (mt/with-log-messages-for-level [messages :error]
+ (mi/encrypted-json-out "{\"a\": 1")
+ (is (=? [{:level :error, :e JsonParseException, :message "Error parsing JSON"}]
+ (messages))))
+ (mt/with-log-messages-for-level [messages :error]
+ (encryption-test/with-secret-key "qwe"
+ (mi/encrypted-json-out
+ (encryption/encrypt (encryption/secret-key->hash "qwe") "{\"a\": 1")))
+ (is (=? [{:level :error, :e JsonParseException, :message "Error parsing JSON"}]
+ (messages)))))))
-(deftest instances-with-hydrated-data-test
+(deftest ^:parallel instances-with-hydrated-data-test
(let [things [{:id 2} nil {:id 1}]]
(is (= [{:id 2 :even-id? true} nil {:id 1 :even-id? false}]
(mi/instances-with-hydrated-data
@@ -170,7 +175,7 @@
things)
:id)))))
-(deftest normalize-mbql-clause-impostor-in-visualization-settings-test
+(deftest ^:parallel normalize-mbql-clause-impostor-in-visualization-settings-test
(let [viz-settings
{"table.pivot_column" "TAX",
"graph.metrics" ["expression"],
diff --git a/test/metabase/public_settings/premium_features_test.clj b/test/metabase/public_settings/premium_features_test.clj
index 7c7d4a443e4..b0c8a3207d6 100644
--- a/test/metabase/public_settings/premium_features_test.clj
+++ b/test/metabase/public_settings/premium_features_test.clj
@@ -39,56 +39,60 @@
(let [alphabet (into [] (concat (range 0 10) (map char (range (int \a) (int \g)))))]
(apply str (repeatedly 64 #(rand-nth alphabet)))))
-(deftest fetch-token-status-test
- (t2.with-temp/with-temp [User _user {:email "admin@example.com"}]
- (let [print-token "d7ad...c611"]
- (testing "Do not log the token (#18249)"
- (let [logs (mt/with-log-messages-for-level :info
- (#'premium-features/fetch-token-status* random-fake-token))
- pr-str-logs (mapv pr-str logs)]
- (is (every? (complement #(re-find (re-pattern random-fake-token) %)) pr-str-logs))
- (is (= 1 (count (filter #(re-find (re-pattern print-token) %) pr-str-logs))))))
-
- (testing "With the backend unavailable"
- (let [result (token-status-response random-fake-token {:status 500})]
- (is (false? (:valid result)))))
- (testing "On other errors"
- (binding [http/request (fn [& _]
- ;; note originally the code caught clojure.lang.ExceptionInfo so don't
- ;; throw an ex-info here
- (throw (Exception. "network issues")))]
- (is (= {:valid false
- :status "Unable to validate token"
- :error-details "network issues"}
- (premium-features/fetch-token-status (apply str (repeat 64 "b")))))))
- (testing "Only attempt the token twice (default and fallback URLs)"
- (let [call-count (atom 0)
- token (random-token)]
- (binding [http/request (fn [& _]
- (swap! call-count inc)
- (throw (Exception. "no internet")))]
-
- (mt/with-temporary-raw-setting-values [:premium-embedding-token token]
- (testing "Sanity check"
- (is (= token
- (premium-features/premium-embedding-token)))
- (is (= #{}
- (premium-features/*token-features*))))
- (doseq [has-feature? [#'premium-features/hide-embed-branding?
- #'premium-features/enable-whitelabeling?
- #'premium-features/enable-audit-app?
- #'premium-features/enable-sandboxes?
- #'premium-features/enable-serialization?]]
- (testing (format "\n%s is false" (:name (meta has-feature?)))
- (is (not (has-feature?)))))
- (is (= 2
- @call-count))))))
-
- (testing "With a valid token"
- (let [result (token-status-response random-fake-token {:status 200
- :body token-response-fixture})]
- (is (:valid result))
- (is (contains? (set (:features result)) "test")))))))
+(deftest ^:parallel fetch-token-status-test
+ (let [print-token "d7ad...c611"]
+ (testing "Do not log the token (#18249)"
+ (mt/with-log-messages-for-level [messages :info]
+ (#'premium-features/fetch-token-status* random-fake-token)
+ (let [logs (mapv :message (messages))]
+ (is (every? (complement #(re-find (re-pattern random-fake-token) %)) logs))
+ (is (= 1 (count (filter #(re-find (re-pattern print-token) %) logs)))))))))
+
+(deftest ^:parallel fetch-token-status-test-2
+ (testing "With the backend unavailable"
+ (let [result (token-status-response random-fake-token {:status 500})]
+ (is (false? (:valid result))))))
+
+(deftest ^:parallel fetch-token-status-test-3
+ (testing "On other errors"
+ (binding [http/request (fn [& _]
+ ;; note originally the code caught clojure.lang.ExceptionInfo so don't
+ ;; throw an ex-info here
+ (throw (Exception. "network issues")))]
+ (is (= {:valid false
+ :status "Unable to validate token"
+ :error-details "network issues"}
+ (premium-features/fetch-token-status (apply str (repeat 64 "b"))))))))
+
+(deftest fetch-token-status-test-4
+ (testing "Only attempt the token twice (default and fallback URLs)"
+ (let [call-count (atom 0)
+ token (random-token)]
+ (binding [http/request (fn [& _]
+ (swap! call-count inc)
+ (throw (Exception. "no internet")))]
+ (mt/with-temporary-raw-setting-values [:premium-embedding-token token]
+ (testing "Sanity check"
+ (is (= token
+ (premium-features/premium-embedding-token)))
+ (is (= #{}
+ (premium-features/*token-features*))))
+ (doseq [has-feature? [#'premium-features/hide-embed-branding?
+ #'premium-features/enable-whitelabeling?
+ #'premium-features/enable-audit-app?
+ #'premium-features/enable-sandboxes?
+ #'premium-features/enable-serialization?]]
+ (testing (format "\n%s is false" (:name (meta has-feature?)))
+ (is (not (has-feature?)))))
+ (is (= 2
+ @call-count)))))))
+
+(deftest ^:parallel fetch-token-status-test-5
+ (testing "With a valid token"
+ (let [result (token-status-response random-fake-token {:status 200
+ :body token-response-fixture})]
+ (is (:valid result))
+ (is (contains? (set (:features result)) "test")))))
(deftest not-found-test
(mt/with-log-level :fatal
diff --git a/test/metabase/pulse/render/style_test.clj b/test/metabase/pulse/render/style_test.clj
index bb25a68e3ec..90ef74f1c15 100644
--- a/test/metabase/pulse/render/style_test.clj
+++ b/test/metabase/pulse/render/style_test.clj
@@ -8,7 +8,6 @@
(testing "`style` should filter out nil values"
(is (= ""
(style/style {:a nil})))
-
(is (= "a: 0; c: 2;"
(style/style {:a 0, :b nil, :c 2, :d ""})))))
@@ -16,15 +15,14 @@
(testing "Under normal circumstances, font registration should work as expected"
(is (= nil
(#'style/register-fonts-if-needed!))))
-
(testing "If font registration fails, we should an Exception with a useful error message"
(with-redefs [style/register-font! (fn [& _]
(throw (ex-info "Oops!" {})))]
- (let [messages (mt/with-log-messages-for-level :error
- (is (thrown-with-msg?
- clojure.lang.ExceptionInfo
- #"Error registering fonts: Metabase will not be able to send Pulses"
- (#'style/register-fonts!))))]
+ (mt/with-log-messages-for-level [messages :error]
+ (is (thrown-with-msg?
+ clojure.lang.ExceptionInfo
+ #"Error registering fonts: Metabase will not be able to send Pulses"
+ (#'style/register-fonts!)))
(testing "Should log the Exception"
- (is (=? [:error Throwable #"^Error registering fonts: .*"]
- (first messages))))))))
+ (is (=? {:level :error, :e Throwable, :message #"^Error registering fonts: .*"}
+ (first (messages)))))))))
diff --git a/test/metabase/server/middleware/session_test.clj b/test/metabase/server/middleware/session_test.clj
index d448876c950..7639b8c76af 100644
--- a/test/metabase/server/middleware/session_test.clj
+++ b/test/metabase/server/middleware/session_test.clj
@@ -88,17 +88,19 @@
:type :normal}
request-time (t/zoned-date-time "2022-07-06T02:00Z[UTC]")]
(testing "should log a warning if SameSite is configured to \"None\" and the site is served over an insecure connection."
- (is (contains? (into #{}
- (map (fn [[_log-level _error message]] message))
- (mt/with-log-messages-for-level :warn
- (mw.session/set-session-cookies {:headers {"x-forwarded-proto" "http"}} {} session request-time)))
- "Session cookie's SameSite is configured to \"None\", but site is served over an insecure connection. Some browsers will reject cookies under these conditions. https://www.chromestatus.com/feature/5633521622188032")))
+ (mt/with-log-messages-for-level [messages :warn]
+ (mw.session/set-session-cookies {:headers {"x-forwarded-proto" "http"}} {} session request-time)
+ (is (contains? (into #{}
+ (map :message)
+ (messages))
+ "Session cookie's SameSite is configured to \"None\", but site is served over an insecure connection. Some browsers will reject cookies under these conditions. https://www.chromestatus.com/feature/5633521622188032"))))
(testing "should not log a warning over a secure connection."
- (is (not (contains? (into #{}
- (map (fn [[_log-level _error message]] message))
- (mt/with-log-messages-for-level :warn
- (mw.session/set-session-cookies {:headers {"x-forwarded-proto" "https"}} {} session request-time)))
- "Session cookie's SameSite is configured to \"None\", but site is served over an insecure connection. Some browsers will reject cookies under these conditions. https://www.chromestatus.com/feature/5633521622188032")))))))
+ (mt/with-log-messages-for-level [messages :warn]
+ (mw.session/set-session-cookies {:headers {"x-forwarded-proto" "https"}} {} session request-time)
+ (is (not (contains? (into #{}
+ (map :message)
+ (messages))
+ "Session cookie's SameSite is configured to \"None\", but site is served over an insecure connection. Some browsers will reject cookies under these conditions. https://www.chromestatus.com/feature/5633521622188032"))))))))
;; if request is an HTTPS request then we should set `:secure true`. There are several different headers we check for
;; this. Make sure they all work.
@@ -550,26 +552,30 @@
(mt/user-http-request :crowberto :put 400 "setting/session-timeout" {:value {:unit "hours", :amount -1}})))))
(deftest session-timeout-env-var-validation-test
- (let [set-and-get (fn [timeout]
- (mt/with-temp-env-var-value! [mb-session-timeout (json/generate-string timeout)]
- (mw.session/session-timeout)))]
+ (let [set-and-get! (fn [timeout]
+ (mt/with-temp-env-var-value! [mb-session-timeout (json/generate-string timeout)]
+ (mw.session/session-timeout)))]
(testing "Setting the session timeout with env var should work with valid timeouts"
(doseq [timeout [{:unit "hours", :amount 1}
{:unit "hours", :amount (dec (* 100 365.25 24))}]]
(is (= timeout
- (set-and-get timeout)))))
+ (set-and-get! timeout)))))
(testing "Setting the session timeout via the env var should fail if the timeout isn't positive"
(doseq [amount [0 -1]
:let [timeout {:unit "hours", :amount amount}]]
- (is (nil? (set-and-get timeout)))
- (is (= [[:warn nil "Session timeout amount must be positive."]]
- (mt/with-log-messages-for-level :warn (set-and-get timeout))))))
+ (is (nil? (set-and-get! timeout)))
+ (mt/with-log-messages-for-level [messages :warn]
+ (set-and-get! timeout)
+ (is (=? [{:level :warn, :message "Session timeout amount must be positive."}]
+ (messages))))))
(testing "Setting the session timeout via env var should fail if the timeout is too large"
(doseq [timeout [{:unit "hours", :amount (* 100 365.25 24)}
{:unit "minutes", :amount (* 100 365.25 24 60)}]]
- (is (nil? (set-and-get timeout)))
- (is (= [[:warn nil "Session timeout must be less than 100 years."]]
- (mt/with-log-messages-for-level :warn (set-and-get timeout))))))))
+ (is (nil? (set-and-get! timeout)))
+ (mt/with-log-messages-for-level [messages :warn]
+ (set-and-get! timeout)
+ (is (=? [{:level :warn, :message "Session timeout must be less than 100 years."}]
+ (messages))))))))
(deftest ^:parallel session-timeout-test
(testing "`session-timeout` setting conversion to seconds"
diff --git a/test/metabase/shared/formatting/date_test.cljc b/test/metabase/shared/formatting/date_test.cljc
index 5130ba00fa9..69271801a38 100644
--- a/test/metabase/shared/formatting/date_test.cljc
+++ b/test/metabase/shared/formatting/date_test.cljc
@@ -2,12 +2,16 @@
(:require
[clojure.test :refer [are deftest is testing]]
[metabase.shared.formatting.date :as date]
+ [metabase.shared.formatting.internal.date-formatters :as formatters]
[metabase.shared.util.time :as shared.ut]
- #?@(:clj [[metabase.shared.formatting.internal.date-formatters :as formatters]
- [metabase.test :as mt]]))
+ [metabase.util.log.capture :as log.capture]
+ #?@(:cljs
+ [[metabase.test-runner.assert-exprs.approximately-equal]]))
#?(:clj (:import
java.util.Locale)))
+#?(:cljs (comment metabase.test-runner.assert-exprs.approximately-equal/keep-me))
+
(def ^:private locale
#?(:cljs nil :clj (Locale. "en")))
@@ -28,8 +32,9 @@
"2022-01-19" "2022-01-19T12:03:19" "quarter-of-year"
;; Days
"2022-01-19" "2022-01-19T12:03:19" "day"
- "2022-12-19" "2022-12-19T12:03:19" "day"))
+ "2022-12-19" "2022-12-19T12:03:19" "day")))
+(deftest ^:parallel format-for-parameter-test-2
(testing "other units are treated as days or day ranges"
(are [exp date unit] (= exp (date/format-for-parameter (shared.ut/coerce-to-timestamp date)
{:unit unit
@@ -66,8 +71,7 @@
(is (= (str "Dec 11" date/range-separator "17, 2022")
(week-of "2022-12-14T11:19:04"))))))
-#_{:clj-kondo/ignore [:metabase/i-like-making-cams-eyes-bleed-with-horrifically-long-tests]}
-(deftest ^:parallel format-datetime-with-unit-test
+(deftest ^:parallel format-datetime-with-unit-test-1a1
(testing "special cases"
(testing "is-exclude"
(testing "for hour-of-day renders only the hour"
@@ -75,8 +79,11 @@
"11 AM" "2022-11-20T11:19:04"
"3 PM" "2022-11-20T15:19:04"
"12 AM" "2022-11-20T00:19:04"
- "12 PM" "2022-11-20T12:19:04"))
+ "12 PM" "2022-11-20T12:19:04")))))
+(deftest ^:parallel format-datetime-with-unit-test-1a2
+ (testing "special cases"
+ (testing "is-exclude"
(testing "for day-of-week renders eg. Monday"
(testing "from ISO date strings"
(are [exp date] (= exp (date/format-datetime-with-unit date {:unit "day-of-week" :is-exclude true}))
@@ -86,8 +93,12 @@
"Wednesday" "2022-12-21T11:19:04"
"Thursday" "2022-12-22T11:19:04"
"Friday" "2022-12-23T11:19:04"
- "Saturday" "2022-12-24T11:19:04"))
+ "Saturday" "2022-12-24T11:19:04"))))))
+(deftest ^:parallel format-datetime-with-unit-test-1a3
+ (testing "special cases"
+ (testing "is-exclude"
+ (testing "for day-of-week renders eg. Monday"
(testing "from weekday numbers"
(are [exp date] (= exp (date/format-datetime-with-unit date {:unit "day-of-week" :is-exclude true}))
"Saturday" 0
@@ -98,8 +109,12 @@
"Thursday" 5
"Friday" 6
"Saturday" 7
- "Sunday" 8))
+ "Sunday" 8))))))
+(deftest ^:parallel format-datetime-with-unit-test-1a4
+ (testing "special cases"
+ (testing "is-exclude"
+ (testing "for day-of-week renders eg. Monday"
(testing "from short weekday names"
(are [exp date] (= exp (date/format-datetime-with-unit date {:unit "day-of-week" :is-exclude true}))
"Sunday" "Sun"
@@ -109,8 +124,12 @@
"Thursday" "Thu"
"Friday" "Fri"
"Saturday" "Sat"
- "Sunday" "Sun"))
+ "Sunday" "Sun"))))))
+(deftest ^:parallel format-datetime-with-unit-test-1a5
+ (testing "special cases"
+ (testing "is-exclude"
+ (testing "for day-of-week renders eg. Monday"
(testing "from full weekday names"
(are [exp date] (= exp (date/format-datetime-with-unit date {:unit "day-of-week" :is-exclude true}))
"Sunday" "Sunday"
@@ -120,25 +139,36 @@
"Thursday" "Thursday"
"Friday" "Friday"
"Saturday" "Saturday"
- "Sunday" "Sunday"))))
+ "Sunday" "Sunday"))))))
+(deftest ^:parallel format-datetime-with-unit-test-1b1
+ (testing "special cases"
(testing "weeks in tooltips (condensed ranges, not abbreviated)"
(testing "that fit in one month are formatted December 18 - 24, 2022"
(is (= (str "December 18" date/range-separator "24, 2022")
(date/format-datetime-with-unit "2022-12-20T11:19:04" {:unit "week"
:type "tooltip"
- :locale locale}))))
+ :locale locale})))))))
+
+(deftest ^:parallel format-datetime-with-unit-test-1b2
+ (testing "special cases"
+ (testing "weeks in tooltips (condensed ranges, not abbreviated)"
(testing "that span months are formatted November 27 - December 3, 2022"
(is (= (str "November 27" date/range-separator "December 3, 2022")
(date/format-datetime-with-unit "2022-11-30T11:19:04" {:unit "week"
:type "tooltip"
- :locale locale}))))
+ :locale locale})))))))
+
+(deftest ^:parallel format-datetime-with-unit-test-1b3
+ (testing "special cases"
+ (testing "weeks in tooltips (condensed ranges, not abbreviated)"
(testing "that span years are formatted December 29, 2019 - January 4, 2020"
(is (= (str "December 29, 2019" date/range-separator "January 4, 2020")
(date/format-datetime-with-unit "2019-12-30T11:19:04" {:unit "week"
:type "tooltip"
- :locale locale}))))))
+ :locale locale})))))))
+(deftest ^:parallel format-datetime-with-unit-test-2a
(testing "general dates"
(testing "with default style, unit-based"
(are [exp unit] (= exp (date/format-datetime-with-unit "2022-12-07" {:unit unit}))
@@ -151,8 +181,10 @@
"7" "day-of-month"
"Wednesday" "day-of-week"
"341" "day-of-year"
- #?(:clj "50" :cljs "50th") "week-of-year"))
+ #?(:clj "50" :cljs "50th") "week-of-year"))))
+(deftest ^:parallel format-datetime-with-unit-test-2b
+ (testing "general dates"
(testing "default formats for each date style"
(are [exp style unit] (= exp (date/format-datetime-with-unit "2022-04-07T19:08:45.123" {:unit unit
:date-style style
@@ -162,8 +194,10 @@
"2022/4/7" "YYYY/M/D" "day"
"April 7, 2022" "MMMM D, YYYY" "day"
"7 April, 2022" "D MMMM, YYYY" "day"
- "Thursday, April 7, 2022" "dddd, MMMM D, YYYY" "day"))
+ "Thursday, April 7, 2022" "dddd, MMMM D, YYYY" "day"))))
+(deftest ^:parallel format-datetime-with-unit-test-2c1
+ (testing "general dates"
(testing "unit overrides for various styles"
(are [exp style unit] (= exp (date/format-datetime-with-unit "2022-04-07T19:08:45.123" {:unit unit
:date-style style
@@ -175,8 +209,11 @@
"April, 2022" "MMMM D, YYYY" "month"
"April, 2022" "D MMMM, YYYY" "month"
"April 7, 2022" "dddd, MMMM D, YYYY" "week" ;; TODO is this actually right? check with existing code
- "April, 2022" "dddd, MMMM D, YYYY" "month")
+ "April, 2022" "dddd, MMMM D, YYYY" "month"))))
+(deftest ^:parallel format-datetime-with-unit-test-2c2
+ (testing "general dates"
+ (testing "unit overrides for various styles"
(testing "use short forms in compact mode"
(are [exp style unit] (= exp (date/format-datetime-with-unit "2022-04-07T19:08:45.123" {:unit unit
:time-enabled false
@@ -184,8 +221,10 @@
"Apr, 2022" "MMMM D, YYYY" "month"
"Apr, 2022" "D MMMM, YYYY" "month"
"Apr 7, 2022" "dddd, MMMM D, YYYY" "week" ;; TODO is this actually right? check with existing code
- "Apr, 2022" "dddd, MMMM D, YYYY" "month")))
+ "Apr, 2022" "dddd, MMMM D, YYYY" "month")))))
+(deftest ^:parallel format-datetime-with-unit-test-2d
+ (testing "general dates"
(testing "custom date separators"
(are [exp style separator unit]
(= exp (date/format-datetime-with-unit "2022-04-07T19:08:45.123" {:unit unit
@@ -204,13 +243,16 @@
"4/2022" "D/M/YYYY" "/" "month"
"7/4/2022" "D/M/YYYY" "/" "day"
"4-2022" "D/M/YYYY" "-" "month"
- "7-4-2022" "D/M/YYYY" "-" "day")))
+ "7-4-2022" "D/M/YYYY" "-" "day"))))
+(deftest ^:parallel format-datetime-with-unit-test-3a
(testing "general dates and times"
(testing "with both styles left as defaults and a sub-day :unit"
(is (= "April 7, 2022, 7:08 PM"
- (date/format-datetime-with-unit "2022-04-07T19:08:45.123" {:unit "minute"}))))
+ (date/format-datetime-with-unit "2022-04-07T19:08:45.123" {:unit "minute"}))))))
+(deftest ^:parallel format-datetime-with-unit-test-3b
+ (testing "general dates and times"
(testing "setting the time style"
(are [exp style enabled]
(= exp (date/format-datetime-with-unit "2022-04-07T19:08:45.123" {:time-enabled enabled
@@ -220,8 +262,10 @@
"April 7, 2022, 7:08:45 PM" "h:mm A" "seconds"
"April 7, 2022, 19:08:45" "HH:mm" "seconds"
"April 7, 2022, 7:08:45.123 PM" "h:mm A" "milliseconds"
- "April 7, 2022, 19:08:45.123" "HH:mm" "milliseconds"))
+ "April 7, 2022, 19:08:45.123" "HH:mm" "milliseconds"))))
+(deftest ^:parallel format-datetime-with-unit-test-3c
+ (testing "general dates and times"
(testing "setting both styles"
(are [exp date-style time-style enabled]
(= exp (date/format-datetime-with-unit "2022-04-07T19:08:45.123" {:date-style date-style
@@ -232,16 +276,19 @@
"4/7/2022, 7:08 PM" "M/D/YYYY" "h:mm A" "minutes"
"4/7/2022, 19:08" "M/D/YYYY" "HH:mm" "minutes"
"4/7/2022, 19:08:45" "M/D/YYYY" "HH:mm" "seconds"
- "4/7/2022, 19:08:45.123" "M/D/YYYY" "HH:mm" "milliseconds"))
+ "4/7/2022, 19:08:45.123" "M/D/YYYY" "HH:mm" "milliseconds"))))
+(deftest ^:parallel format-datetime-with-unit-test-3d
+ (testing "general dates and times"
(testing "setting a date style and unit that overrides, plus a time"
;; This is a weird thing to do, but it should work correctly.
(is (= "4/2022, 19:08:45.123"
(date/format-datetime-with-unit "2022-04-07T19:08:45.123" {:date-style "M/D/YYYY"
:time-style "HH:mm"
:time-enabled "milliseconds"
- :unit "month"})))))
+ :unit "month"}))))))
+(deftest ^:parallel format-datetime-with-unit-test-4
(testing "bare times"
(are [exp arg unit time-style] (= exp (date/format-datetime-with-unit arg {:unit unit
:time-style time-style}))
@@ -252,8 +299,9 @@
"07:00" 7 "hour-of-day" "HH:mm"
"12:00" 12 "hour-of-day" "HH:mm"
"19:00" 19 "hour-of-day" "HH:mm"
- "00:00" 24 "hour-of-day" "HH:mm"))
+ "00:00" 24 "hour-of-day" "HH:mm")))
+(deftest ^:parallel format-datetime-with-unit-test-5
(testing "prepending weekdays"
(testing "works on any date format with days"
(are [exp date-style time-style unit]
@@ -268,8 +316,10 @@
"Thu, 4/7/2022, 19:08" "M/D/YYYY" "HH:mm" "minute"
"Thu, 4/7/2022, 19:08" "M/D/YYYY" "HH:mm" "hour"
"Thu, April 7, 2022" "MMMM D, YYYY" nil "day"
- "Thu, April 7, 2022" "MMMM D, YYYY" nil "week"))
+ "Thu, April 7, 2022" "MMMM D, YYYY" nil "week"))))
+(deftest ^:parallel format-datetime-with-unit-test-5b
+ (testing "prepending weekdays"
(testing "is skipped if the unit does not have day resolution"
(are [exp date-style unit]
(= exp (date/format-datetime-with-unit "2022-04-07T19:08:45.123" {:date-style date-style
@@ -279,26 +329,19 @@
"Q2 - 2022" "MMMM D, YYYY" "quarter"
"2022" "MMMM D, YYYY" "year"))))
-;; This is a separate deftest because the [[mt/with-log-messages-for-level]] doesn't work in :parallel tests.
-;; TODO Capturing log messages and suppressing the output is Clojure-only. Port that to CLJS and test it here.
(deftest fallback-test
(testing "fallback to ISO date string if neither the unit nor style map to a format"
- #?(:clj (let [result (atom nil)]
- ;; Clear the cache, because it only generates the warning the first time this gets constructured.
- (reset! @#'formatters/options->formatter-cache {})
-
- (is (= [[:warn nil "Unrecognized date style {:date-style asdf, :unit :asdf}"]]
- (mt/with-log-messages-for-level :warn
- (reset! result
- (date/format-datetime-with-unit "2022-04-07T19:08:45.123" {:unit :asdf
- :date-style "asdf"
- :time-enabled false})))))
- (is (= "2022-04-07T19:08:45" @result)))
-
- :cljs (is (= "2022-04-07T19:08:45"
- (date/format-datetime-with-unit "2022-04-07T19:08:45.123" {:unit "asdf"
- :date-style "asdf"
- :time-enabled false}))))))
+ (let [result (atom nil)]
+ ;; Clear the cache, because it only generates the warning the first time this gets constructured.
+ (reset! @#'formatters/options->formatter-cache {})
+ (log.capture/with-log-messages-for-level [messages :warn]
+ (reset! result
+ (date/format-datetime-with-unit "2022-04-07T19:08:45.123" {:unit :asdf
+ :date-style "asdf"
+ :time-enabled false}))
+ (is (=? [{:level :warn, :message "Unrecognized date style {:date-style asdf, :unit :asdf}"}]
+ (messages))))
+ (is (= "2022-04-07T19:08:45" @result)))))
;; TODO The originals theoretically support custom "date-format" and "time-format" options; are they ever
;; actually used? What about non-standard styles?
diff --git a/test/metabase/test.clj b/test/metabase/test.clj
index ae8dd32f64f..ace9084b425 100644
--- a/test/metabase/test.clj
+++ b/test/metabase/test.clj
@@ -41,6 +41,7 @@
[metabase.test.util.public-settings :as tu.public-setings]
[metabase.test.util.thread-local :as tu.thread-local]
[metabase.test.util.timezone :as test.tz]
+ [metabase.util.log.capture]
[metabase.util.random :as u.random]
[pjstadig.humane-test-output :as humane-test-output]
[potemkin :as p]
@@ -69,17 +70,19 @@
lib.metadata.jvm/keep-me
mb.hawk.init/keep-me
mb.hawk.parallel/keep-me
- test.redefs/keep-me
+ metabase.util.log.capture/keep-me
mw.session/keep-me
perms.test-util/keep-me
qp.store/keep-me
qp.test-util/keep-me
qp/keep-me
+ schema-migrations-test.impl/keep-me
sql-jdbc.tu/keep-me
sql.qp-test-util/keep-me
t2.with-temp/keepme
test-runner.assert-exprs/keep-me
test.persistence/keep-me
+ test.redefs/keep-me
test.tz/keep-me
test.users/keep-me
tu.async/keep-me
@@ -87,11 +90,10 @@
tu.misc/keep-me
tu.public-setings/keep-me
tu.thread-local/keep-me
- u.random/keep-me
tu/keep-me
tx.env/keep-me
tx/keep-me
- schema-migrations-test.impl/keep-me)
+ u.random/keep-me)
;; Add more stuff here as needed
#_{:clj-kondo/ignore [:discouraged-var :deprecated-var]}
@@ -161,6 +163,9 @@
[lib.metadata.jvm
application-database-metadata-provider]
+ [metabase.util.log.capture
+ with-log-messages-for-level]
+
[mw.session
with-current-user
as-admin]
@@ -275,7 +280,6 @@
[tu.log
ns-log-level
set-ns-log-level!
- with-log-messages-for-level
with-log-level]
[tu.misc
diff --git a/test/metabase/test/util/log.clj b/test/metabase/test/util/log.clj
index c21f4b9973b..fabec24b628 100644
--- a/test/metabase/test/util/log.clj
+++ b/test/metabase/test/util/log.clj
@@ -5,12 +5,10 @@
[mb.hawk.parallel]
[metabase.logger :as logger]
[metabase.util.malli :as mu]
- [metabase.util.malli.schema :as ms]
- [net.cgrand.macrovich :as macros]
- [potemkin :as p])
+ [metabase.util.malli.schema :as ms])
(:import
(org.apache.logging.log4j Level)
- (org.apache.logging.log4j.core Appender LifeCycle LogEvent)
+ (org.apache.logging.log4j.core Appender)
(org.apache.logging.log4j.core.config LoggerConfig)))
(set! *warn-on-reflection* true)
@@ -153,99 +151,6 @@
a-namespace)]
`(do-with-log-level ~a-namespace ~level (fn [] ~@body))))
-
-;;;; [[with-log-messages-for-level]]
-
-(p/defprotocol+ ^:private IInMemoryAppender
- (^:private appender-logs [this]))
-
-(p/defrecord+ ^:private InMemoryAppender [appender-name state]
- Appender
- (append [_this event]
- (let [event ^LogEvent event]
- (swap! state update :logs (fn [logs]
- (conj (vec logs)
- [(log-level->keyword (.getLevel event))
- (.getThrown event)
- (str (.getMessage event))
- #_(.getLoggerName event)]))))
- nil)
- (getHandler [_this]
- (:error-handler @state))
- (getLayout [_this])
- (getName [_this]
- appender-name)
- (ignoreExceptions [_this]
- true)
- (setHandler [_this new-handler]
- (swap! state assoc :error-handler new-handler))
-
- LifeCycle
- (getState [_this])
- (initialize [_this])
- (isStarted [_this]
- (not (:stopped @state)))
- (isStopped [_this]
- (boolean (:stopped @state)))
- (start [_this]
- (swap! state assoc :stopped false))
- (stop [_this]
- (swap! state assoc :stopped true))
-
- IInMemoryAppender
- (appender-logs [_this]
- (:logs @state)))
-
-(defn do-with-log-messages-for-level [a-namespace level f]
- (mb.hawk.parallel/assert-test-is-not-parallel "with-log-messages-for-level")
- (ensure-unique-logger! a-namespace)
- (let [state (atom nil)
- appender-name (format "%s-%s-%s" `InMemoryAppender (logger/logger-name a-namespace) (name level))
- appender (->InMemoryAppender appender-name state)
- logger (exact-ns-logger a-namespace)]
- (try
- (.addAppender logger appender (->Level level) nil)
- (f (fn [] (appender-logs appender)))
- (finally
- (.removeAppender logger appender-name)))))
-
-(defmacro with-log-messages-for-level-clj
- "Executes `body` with the metabase logging level set to `level-kwd`. This is needed when the logging level is set at a
- higher threshold than the log messages you're wanting to example. As an example if the metabase logging level is set
- to `ERROR` in the log4j.properties file and you are looking for a `WARN` message, it won't show up in the
- `with-log-messages` call as there's a guard around the log invocation, if it's not enabled (it is set to `ERROR`)
- the log function will never be invoked. This macro will temporarily set the logging level to `level-kwd`, then
- invoke `with-log-messages`, then set the level back to what it was before the invocation. This allows testing log
- messages even if the threshold is higher than the message you are looking for."
- {:arglists '([level & body] [[a-namespace level] & body])}
- [ns+level & body]
- (let [[a-namespace level] (if (sequential? ns+level)
- ns+level
- ['metabase ns+level])
- a-namespace (if (symbol? a-namespace)
- (list 'quote a-namespace)
- a-namespace)]
- `(do-with-log-level
- ~a-namespace
- ~level
- (fn []
- (do-with-log-messages-for-level
- ~a-namespace
- ~level
- (fn [logs#]
- ~@body
- (logs#)))))))
-
-;; TODO -- this macro should probably just take a binding for the `logs` function so you can eval when needed
-;; Tech debt issue: #39335
-(defmacro with-log-messages-for-level [ns+level & body]
- (macros/case
- :clj `(with-log-messages-for-level-clj ~ns+level ~@body)
- :cljs (let [[log-ns level] (if (sequential? ns+level)
- ns+level
- [(str (ns-name *ns*)) ns+level])]
- `(do-with-glogi-logs ~log-ns ~level (fn [] ~@body)))))
-
;;;; tests
(deftest set-ns-log-level!-test
diff --git a/test/metabase/test/util/log.cljs b/test/metabase/test/util/log.cljs
index e6cc0fe88dd..be8ac19c077 100644
--- a/test/metabase/test/util/log.cljs
+++ b/test/metabase/test/util/log.cljs
@@ -1,33 +1,3 @@
(ns metabase.test.util.log
- (:require
- [lambdaisland.glogi :as glogi]
- [metabase.util.log :as log])
- (:require-macros [metabase.test.util.log]))
-
-(def ^:private level-overrides
- {:warning :warn
- :severe :error
- :shout :fatal
- :fine :debug
- :finer :trace})
-
-(defn- extract-log [{:keys [exception level message]}]
- [(get level-overrides level level) exception message])
-
-;; TODO This does not suppress the logs from actually reaching the console.
-;; Perhaps https://github.com/lambdaisland/glogi/issues/24 to add a `clear-handlers!` or similar.
-;; Tech debt issue: #39335
-#_{:clj-kondo/ignore [:clojure-lsp/unused-public-var]}
-(defn do-with-glogi-logs
- "Used internally by the CLJS flavour of [[with-log-messages-for-level]]. Don't call this directly."
- [log-ns level body-fn]
- (let [captured (atom [])
- handler (fn [record] (swap! captured conj record))]
- (glogi/add-handler log-ns handler)
- (glogi/set-levels {log-ns (log/glogi-level level)
- "" :off})
- (body-fn)
- (glogi/remove-handler log-ns handler)
- (glogi/set-levels {log-ns :info
- "" :info})
- (mapv extract-log @captured)))
+ (:require-macros
+ [metabase.test.util.log]))
diff --git a/test/metabase/util/encryption_test.clj b/test/metabase/util/encryption_test.clj
index c931626b4a1..6a97fb76428 100644
--- a/test/metabase/util/encryption_test.clj
+++ b/test/metabase/util/encryption_test.clj
@@ -8,7 +8,7 @@
[metabase.test.initialize :as initialize]
[metabase.util.encryption :as encryption]))
-(defn do-with-secret-key [^String secret-key thunk]
+(defn do-with-secret-key! [^String secret-key thunk]
;; flush the Setting cache so unencrypted values have to be fetched from the DB again
(initialize/initialize-if-needed! :db)
(setting.cache/restore-cache!)
@@ -20,6 +20,7 @@
;; reset the cache again so nothing that happened during the test is persisted.
(setting.cache/restore-cache!))))
+#_{:clj-kondo/ignore [:metabase/test-helpers-use-non-thread-safe-functions]}
(defmacro with-secret-key
"Run `body` with the encryption secret key temporarily bound to `secret-key`. Useful for testing how functions behave
with and without encryption disabled."
@@ -27,7 +28,7 @@
[^String secret-key & body]
`(let [secret-key# ~secret-key]
(testing (format "\nwith secret key %s" (pr-str secret-key#))
- (do-with-secret-key secret-key# (fn [] ~@body)))))
+ (do-with-secret-key! secret-key# (fn [] ~@body)))))
(def ^:private secret-string "Orw0AAyzkO/kPTLJRxiyKoBHXa/d6ZcO+p+gpZO/wSQ=")
@@ -85,16 +86,17 @@
(encryption/maybe-decrypt secret-2 original-ciphertext))))))
(defn- includes-encryption-warning? [log-messages]
- (some (fn [[level _ message]]
+ (some (fn [{:keys [level message]}]
(and (= level :warn)
(str/includes? message (str "Cannot decrypt encrypted String. Have you changed or forgot to set "
"MB_ENCRYPTION_SECRET_KEY?"))))
log-messages))
-(deftest no-errors-for-unencrypted-test
+(deftest ^:parallel no-errors-for-unencrypted-test
(testing "Something obviously not encrypted should avoiding trying to decrypt it (and thus not log an error)"
- (is (empty? (mt/with-log-messages-for-level :warn
- (encryption/maybe-decrypt secret "abc"))))))
+ (mt/with-log-messages-for-level [messages :warn]
+ (encryption/maybe-decrypt secret "abc")
+ (is (empty? (messages))))))
(def ^:private fake-ciphertext
"AES+CBC's block size is 16 bytes and the tag length is 32 bytes. This is a string of characters that is the same
@@ -102,15 +104,15 @@
have the same size"
(apply str (repeat 64 "a")))
-(deftest log-warning-on-failure-test
+(deftest ^:parallel log-warning-on-failure-test
(testing (str "Something that is not encrypted, but might be (is the correct shape etc) should attempt to be "
"decrypted. If unable to decrypt it, log a warning.")
- (is (includes-encryption-warning?
- (mt/with-log-messages-for-level :warn
- (encryption/maybe-decrypt secret fake-ciphertext))))
- (is (includes-encryption-warning?
- (mt/with-log-messages-for-level :warn
- (encryption/maybe-decrypt secret-2 (encryption/encrypt secret "WOW")))))))
+ (mt/with-log-messages-for-level [messages :warn]
+ (encryption/maybe-decrypt secret fake-ciphertext)
+ (is (includes-encryption-warning? (messages))))
+ (mt/with-log-messages-for-level [messages :warn]
+ (encryption/maybe-decrypt secret-2 (encryption/encrypt secret "WOW"))
+ (is (includes-encryption-warning? (messages))))))
(deftest ^:parallel possibly-encrypted-test
(testing "Something that is not encrypted, but might be should return the original text"
diff --git a/test/metabase/util/log/capture_test.cljc b/test/metabase/util/log/capture_test.cljc
new file mode 100644
index 00000000000..39e972440f0
--- /dev/null
+++ b/test/metabase/util/log/capture_test.cljc
@@ -0,0 +1,214 @@
+(ns metabase.util.log.capture-test
+ (:require
+ [clojure.test :refer [deftest testing is are]]
+ [metabase.util.log :as log]
+ [metabase.util.log.capture :as log.capture]
+ #?@(:cljs
+ [[metabase.test-runner.assert-exprs.approximately-equal]])))
+
+#?(:cljs
+ (comment
+ metabase.test-runner.assert-exprs.approximately-equal/keep-me))
+
+(deftest ^:parallel basic-logp-test
+ (is (= [{:namespace 'metabase.util.log.capture-test, :level :warn, :e nil, :message "a message"}]
+ (log.capture/with-log-messages-for-level [messages :warn]
+ (log/info "not this one")
+ (log/warn "a message")
+ (messages))))
+ (is (= [{:namespace 'metabase.util.log.capture-test, :level :info, :e nil, :message "here's one"}
+ {:namespace 'metabase.util.log.capture-test, :level :warn, :e nil, :message "a message"}]
+ (log.capture/with-log-messages-for-level [messages :info]
+ (log/info "here's one")
+ (log/warn "a message")
+ (messages))))
+ (is (= [{:namespace 'metabase.util.log.capture-test, :level :info, :e nil, :message ":keyword 78"}]
+ (log.capture/with-log-messages-for-level [messages :info]
+ (log/info :keyword 78)
+ (messages)))))
+
+(deftest ^:parallel logp-levels-test
+ (let [important-message #{"fatal" "error" "warn" "info" "debug" "trace"}
+ spam (fn []
+ (log/fatal "fatal")
+ (log/error "error")
+ (log/warn "warn")
+ (log/info "info")
+ (log/debug "debug")
+ (log/trace "trace"))
+ logs [{:namespace 'metabase.util.log.capture-test, :level :fatal, :e nil, :message "fatal"}
+ {:namespace 'metabase.util.log.capture-test, :level :error, :e nil, :message "error"}
+ {:namespace 'metabase.util.log.capture-test, :level :warn, :e nil, :message "warn"}
+ {:namespace 'metabase.util.log.capture-test, :level :info, :e nil, :message "info"}
+ {:namespace 'metabase.util.log.capture-test, :level :debug, :e nil, :message "debug"}
+ {:namespace 'metabase.util.log.capture-test, :level :trace, :e nil, :message "trace"}]]
+ (are [prefix level] (= (->> logs
+ (filter #(contains? important-message (:message %)))
+ (take prefix))
+ (log.capture/with-log-messages-for-level [messages level]
+ (spam)
+ (messages)))
+ ;0 :off - this doesn't work in CLJ and perhaps should?
+ 1 :fatal
+ 2 :error
+ 3 :warn
+ 4 :info
+ 5 :debug
+ 6 :trace)))
+
+(deftest ^:parallel logf-formatting-test
+ (is (= [{:namespace 'metabase.util.log.capture-test, :level :info, :e nil, :message "input: 8, 3; output: ignored"}]
+ (log.capture/with-log-messages-for-level [messages :info]
+ (log/infof "input: %d, %d; %s: ignored" 8 3 "output")
+ (messages)))))
+
+(deftest ^:parallel ignore-logs-at-finer-level-test
+ (testing "Do not capture logs at a finer level"
+ (log.capture/with-log-messages-for-level [messages [metabase.util.log.capture-test :debug]]
+ (is (= []
+ (messages)))
+ (let [evaluated? (atom false)]
+ (log/trace (do
+ (reset! evaluated? true)
+ "a picture"))
+ (is (not @evaluated?)
+ "Should not evaluate logged forms that don't get captured")
+ (is (= []
+ (messages)))))))
+
+(deftest ^:parallel capture-logs-at-same-level-test
+ (testing "Capture logs at the same level"
+ (log.capture/with-log-messages-for-level [messages [metabase.util.log.capture-test :trace]]
+ (is (= []
+ (messages)))
+ (log/trace "a" "picture")
+ (is (= [{:namespace 'metabase.util.log.capture-test
+ :level :trace
+ :e nil
+ :message "a picture"}]
+ (messages))))))
+
+(deftest ^:parallel capture-logs-at-coarser-level-test
+ (testing "Capture logs at a coarser level"
+ (log.capture/with-log-messages-for-level [messages [metabase.util.log.capture-test :trace]]
+ (is (= []
+ (messages)))
+ (log/debug "a picture")
+ (is (= [{:namespace 'metabase.util.log.capture-test
+ :level :debug
+ :e nil
+ :message "a picture"}]
+ (messages))))))
+
+(deftest ^:parallel capture-child-namespaces-test
+ (testing "Should capture logging for child namespaces"
+ (log.capture/with-log-messages-for-level [messages ["metabase.util" :trace]]
+ (is (= []
+ (messages)))
+ (log/trace "a picture")
+ (is (= [{:namespace 'metabase.util.log.capture-test
+ :level :trace
+ :e nil
+ :message "a picture"}]
+ (messages))))))
+
+(deftest ^:parallel default-namespace-test
+ (testing "Capture logs for metabase\\..* by default"
+ (log.capture/with-log-messages-for-level [messages :trace]
+ (is (= []
+ (messages)))
+ (log/trace "a picture")
+ (is (= [{:namespace 'metabase.util.log.capture-test
+ :level :trace
+ :e nil
+ :message "a picture"}]
+ (messages))))))
+
+(deftest ^:parallel only-capture-child-namespaces-test
+ (testing "Capturing logging for metabase.util.log.capture should not capture metabase.util.log.capture-test"
+ (log.capture/with-log-messages-for-level [messages ["metabase.util.log.capture" :debug]]
+ (is (= []
+ (messages)))
+ (log/debug "a picture")
+ (is (= []
+ (messages))))))
+
+(deftest ^:parallel multiple-captures-test
+ (testing "Should be able to use `with-log-messages-for-level` multiple times"
+ (log.capture/with-log-messages-for-level [util-trace-messages ["metabase.util" :trace]]
+ (log.capture/with-log-messages-for-level [test-debug-messages [metabase.util.log.capture-test :debug]]
+ (is (= []
+ (util-trace-messages)))
+ (is (= []
+ (test-debug-messages)))
+ (testing "trace message should only show up in :trace"
+ (log/trace "a picture")
+ (is (= [{:namespace 'metabase.util.log.capture-test
+ :level :trace
+ :e nil
+ :message "a picture"}]
+ (util-trace-messages)))
+ (is (= []
+ (test-debug-messages))))
+ (testing "debug message should show up in :trace and :debug"
+ (log/debug "a bug")
+ (is (= [{:namespace 'metabase.util.log.capture-test
+ :level :trace
+ :e nil
+ :message "a picture"}
+ {:namespace 'metabase.util.log.capture-test
+ :level :debug
+ :e nil
+ :message "a bug"}]
+ (util-trace-messages)))
+ (is (= [{:namespace 'metabase.util.log.capture-test
+ :level :debug
+ :e nil
+ :message "a bug"}]
+ (test-debug-messages))))))))
+
+(deftest ^:parallel multiple-captures-test-2
+ (log.capture/with-log-messages-for-level [util-debug-messages ["metabase.util" :debug]
+ test-trace-messages [metabase.util.log.capture-test :trace]]
+ (is (= []
+ (util-debug-messages)))
+ (is (= []
+ (test-trace-messages)))
+ (testing "trace message should only show up in :trace"
+ (log/tracef "a %s" "picture")
+ (is (= []
+ (util-debug-messages)))
+ (is (= [{:namespace 'metabase.util.log.capture-test
+ :level :trace
+ :e nil
+ :message "a picture"}]
+ (test-trace-messages))))
+ (testing "debug message should show up in :trace and :debug"
+ (log/debugf "a %s" "bug")
+ (is (= [{:namespace 'metabase.util.log.capture-test
+ :level :debug
+ :e nil
+ :message "a bug"}]
+ (util-debug-messages)))
+ (is (= [{:namespace 'metabase.util.log.capture-test
+ :level :trace
+ :e nil
+ :message "a picture"}
+ {:namespace 'metabase.util.log.capture-test
+ :level :debug
+ :e nil
+ :message "a bug"}]
+ (test-trace-messages))))))
+
+(deftest ^:parallel preserve-formatting-test
+ ;; for whatever reason `logp` uses the equivalent of [[print-str]] while `logf` uses the equivalent of [[str]]
+ (testing 'logp
+ (log.capture/with-log-messages-for-level [messages :info]
+ (log/info "Something:" "s" [:vector "string"])
+ (is (=? [{:message "Something: s [:vector string]"}]
+ (messages)))))
+ (testing 'logf
+ (log.capture/with-log-messages-for-level [messages :info]
+ (log/infof "Something: %s %s" "s" [:vector "string"])
+ (is (=? [{:message "Something: s [:vector \"string\"]"}]
+ (messages))))))
diff --git a/test/metabase/util/log_test.cljc b/test/metabase/util/log_test.cljc
deleted file mode 100644
index 848e4770953..00000000000
--- a/test/metabase/util/log_test.cljc
+++ /dev/null
@@ -1,51 +0,0 @@
-(ns metabase.util.log-test
- (:require
- [clojure.test :refer [are deftest is]]
- [metabase.test.util.log :as tlog]
- [metabase.util.log :as log]))
-
-(deftest basic-logp-test
- (is (= [[:warn nil "a message"]]
- (tlog/with-log-messages-for-level :warn
- (log/info "not this one")
- (log/warn "a message"))))
- (is (= [[:info nil "here's one"]
- [:warn nil "a message"]]
- (tlog/with-log-messages-for-level :info
- (log/info "here's one")
- (log/warn "a message"))))
- (is (= [[:info nil ":keyword 78"]]
- (tlog/with-log-messages-for-level :info
- (log/info :keyword 78)))))
-
-(deftest logp-levels-test
- (let [important-message #{"fatal" "error" "warn" "info" "debug" "trace"}
- spam (fn []
- (log/fatal "fatal")
- (log/error "error")
- (log/warn "warn")
- (log/info "info")
- (log/debug "debug")
- (log/trace "trace"))
- logs [[:fatal nil "fatal"]
- [:error nil "error"]
- [:warn nil "warn"]
- [:info nil "info"]
- [:debug nil "debug"]
- [:trace nil "trace"]]]
- (are [prefix level] (= (->> logs
- (filter (fn [[_ _ msg]] (contains? important-message msg)))
- (take prefix))
- (tlog/with-log-messages-for-level level (spam)))
- ;0 :off - this doesn't work in CLJ and perhaps should?
- 1 :fatal
- 2 :error
- 3 :warn
- 4 :info
- 5 :debug
- 6 :trace)))
-
-(deftest logf-formatting-test
- (is (= [[:info nil "input: 8, 3; output: ignored"]]
- (tlog/with-log-messages-for-level :info
- (log/infof "input: %d, %d; %s: ignored" 8 3 "output")))))
--
GitLab