From d5caad6fc810a7f97ee22a755d5575cb4ab8a310 Mon Sep 17 00:00:00 2001 From: Cam Saul <cam@geotip.com> Date: Tue, 28 Jul 2015 13:57:21 -0700 Subject: [PATCH] a bit more logging cleanup --- project.clj | 3 +- src/metabase/db.clj | 1 - src/metabase/driver.clj | 8 +-- src/metabase/driver/query_processor.clj | 1 - src/metabase/driver/sync.clj | 70 ++++++++++--------- test/metabase/api/common/throttle_test.clj | 4 +- .../driver/generic_sql/native_test.clj | 13 ++-- test/metabase/test_setup.clj | 17 ++--- 8 files changed, 53 insertions(+), 64 deletions(-) diff --git a/project.clj b/project.clj index 9832355b3ee..683a457b2a2 100644 --- a/project.clj +++ b/project.clj @@ -80,7 +80,8 @@ "-Xmx2048m" ; hard limit of 2GB so we stop hitting the 4GB container limit on CircleCI "-XX:+CMSClassUnloadingEnabled" ; let Clojure's dynamically generated temporary classes be GC'ed from PermGen "-XX:+UseConcMarkSweepGC"]} ; Concurrent Mark Sweep GC needs to be used for Class Unloading (above) - :expectations {:injections [(require 'metabase.test-setup)] + :expectations {:global-vars {*warn-on-reflection* false} + :injections [(require 'metabase.test-setup)] :resource-paths ["test_resources"] :env {:mb-test-setting-1 "ABCDEFG"} :jvm-opts ["-Dmb.db.in.memory=true" diff --git a/src/metabase/db.clj b/src/metabase/db.clj index 36f6bebfe90..4d64736a1b0 100644 --- a/src/metabase/db.clj +++ b/src/metabase/db.clj @@ -95,7 +95,6 @@ [& {:keys [auto-migrate] :or {auto-migrate true}}] (reset! setup-db-has-been-called? true) - (log/info "Setting up DB specs...") ;; Test DB connection and throw exception if we have any troubles connecting (log/info "Verifying Database Connection ...") diff --git a/src/metabase/driver.clj b/src/metabase/driver.clj index c9d0ccb2a9c..f96936cce9f 100644 --- a/src/metabase/driver.clj +++ b/src/metabase/driver.clj @@ -125,7 +125,7 @@ (let [-sync-database! (u/runtime-resolved-fn 'metabase.driver.sync 'sync-database!)] ; these need to be resolved at runtime to avoid circular deps (fn [database] {:pre [(map? database)]} - (time (-sync-database! (engine->driver (:engine database)) database))))) + (-sync-database! (engine->driver (:engine database)) database)))) (def ^{:arglists '([table])} sync-table! "Sync a `Table` and its `Fields`." @@ -183,10 +183,8 @@ (when (= :failed (:status query-result)) (throw (Exception. ^String (get query-result :error "general error")))) (query-complete query-execution query-result)) - (catch Exception ex - (log/warn ex) - (.printStackTrace ex) - (query-fail query-execution (.getMessage ex))))))) + (catch Exception e + (query-fail query-execution (.getMessage e))))))) (defn query-fail "Save QueryExecution state and construct a failed query response" diff --git a/src/metabase/driver/query_processor.clj b/src/metabase/driver/query_processor.clj index e1f570e54c5..24f2d52b09b 100644 --- a/src/metabase/driver/query_processor.clj +++ b/src/metabase/driver/query_processor.clj @@ -41,7 +41,6 @@ (fn [query] (try (qp query) (catch Throwable e - (.printStackTrace e) {:status :failed :error (.getMessage e) :stacktrace (u/filtered-stacktrace e) diff --git a/src/metabase/driver/sync.clj b/src/metabase/driver/sync.clj index 4d0b7edf6f7..198e01dd5ae 100644 --- a/src/metabase/driver/sync.clj +++ b/src/metabase/driver/sync.clj @@ -43,39 +43,41 @@ *sel-disable-logging* true] (sync-in-context driver database (fn [] - (log/info (u/format-color 'magenta "Syncing %s database '%s'..." (name (:engine database)) (:name database))) - - (let [active-table-names (active-table-names driver database) - table-name->id (sel :many :field->id [Table :name] :db_id (:id database) :active true)] - (assert (set? active-table-names) "active-table-names should return a set.") - (assert (every? string? active-table-names) "active-table-names should return the names of Tables as *strings*.") - - ;; First, let's mark any Tables that are no longer active as such. - ;; These are ones that exist in table-name->id but not in active-table-names. - (doseq [[table-name table-id] table-name->id] - (when-not (contains? active-table-names table-name) - (upd Table table-id :active false) - (log/info (u/format-color 'cyan "Marked table %s.%s as inactive." (:name database) table-name)) - - ;; We need to mark driver Table's Fields as inactive so we don't expose them in UI such as FK selector (etc.) - (k/update Field - (k/where {:table_id table-id}) - (k/set-fields {:active false})))) - - ;; Next, we'll create new Tables (ones that came back in active-table-names but *not* in table-name->id) - (let [existing-table-names (set (keys table-name->id)) - new-table-names (set/difference active-table-names existing-table-names)] - (when (seq new-table-names) - (log/debug (u/format-color 'blue "Found new tables: %s" new-table-names)) - (doseq [new-table-name new-table-names] - (ins Table :db_id (:id database), :active true, :name new-table-name))))) - - ;; Now sync the active tables - (->> (sel :many Table :db_id (:id database) :active true) - (map #(assoc % :db (delay database))) ; replace default delays with ones that reuse database (and don't require a DB call) - (sync-database-active-tables! driver)) - - (log/info (u/format-color 'magenta "Finished syncing %s database %s." (name (:engine database)) (:name database))))))) + (let [start-time (System/currentTimeMillis)] + (log/info (u/format-color 'magenta "Syncing %s database '%s'..." (name (:engine database)) (:name database))) + + (let [active-table-names (active-table-names driver database) + table-name->id (sel :many :field->id [Table :name] :db_id (:id database) :active true)] + (assert (set? active-table-names) "active-table-names should return a set.") + (assert (every? string? active-table-names) "active-table-names should return the names of Tables as *strings*.") + + ;; First, let's mark any Tables that are no longer active as such. + ;; These are ones that exist in table-name->id but not in active-table-names. + (doseq [[table-name table-id] table-name->id] + (when-not (contains? active-table-names table-name) + (upd Table table-id :active false) + (log/info (u/format-color 'cyan "Marked table %s.%s as inactive." (:name database) table-name)) + + ;; We need to mark driver Table's Fields as inactive so we don't expose them in UI such as FK selector (etc.) + (k/update Field + (k/where {:table_id table-id}) + (k/set-fields {:active false})))) + + ;; Next, we'll create new Tables (ones that came back in active-table-names but *not* in table-name->id) + (let [existing-table-names (set (keys table-name->id)) + new-table-names (set/difference active-table-names existing-table-names)] + (when (seq new-table-names) + (log/debug (u/format-color 'blue "Found new tables: %s" new-table-names)) + (doseq [new-table-name new-table-names] + (ins Table :db_id (:id database), :active true, :name new-table-name))))) + + ;; Now sync the active tables + (->> (sel :many Table :db_id (:id database) :active true) + (map #(assoc % :db (delay database))) ; replace default delays with ones that reuse database (and don't require a DB call) + (sync-database-active-tables! driver)) + + (log/info (u/format-color 'magenta "Finished syncing %s database %s. (%d ms)" (name (:engine database)) (:name database) + (- (System/currentTimeMillis) start-time)))))))) (defn sync-table! "Sync a *single* TABLE by running all the sync steps for it. @@ -146,7 +148,7 @@ (sync-table-fields-metadata! driver table) (swap! finished-tables-count inc) - (log/info (u/format-color 'magenta "%s Synced table '%s'." (sync-progress-meter-string @finished-tables-count tables-count) (:name table))))))) + (log/debug (u/format-color 'magenta "%s Synced table '%s'." (sync-progress-meter-string @finished-tables-count tables-count) (:name table))))))) ;; ## sync-table steps. diff --git a/test/metabase/api/common/throttle_test.clj b/test/metabase/api/common/throttle_test.clj index 0509c7ebccc..f320f91eb63 100644 --- a/test/metabase/api/common/throttle_test.clj +++ b/test/metabase/api/common/throttle_test.clj @@ -99,10 +99,10 @@ (attempt 1 :d))) ;; Check that the interal list for the throttler doesn't keep growing after throttling starts -(expect [0 4] +(expect [0 3] [(do (reset! (:attempts test-throttler) '()) ; reset it to 0 (count @(:attempts test-throttler))) - (do (attempt 1000) + (do (attempt 10) (count @(:attempts test-throttler)))]) ;; Check that attempts clear after the TTL diff --git a/test/metabase/driver/generic_sql/native_test.clj b/test/metabase/driver/generic_sql/native_test.clj index a3412a6b69e..07245c805aa 100644 --- a/test/metabase/driver/generic_sql/native_test.clj +++ b/test/metabase/driver/generic_sql/native_test.clj @@ -35,13 +35,12 @@ ;; Check that we get proper error responses for malformed SQL (expect {:status :failed :error "Column \"ZID\" not found"} - (do (log/info (color/green "NOTE: The following stacktrace is expected <3")) ; this will print a stacktrace - (dissoc (driver/process-query {:native {:query "SELECT ZID FROM CHECKINS LIMIT 2;"} ; make sure people know it's to be expected - :type :native - :database (db-id)}) - :stacktrace - :query - :expanded-query))) + (dissoc (driver/process-query {:native {:query "SELECT ZID FROM CHECKINS LIMIT 2;"} ; make sure people know it's to be expected + :type :native + :database (db-id)}) + :stacktrace + :query + :expanded-query)) ;; Check that we're not allowed to run SQL against an H2 database with a non-admin account (expect "Running SQL queries against H2 databases using the default (admin) database user is forbidden." diff --git a/test/metabase/test_setup.clj b/test/metabase/test_setup.clj index 5526cbd0de4..e0edf0f7e1f 100644 --- a/test/metabase/test_setup.clj +++ b/test/metabase/test_setup.clj @@ -79,22 +79,13 @@ (defn test-startup {:expectations-options :before-run} [] - (log/info "Starting up Metabase unit test runner") - (log/info "Setting up test DB and running migrations...") (db/setup-db :auto-migrate true) - ;; add any global settings defaults - (metabase.models.setting/set :site-name "Metabase Test") - - ;; Load the test datasets - (load-test-datasets) - - ;; startup test web server - (core/start-jetty) - - ;; start the task runner - (task/start-task-runner!)) + (metabase.models.setting/set :site-name "Metabase Test") ; add any global settings defaults + (load-test-datasets) ; Load the test datasets + (core/start-jetty) ; startup test web server + (task/start-task-runner!)) ; start the task runner (defn test-teardown -- GitLab