Merge pull request #3369 from metabase/faster-mac-app-launch-time

Faster mac app launch time 

OSX/Metabase/Backend/MetabaseTask.m

@@ -95,7 +95,9 @@
 		self.task.environment	= @{@"MB_DB_FILE": DBPath(),
 									@"MB_PLUGINS_DIR": PluginsDirPath(),
 									@"MB_JETTY_PORT": @(self.port)};
-		self.task.arguments		= @[@"-Djava.awt.headless=true",
+		self.task.arguments		= @[@"-Djava.awt.headless=true", // this prevents the extra java icon from popping up in the dock when running
+                                    @"-client",                  // make sure we're running in -client mode, which has a faster lanuch time
+                                    @"-Xverify:none",            // disable bytecode verification for faster launch speed, not really needed here since JAR is packaged as part of signed .app
 									@"-jar", UberjarPath()];
 				
 		__weak MetabaseTask *weakSelf = self;

project.clj

@@ -9,6 +9,7 @@
             "check-reflection-warnings" ["with-profile" "+reflection-warnings" "check"]
             "test" ["with-profile" "+expectations" "expectations"]
             "generate-sample-dataset" ["with-profile" "+generate-sample-dataset" "run"]
+            "profile" ["with-profile" "+profile" "run" "profile"]
             "h2" ["with-profile" "+h2-shell" "run" "-url" "jdbc:h2:./metabase.db" "-user" "" "-password" "" "-driver" "org.h2.Driver"]}
   :dependencies [[org.clojure/clojure "1.8.0"]
                  [org.clojure/core.async "0.2.391"]
@@ -72,14 +73,15 @@
                  [ring/ring-json "0.4.0"]                             ; Ring middleware for reading/writing JSON automatically
                  [stencil "0.5.0"]                                    ; Mustache templates for Clojure
                  [swiss-arrows "1.0.0"]]                              ; 'Magic wand' macro -<>, etc.
-  :repositories [["bintray" "https://dl.bintray.com/crate/crate"]]
+  :repositories [["bintray" "https://dl.bintray.com/crate/crate"]]    ; Repo for Crate JDBC driver
   :plugins [[lein-environ "1.0.3"]                                    ; easy access to environment variables
             [lein-ring "0.9.7"                                        ; start the HTTP server with 'lein ring server'
              :exclusions [org.clojure/clojure]]]                      ; TODO - should this be a dev dependency ?
   :main ^:skip-aot metabase.core
   :manifest {"Liquibase-Package" "liquibase.change,liquibase.changelog,liquibase.database,liquibase.parser,liquibase.precondition,liquibase.datatype,liquibase.serializer,liquibase.sqlgenerator,liquibase.executor,liquibase.snapshot,liquibase.logging,liquibase.diff,liquibase.structure,liquibase.structurecompare,liquibase.lockservice,liquibase.sdk,liquibase.ext"}
   :target-path "target/%s"
-  :jvm-opts ["-Djava.awt.headless=true"]                              ; prevent Java icon from randomly popping up in dock when running `lein ring server`
+  :jvm-opts ["-server"                                                ; Run JVM in server mode as opposed to client -- see http://stackoverflow.com/questions/198577/real-differences-between-java-server-and-java-client for a good explanation of this
+             "-Djava.awt.headless=true"]                              ; prevent Java icon from randomly popping up in dock when running `lein ring server`
   :javac-options ["-target" "1.7", "-source" "1.7"]
   :uberjar-name "metabase.jar"
   :ring {:handler metabase.core/app
@@ -114,7 +116,7 @@
                    :jvm-opts ["-Dlogfile.path=target/log"
                               "-Xms1024m"                             ; give JVM a decent heap size to start with
                               "-Xmx2048m"                             ; hard limit of 2GB so we stop hitting the 4GB container limit on CircleCI
-                              "-server"                               ; Run JVM in server mode as opposed to client -- see http://stackoverflow.com/questions/198577/real-differences-between-java-server-and-java-client for a good explanation of this
+                              "-Xverify:none"                         ; disable bytecode verification when running in dev so it starts slightly faster
                               "-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)
                    :aot [metabase.logger]}                            ; Log appender class needs to be compiled for log4j to use it
@@ -127,15 +129,19 @@
                                        "-Dmb.db.in.memory=true"
                                        "-Dmb.jetty.join=false"
                                        "-Dmb.jetty.port=3010"
-                                       "-Dmb.api.key=test-api-key"
-                                       "-Xverify:none"]}              ; disable bytecode verification when running tests so they start slightly faster
+                                       "-Dmb.api.key=test-api-key"]}
+             ;; build the uberjar with `lein uberjar`
              :uberjar {:aot :all
                        :jvm-opts ["-Dclojure.compiler.elide-meta=[:doc :added :file :line]" ; strip out metadata for faster load / smaller uberjar size
                                   "-Dmanifold.disable-jvm8-primitives=true"]}               ; disable Manifold Java 8 primitives (see https://github.com/ztellman/manifold#java-8-extensions)
-             :generate-sample-dataset {:dependencies [[faker "0.2.2"]                   ; Fake data generator -- port of Perl/Ruby
+             ;; generate sample dataset with `lein generate-sample-dataset`
+             :generate-sample-dataset {:dependencies [[faker "0.2.2"]                   ; Fake data generator -- port of Perl/Ruby library
                                                       [incanter/incanter-core "1.9.1"]] ; Satistical functions like normal distibutions}})
                                        :source-paths ["sample_dataset"]
                                        :main ^:skip-aot metabase.sample-dataset.generate}
+             ;; Profile Metabase start time with `lein profile`
+             :profile {:jvm-opts ["-XX:+CITime"                       ; print time spent in JIT compiler
+                                  "-XX:+PrintGC"]}                    ; print a message when garbage collection takes place
              ;; Run reset password from source: MB_DB_PATH=/path/to/metabase.db lein with-profile reset-password run email@address.com
              ;; Create the reset password JAR:  lein with-profile reset-password jar
              ;;                                   -> ./reset-password-artifacts/reset-password/reset-password.jar
@@ -147,4 +153,5 @@
                               ;; Exclude everything except for reset-password specific code in the created jar
                               :jar-exclusions [#"^(?!metabase/reset_password).*$"]
                               :target-path "reset-password-artifacts/%s"} ; different than ./target because otherwise lein uberjar will delete our artifacts and vice versa
-             :h2-shell {:main org.h2.tools.Shell}}) ; get the H2 shell with 'lein h2'
+             ;; get the H2 shell with 'lein h2'
+             :h2-shell {:main org.h2.tools.Shell}})

src/metabase/core.clj

 ;; -*- comment-column: 35; -*-
 (ns metabase.core
   (:gen-class)
-  (:require [clojure.tools.logging :as log]
+  (:require [clojure.string :as s]
+            [clojure.tools.logging :as log]
+            environ.core
             [ring.adapter.jetty :as ring-jetty]
             (ring.middleware [cookies :refer [wrap-cookies]]
                              [gzip :refer [wrap-gzip]]
@@ -24,8 +26,7 @@
                       [setup :as setup]
                       [task :as task]
                       [util :as u])
-            (metabase.models [setting :refer [defsetting]]
-                             [user :refer [User]])))
+            [metabase.models.user :refer [User]]))
 
 ;;; CONFIG
 
@@ -183,8 +184,7 @@
     (reset! jetty-instance nil)))
 
 
-;;; ## ---------------------------------------- App Main ----------------------------------------
-
+;;; ## ---------------------------------------- Normal Start ----------------------------------------
 
 (defn- start-normally []
   (log/info "Starting Metabase in STANDALONE mode")
@@ -201,29 +201,60 @@
       (log/error "Metabase Initialization FAILED: " (.getMessage e))
       (System/exit 1))))
 
-(def ^:private cmd->fn
-  {:migrate      (fn [direction]
-                   (db/migrate! @db/db-connection-details (keyword direction)))
-   :load-from-h2 (fn [& [h2-connection-string-or-nil]]
-                   (require 'metabase.cmd.load-from-h2)
-                   ((resolve 'metabase.cmd.load-from-h2/load-from-h2!) h2-connection-string-or-nil))})
+;;; ---------------------------------------- Special Commands ----------------------------------------
+
+(defn ^:command migrate
+  "Run database migrations. Valid options for DIRECTION are `up`, `force`, `down-one`, `print`, or `release-locks`."
+  [direction]
+  (db/migrate! @db/db-connection-details (keyword direction)))
+
+(defn ^:command load-from-h2
+  "Transfer data from existing H2 database to the newly created MySQL or Postgres DB specified by env vars."
+  ([]
+   (load-from-h2 nil))
+  ([h2-connection-string]
+   (require 'metabase.cmd.load-from-h2)
+   ((resolve 'metabase.cmd.load-from-h2/load-from-h2!) h2-connection-string)))
+
+(defn ^:command profile
+  "Start Metabase the usual way and exit. Useful for profiling Metabase launch time."
+  []
+  ;; override env var that would normally make Jetty block forever
+  (intern 'environ.core 'env (assoc environ.core/env :mb-jetty-join "false"))
+  (u/profile "start-normally" (start-normally)))
+
+(defn ^:command help
+  "Show this help message listing valid Metabase commands."
+  []
+  (println "Valid commands are:")
+  (doseq [[symb varr] (sort (ns-interns 'metabase.core))
+          :when       (:command (meta varr))]
+    (println symb (s/join " " (:arglists (meta varr))))
+    (println "\t" (:doc (meta varr)))))
+
+(defn- cmd->fn [command-name]
+  (or (when (seq command-name)
+        (when-let [varr (ns-resolve 'metabase.core (symbol command-name))]
+          (when (:command (meta varr))
+            @varr)))
+      (do (println (u/format-color 'red "Unrecognized command: %s" command-name))
+          (help)
+          (System/exit 1))))
 
 (defn- run-cmd [cmd & args]
-  (let [f (or (cmd->fn cmd)
-              (do (println (u/format-color 'red "Unrecognized command: %s" (name cmd)))
-                  (println "Valid commands are:\n" (u/pprint-to-str (map name (keys cmd->fn))))
-                  (System/exit 1)))]
-    (try (apply f args)
-         (catch Throwable e
-           (.printStackTrace e)
-           (println (u/format-color 'red "Command failed with exception: %s" (.getMessage e)))
-           (System/exit 1)))
-    (println "Success.")
-    (System/exit 0)))
+  (try (apply (cmd->fn cmd) args)
+       (catch Throwable e
+         (.printStackTrace e)
+         (println (u/format-color 'red "Command failed with exception: %s" (.getMessage e)))
+         (System/exit 1)))
+  (System/exit 0))
+
+
+;;; ---------------------------------------- App Entry Point ----------------------------------------
 
 (defn -main
   "Launch Metabase in standalone mode."
   [& [cmd & args]]
   (if cmd
-    (apply run-cmd (keyword cmd) args) ; run a command like `java -jar metabase.jar migrate release-locks` or `lein run migrate release-locks`
-    (start-normally)))                 ; with no command line args just start Metabase normally
+    (apply run-cmd cmd args) ; run a command like `java -jar metabase.jar migrate release-locks` or `lein run migrate release-locks`
+    (start-normally)))       ; with no command line args just start Metabase normally

src/metabase/util.clj

@@ -21,6 +21,11 @@
            javax.xml.bind.DatatypeConverter
            org.joda.time.format.DateTimeFormatter))
 
+;; This is the very first log message that will get printed.
+;; It's here because this is one of the very first namespaces that gets loaded, and the first that has access to the logger
+;; It shows up a solid 10-15 seconds before the "Starting Metabase in STANDALONE mode" message because so many other namespaces need to get loaded
+(log/info "Loading Metabase...")
+
 ;; Set the default width for pprinting to 200 instead of 72. The default width is too narrow and wastes a lot of space for pprinting huge things like expanded queries
 (intern 'clojure.pprint '*print-right-margin* 200)
 
@@ -707,3 +712,11 @@
     (map? object-or-id)     (recur (:id object-or-id))
     (integer? object-or-id) object-or-id
     :else                   (throw (Exception. (str "Not something with an ID: " object-or-id)))))
+
+(defmacro profile
+  "Like `clojure.core/time`, but lets you specify a message that gets printed with the total time, and formats the time nicely using `format-nanoseconds`."
+  {:style/indent 1}
+  [message & body]
+  `(let [start-time# (System/nanoTime)]
+     (prog1 (do ~@body)
+       (println (format-color '~'green "%s took %s" ~message (format-nanoseconds (- (System/nanoTime) start-time#)))))))