Skip to content

Commit

Permalink
Feature CMR-10024 : Less Timed Logs from Ingest (#2157)
Browse files Browse the repository at this point in the history
* Kondo lint changes- ingest is now good
* Removing timed logs for a few functions which are either already pretty fast or do not show up much
  • Loading branch information
jceaser authored Aug 5, 2024
1 parent 5d79fb4 commit 5481836
Show file tree
Hide file tree
Showing 45 changed files with 315 additions and 255 deletions.
145 changes: 91 additions & 54 deletions common-lib/src/cmr/common/util.clj
Original file line number Diff line number Diff line change
Expand Up @@ -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*)
Expand All @@ -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
Expand Down Expand Up @@ -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)
Expand All @@ -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)
Expand All @@ -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
Expand Down Expand Up @@ -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)))
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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."
Expand Down Expand Up @@ -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
Expand Down Expand Up @@ -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
Expand All @@ -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.
Expand Down Expand Up @@ -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.
Expand Down Expand Up @@ -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:
Expand Down
4 changes: 2 additions & 2 deletions ingest-app/src/cmr/db.clj
Original file line number Diff line number Diff line change
@@ -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]
Expand Down Expand Up @@ -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")))))
Expand Down
14 changes: 5 additions & 9 deletions ingest-app/src/cmr/ingest/api/bulk.clj
Original file line number Diff line number Diff line change
Expand Up @@ -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
Expand Down Expand Up @@ -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
Expand All @@ -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)}
Expand All @@ -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
Expand All @@ -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
Expand All @@ -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)}
Expand Down
6 changes: 3 additions & 3 deletions ingest-app/src/cmr/ingest/api/collections.clj
Original file line number Diff line number Diff line change
Expand Up @@ -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]))
Expand All @@ -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)
Expand All @@ -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)
Expand Down
Loading

0 comments on commit 5481836

Please sign in to comment.