Feature CMR-10024 : Less Timed Logs from Ingest

common-lib/src/cmr/common/util.clj

@@ -163,11 +163,48 @@
          result# (do ~@body)]
      [(- (System/currentTimeMillis) start#) result#]))
 
+(defmacro defn-timed-level
+  "Creates a function that logs how long it took to execute the body. It
+   supports multiarity functions but only times how long the last listed arity
+   version takes. This means it should be used with multiarity functions where
+   it calls itself with the extra arguments.
+   This function is different from defn-timed by allowing the log function to be
+   passed in so as to allow the calling function to pick which level to log to."
+  [fn-name level & fn-tail]
+  (let [fn-name-str (name fn-name)
+        ns-str (str *ns*)
+        ;; Extract the doc string from the function if present
+        [doc-string fn-tail] (if (string? (first fn-tail))
+                               [(first fn-tail) (next fn-tail)]
+                               [nil fn-tail])
+        ;; Wrap single arity functions in a list
+        fn-tail (if (vector? (first fn-tail))
+                  (list fn-tail)
+                  fn-tail)
+        ;; extract other arities defined in the function which will not be
+        ;; timed.
+        other-arities (drop-last fn-tail)
+        ;; extract the last arity definitions bindings and body
+        [timed-arity-bindings & timed-arity-body] (last fn-tail)]
+    `(defn ~fn-name
+       ~@(when doc-string [doc-string])
+       ~@other-arities
+       (~timed-arity-bindings
+        (let [start# (System/currentTimeMillis)]
+          (try
+            ~@timed-arity-body
+            (finally
+              (let [elapsed# (- (System/currentTimeMillis) start#)]
+                (when (true? (cfg/defn-timed-debug))
+                  (~level
+                   (format
+                    "Timed function %s/%s took %d ms."
+                    ~ns-str ~fn-name-str elapsed#)))))))))))
 (defmacro defn-timed
   "Creates a function that logs how long it took to execute the body. It
-  supports multiarity functions but only times how long the last listed arity
-  version takes. This means it should be used with multiarity functions where
-  it calls itself with the extra arguments."
+   supports multiarity functions but only times how long the last listed arity
+   version takes. This means it should be used with multiarity functions where
+   it calls itself with the extra arguments."
   [fn-name & fn-tail]
   (let [fn-name-str (name fn-name)
         ns-str (str *ns*)
@@ -188,23 +225,23 @@
        ~@(when doc-string [doc-string])
        ~@other-arities
        (~timed-arity-bindings
-         (let [start# (System/currentTimeMillis)]
-           (try
-             ~@timed-arity-body
-             (finally
-               (let [elapsed# (- (System/currentTimeMillis) start#)]
-                 (when (true? (cfg/defn-timed-debug))
-                   (info
-                     (format
-                       "Timed function %s/%s took %d ms."
-                       ~ns-str ~fn-name-str elapsed#)))))))))))
+        (let [start# (System/currentTimeMillis)]
+          (try
+            ~@timed-arity-body
+            (finally
+              (let [elapsed# (- (System/currentTimeMillis) start#)]
+                (when (true? (cfg/defn-timed-debug))
+                  (info
+                   (format
+                    "Timed function %s/%s took %d ms."
+                    ~ns-str ~fn-name-str elapsed#)))))))))))
 
 (defmacro record-fields
   "Returns the set of fields in a record type as keywords. The record type
   passed in must be a java class. Uses the getBasis function on record classes
   which returns a list of symbols of the fields of the record."
   [record-type]
-  `(map keyword  ( ~(symbol (str record-type "/getBasis")))))
+  `(map keyword  (~(symbol (str record-type "/getBasis")))))
 
 (defn remove-map-keys
   "Removes all keys from a map where the provided function returns true for the
@@ -242,7 +279,7 @@
   (cond
     (map? x)
     (let [clean-map (remove-nil-keys
-                      (zipmap (keys x) (map remove-empty-maps (vals x))))]
+                     (zipmap (keys x) (map remove-empty-maps (vals x))))]
       (when (seq clean-map)
         clean-map))
     (sequential? x)
@@ -256,7 +293,7 @@
   [x]
   (cond
     (map? x) (let [clean-map (remove-nil-keys
-                               (zipmap (keys x) (map remove-nils-empty-maps-seqs (vals x))))]
+                              (zipmap (keys x) (map remove-nils-empty-maps-seqs (vals x))))]
                (when (seq clean-map)
                  clean-map))
     (vector? x) (when (seq x)
@@ -271,13 +308,13 @@
   [f m]
   (when m
     (letfn [(handle-value [v]
-                          (cond
-                            (map? v) (map-keys f v)
-                            (vector? v) (mapv handle-value v)
-                            (seq? v) (map handle-value v)
-                            :else v))
+              (cond
+                (map? v) (map-keys f v)
+                (vector? v) (mapv handle-value v)
+                (seq? v) (map handle-value v)
+                :else v))
             (mapper [[k v]]
-                    [(f k) (handle-value v)])]
+              [(f k) (handle-value v)])]
       (into {} (map mapper m)))))
 
 (defn map-values
@@ -379,13 +416,13 @@
   [f values]
   (let [errors (atom nil)
         result (doall (pmap
-                        (fn [val]
+                       (fn [val]
                          (try
                            (f val)
                            (catch Exception e
                              (swap! errors conj e)
                              nil)))
-                        values))]
+                       values))]
     (if @errors
       (throw (first @errors))
       result)))
@@ -533,7 +570,7 @@
         ^LZ4Factory factory (LZ4Factory/fastestInstance)
         ^LZ4Compressor compressor (.highCompressor factory)
         max-compressed-length (.maxCompressedLength
-                                compressor decompressed-length)
+                               compressor decompressed-length)
         compressed (byte-array max-compressed-length)
         compressed-length (.compress compressor
                                      ;; Data to compress and size
@@ -581,7 +618,7 @@
   obtained by gzip compressing the bytes of the original string."
   [input]
   (let [^bytes b64-bytes (-> input string->gzip-bytes b64/encode)]
-   (String. b64-bytes (java.nio.charset.Charset/forName "UTF-8"))))
+    (String. b64-bytes (java.nio.charset.Charset/forName "UTF-8"))))
 
 (defn gzip-base64->string
   "Converts a base64 encoded gzipped string back to the original string."
@@ -610,13 +647,13 @@
   [matching-map]
   (into {}
         (mapcatv
-          (fn [[k v]]
-            (if (map? v)
-              (mapv (fn [[path value]]
-                      [(vec (cons k path)) value])
-                    (map->path-values v))
-              [[[k] v]]))
-          matching-map)))
+         (fn [[k v]]
+           (if (map? v)
+             (mapv (fn [[path value]]
+                     [(vec (cons k path)) value])
+                   (map->path-values v))
+             [[[k] v]]))
+         matching-map)))
 
 (defn map-matches-path-values?
   "Returns true if the map matches the given path values. Path values are
@@ -783,10 +820,10 @@
      using-map-with-different-sized-collections-in-clojure"
   [f default & colls]
   (lazy-seq
-    (when (some seq colls)
-      (cons
-        (apply f (map #(if (seq %) (first %) default) colls))
-        (apply map-longest f default (map rest colls))))))
+   (when (some seq colls)
+     (cons
+      (apply f (map #(if (seq %) (first %) default) colls))
+      (apply map-longest f default (map rest colls))))))
 
 (defn key-sorted-map
   "Creates an empty map whose keys are sorted by the order given. Keys not in
@@ -796,21 +833,21 @@
   ;; Create a map of the keys to a numeric number indicating their position.
   (let [key-order-map (zipmap key-order (range))]
     (sorted-map-by
-      (fn [k1 k2]
-        (let [k1-order (key-order-map k1)
-              k2-order (key-order-map k2)]
-          (cond
+     (fn [k1 k2]
+       (let [k1-order (key-order-map k1)
+             k2-order (key-order-map k2)]
+         (cond
             ;; k1 and k2 are both in the key-order-map.
-            (and k1-order k2-order) (compare k1-order k2-order)
+           (and k1-order k2-order) (compare k1-order k2-order)
 
             ;; k1 is in the map but not k2. k1 should appear earlier than k2
-            k1-order -1
+           k1-order -1
 
             ;; k2 is in the map but not k1. k1 should appear after k2
-            k2-order 1
+           k2-order 1
 
             ;; Neither is in the map so compare them directly
-            :else (compare k1 k2)))))))
+           :else (compare k1 k2)))))))
 
 ;; Copied from clojure.core.incubator. We were having issues referring to this after updating to
 ;; Clojure 1.7.
@@ -926,10 +963,10 @@
   "Display a Java object's public methods."
   [obj]
   (print-table
-    (sort-by :name
-      (filter (fn [x]
-                (contains? (:flags x) :public))
-              (:members (reflect obj))))))
+   (sort-by :name
+            (filter (fn [x]
+                      (contains? (:flags x) :public))
+                    (:members (reflect obj))))))
 
 (defn show-env
   "Show the system environment currently available to Clojure.
@@ -958,11 +995,11 @@
   "Show just the system environment variables with the `CMR_` prefix."
   []
   (show-env
-    (comp keyword
-          string/lower-case
-          #(string/replace % "_" "-")
-          #(string/replace % #"^CMR_" ""))
-    #(string/starts-with? %1 "CMR_")))
+   (comp keyword
+         string/lower-case
+         #(string/replace % "_" "-")
+         #(string/replace % #"^CMR_" ""))
+   #(string/starts-with? %1 "CMR_")))
 
 (defn scrub-token
   "Scrub token:

ingest-app/src/cmr/db.clj

@@ -1,7 +1,7 @@
 (ns cmr.db
   "Entry point for the db related operations. Defines a main method that accepts arguments."
   (:import [java.io File])
-  (:require [cmr.common.log :refer (debug info warn error)]
+  (:require [cmr.common.log :refer (info error)]
             [cmr.oracle.user :as o]
             [cmr.oracle.config :as oracle-config]
             [cmr.ingest.config :as ingest-config]
@@ -44,7 +44,7 @@
           ;; trying non-local path to find drift migration files
           (with-redefs [drift.core/user-directory (fn [] (new File (str (.getProperty (System/getProperties) "user.dir") "/drift-migration-files")))]
             (drift.execute/run (conj (vec args) "-c" "config.ingest_migrate_config/app-migrate-config")))
-          (catch Exception e
+          (catch Exception _e
             (println "caught exception trying to find migration files in db.clj file for ingest-app. We are probably in local env. Trying local route to migration files...")
             (with-redefs [drift.core/user-directory (fn [] (new File (str (.getProperty (System/getProperties) "user.dir") "/src")))]
               (drift.execute/run (conj (vec args) "-c" "config.ingest_migrate_config/app-migrate-config")))))

ingest-app/src/cmr/ingest/api/bulk.clj

@@ -2,20 +2,16 @@
   "Bulk ingest functions in support of the ingest API."
   (:require
    [clojure.data.xml :as xml]
-   [clojure.string :as string]
    [cmr.acl.core :as acl]
    [cmr.common-app.api.launchpad-token-validation :as lt-validation]
-   [cmr.common.log :refer [debug info warn error]]
    [cmr.common.mime-types :as mt]
    [cmr.common.services.errors :as srvc-errors]
-   [cmr.common.xml.gen :refer :all]
    [cmr.ingest.api.core :as api-core]
    [cmr.ingest.config :as ingest-config]
    [cmr.ingest.data.bulk-update :as data-bulk-update]
    [cmr.ingest.data.granule-bulk-update :as data-gran-bulk-update]
    [cmr.ingest.services.bulk-update-service :as bulk-update]
    [cmr.ingest.services.granule-bulk-update-service :as gran-bulk-update]
-   [cmr.ingest.services.ingest-service :as ingest]
    [cmr.common.util :as util]))
 
 (defn bulk-update-collections
@@ -93,7 +89,7 @@
 
 (defmulti generate-provider-tasks-response
   "Convert a result to a proper response format"
-  (fn [headers result]
+  (fn [headers _result]
     (api-core/get-ingest-result-format headers :xml)))
 
 (defmethod generate-provider-tasks-response :json
@@ -102,7 +98,7 @@
   (api-core/generate-ingest-response headers result))
 
 (defmethod generate-provider-tasks-response :xml
-  [headers result]
+  [_headers result]
   ;; Create an xml response for a list of tasks
   {:status (api-core/ingest-status-code result)
    :headers {"Content-Type" (mt/format->mime-type :xml)}
@@ -114,7 +110,7 @@
 
 (defmulti get-provider-tasks*
   "Get bulk update tasks status based on concept type"
-  (fn [context provider-id concept-type params]
+  (fn [_context _provider-id concept-type _params]
     concept-type))
 
 (defmethod get-provider-tasks* :collection
@@ -138,7 +134,7 @@
 
 (defmulti generate-provider-task-status-response
   "Convert a result to a proper response format"
-  (fn [headers result]
+  (fn [headers _result]
     (api-core/get-ingest-result-format headers :xml)))
 
 (defmethod generate-provider-task-status-response :json
@@ -147,7 +143,7 @@
   (api-core/generate-ingest-response headers result))
 
 (defmethod generate-provider-task-status-response :xml
-  [headers result]
+  [_headers result]
   ;; Create an xml response for a list of tasks
   {:status (api-core/ingest-status-code result)
    :headers {"Content-Type" (mt/format->mime-type :xml)}

ingest-app/src/cmr/ingest/api/collections.clj

@@ -4,7 +4,7 @@
    [cmr.acl.core :as acl]
    [cmr.common-app.api.enabled :as common-enabled]
    [cmr.common-app.api.launchpad-token-validation :as lt-validation]
-   [cmr.common.log :refer [debug info warn error]]
+   [cmr.common.log :refer [info]]
    [cmr.common.util :as util]
    [cmr.ingest.api.core :as api-core]
    [cmr.ingest.services.ingest-service :as ingest]))
@@ -22,7 +22,7 @@
 
 (defn validate-collection
   [provider-id native-id request]
-  (let [{:keys [body content-type params headers request-context]} request
+  (let [{:keys [body content-type _params headers request-context]} request
         concept (api-core/body->concept! :collection provider-id native-id body content-type headers)
         validation-options (get-validation-options headers)]
     (api-core/verify-provider-exists request-context provider-id)
@@ -39,7 +39,7 @@
 
 (defn ingest-collection
   [provider-id native-id request]
-  (let [{:keys [body content-type params headers request-context]} request]
+  (let [{:keys [body content-type _params headers request-context]} request]
     (lt-validation/validate-launchpad-token request-context)
     (api-core/verify-provider-exists request-context provider-id)
     (acl/verify-ingest-management-permission request-context :update :provider-object provider-id)