From 0505346258516e2d5d900c4015ffc5ba5ac2f731 Mon Sep 17 00:00:00 2001 From: Nikolai Sinkov Date: Thu, 11 Nov 2021 21:32:05 -0600 Subject: [PATCH 1/6] record usage of datomic entities and print to file on exit --- scheduler/project.clj | 1 + scheduler/src/cook/other/map_mock.clj | 57 +++++++++++++++++++++++++++ scheduler/src/cook/queries.clj | 6 ++- scheduler/src/cook/rest/api.clj | 25 ++++++++++++ scheduler/src/cook/tools.clj | 4 +- 5 files changed, 90 insertions(+), 3 deletions(-) create mode 100644 scheduler/src/cook/other/map_mock.clj diff --git a/scheduler/project.clj b/scheduler/project.clj index 687e151026..e3ab3a7b41 100644 --- a/scheduler/project.clj +++ b/scheduler/project.clj @@ -49,6 +49,7 @@ org.slf4j/slf4j-api org.slf4j/slf4j-simple]] [better-cond "1.0.1"] + [potemkin "0.4.5"] ;;Logging [org.clojure/tools.logging "0.2.6"] diff --git a/scheduler/src/cook/other/map_mock.clj b/scheduler/src/cook/other/map_mock.clj new file mode 100644 index 0000000000..e7ece86b95 --- /dev/null +++ b/scheduler/src/cook/other/map_mock.clj @@ -0,0 +1,57 @@ +;; +;; Copyright (c) Two Sigma Open Source, LLC +;; +;; Licensed under the Apache License, Version 2.0 (the "License"); +;; you may not use this file except in compliance with the License. +;; You may obtain a copy of the License at +;; +;; http://www.apache.org/licenses/LICENSE-2.0 +;; +;; Unless required by applicable law or agreed to in writing, software +;; distributed under the License is distributed on an "AS IS" BASIS, +;; WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +;; See the License for the specific language governing permissions and +;; limitations under the License. +;; +(ns cook.other.map-mock + (:require [clojure.string :as str] + [potemkin.collections :refer [def-map-type]]) + (:import (java.util Arrays) + (java.util.concurrent ConcurrentHashMap) + (java.util.concurrent.atomic LongAdder) + (java.util.function Function))) + +(defn ignored? [classname] + (let [ignored #{"callers" "dbg" "clojure.lang" "swank" "nrepl" "eval"}] + (some #(re-find (re-pattern %) classname) ignored))) + +(defn cook-callers [] + (let [fns (map #(str (.getClassName %)) + (-> (Throwable.) .fillInStackTrace .getStackTrace))] + ;(vec (doall (remove ignored? fns))) + (vec (doall (filter #(str/starts-with? % "cook.") fns))))) + +(def ^Function make-map-if-absent + (reify Function (apply [_ _] (ConcurrentHashMap.)))) + +(def ^Function make-long-adder-if-absent + (reify Function (apply [_ _] (LongAdder.)))) + +(def ^ConcurrentHashMap access-map + (ConcurrentHashMap.)) + +(def-map-type + AccessLoggingMapType [backing-map entity-name] + (get [_ field-name default-value] + (let [^ConcurrentHashMap access-map-by-entity (.computeIfAbsent access-map entity-name make-map-if-absent) + ^ConcurrentHashMap access-map-by-field (.computeIfAbsent access-map-by-entity field-name make-map-if-absent) + callstack (-> (cook-callers) distinct into-array Arrays/asList) + ^LongAdder adder (.computeIfAbsent access-map-by-field callstack make-long-adder-if-absent)] + (.increment adder)) + (get backing-map field-name default-value)) + (assoc [_ k v] (assoc backing-map k v)) + (dissoc [_ k] (dissoc backing-map k)) + (keys [_] (keys backing-map)) + (meta [_] (meta backing-map)) + (empty [_] {}) + (with-meta [_ new-meta] (with-meta backing-map new-meta))) diff --git a/scheduler/src/cook/queries.clj b/scheduler/src/cook/queries.clj index e532048720..d49958316a 100644 --- a/scheduler/src/cook/queries.clj +++ b/scheduler/src/cook/queries.clj @@ -14,7 +14,8 @@ ;; limitations under the License. ;; (ns cook.queries - (:require [datomic.api :as d :refer [q]] + (:require [cook.other.map-mock :as mm] + [datomic.api :as d :refer [q]] [metrics.timers :as timers])) ;; @@ -49,7 +50,8 @@ [?j :job/commit-latch ?cl] [?cl :commit-latch/committed? ?committed?]] unfiltered-db :job.state/waiting committed?) - (map (partial d/entity unfiltered-db)))) + (map (partial d/entity unfiltered-db)) + (map #(mm/->AccessLoggingMapType % :pending-job)))) (timers/deftimer [cook-mesos scheduler get-pending-jobs-duration]) diff --git a/scheduler/src/cook/rest/api.clj b/scheduler/src/cook/rest/api.clj index ff050c97d4..bf5ad0016e 100644 --- a/scheduler/src/cook/rest/api.clj +++ b/scheduler/src/cook/rest/api.clj @@ -37,6 +37,7 @@ [cook.datomic :as datomic] [cook.mesos] [cook.mesos.reason :as reason] + [cook.other.map-mock :as mm] [cook.passport :as passport] [cook.plugins.adjustment :as adjustment] [cook.plugins.definitions :as plugins] @@ -3399,6 +3400,30 @@ (let [reason (get-in ctx [:request :body-params :reason]) request-user (get-in ctx [:request :authorization/user])] (log/info "Exiting due to /shutdown-leader request from" request-user "with reason:" reason) + (with-open [^java.io.BufferedWriter w (clojure.java.io/writer "datomic_field_access.txt")] + (doseq [[entity-name v] mm/access-map] + (.write w (str entity-name)) + (.newLine w) + (doseq [[field-name _] v] + (.write w (str " " field-name)) + (.newLine w)) + (.newLine w) + (.newLine w))) + (with-open [^java.io.BufferedWriter w (clojure.java.io/writer "datomic_field_access_detailed.txt")] + (doseq [[entity-name v] mm/access-map] + (.write w (str entity-name)) + (.newLine w) + (doseq [[field-name vv] v] + (.write w (str " " field-name)) + (.newLine w) + (doseq [[callstack count] (sort-by (fn [[k, v]] (- v)) vv)] + (.write w (str " " count)) + (.newLine w) + (doseq [function callstack] + (.write w (str " " function)) + (.newLine w)))) + (.newLine w) + (.newLine w))) (shutdown!))) (defn post-shutdown-leader-handler diff --git a/scheduler/src/cook/tools.clj b/scheduler/src/cook/tools.clj index eeac285207..3cbf38f3a3 100644 --- a/scheduler/src/cook/tools.clj +++ b/scheduler/src/cook/tools.clj @@ -28,6 +28,7 @@ [cook.cached-queries :as cached-queries] [cook.caches :as caches] [cook.config :as config] + [cook.other.map-mock :as mm] [cook.pool :as pool] [cook.queries :as queries] [cook.quota :as quota] @@ -488,7 +489,8 @@ :where [?i :instance/status ?status]] db [:instance.status/running :instance.status/unknown]) - (map (partial d/entity db))))) + (map (partial d/entity db)) + (map #(mm/->AccessLoggingMapType % :running-task))))) (defn retrieve-instance "Given an instance UUID, return the instance entity." From 5f8faa9511149cbc770ad7ee1357796d1c6f65a4 Mon Sep 17 00:00:00 2001 From: Nikolai Sinkov Date: Fri, 12 Nov 2021 18:03:30 -0600 Subject: [PATCH 2/6] record usage of datomic entities and print to file on exit --- scheduler/src/cook/other/map_mock.clj | 18 +++++++++++++++--- 1 file changed, 15 insertions(+), 3 deletions(-) diff --git a/scheduler/src/cook/other/map_mock.clj b/scheduler/src/cook/other/map_mock.clj index e7ece86b95..bc41a8e346 100644 --- a/scheduler/src/cook/other/map_mock.clj +++ b/scheduler/src/cook/other/map_mock.clj @@ -26,10 +26,11 @@ (some #(re-find (re-pattern %) classname) ignored))) (defn cook-callers [] - (let [fns (map #(str (.getClassName %)) + (let [fns (map #(str (.getClassName %) ":" (.getLineNumber %)) (-> (Throwable.) .fillInStackTrace .getStackTrace))] ;(vec (doall (remove ignored? fns))) - (vec (doall (filter #(str/starts-with? % "cook.") fns))))) + ;(vec (doall (filter #(str/starts-with? % "cook.") fns))) + (vec fns))) (def ^Function make-map-if-absent (reify Function (apply [_ _] (ConcurrentHashMap.)))) @@ -40,6 +41,8 @@ (def ^ConcurrentHashMap access-map (ConcurrentHashMap.)) +(declare make-access-logging-map) + (def-map-type AccessLoggingMapType [backing-map entity-name] (get [_ field-name default-value] @@ -48,10 +51,19 @@ callstack (-> (cook-callers) distinct into-array Arrays/asList) ^LongAdder adder (.computeIfAbsent access-map-by-field callstack make-long-adder-if-absent)] (.increment adder)) - (get backing-map field-name default-value)) + (let [result (get backing-map field-name default-value)] + (if (instance? datomic.query.EntityMap result) + (if-let [ix (str/index-of (str field-name) "/_")] + (make-access-logging-map result (keyword (str (name entity-name) (subs field-name (+ 1 ix))))) + result) + result))) (assoc [_ k v] (assoc backing-map k v)) (dissoc [_ k] (dissoc backing-map k)) (keys [_] (keys backing-map)) (meta [_] (meta backing-map)) (empty [_] {}) (with-meta [_ new-meta] (with-meta backing-map new-meta))) + +(defn make-access-logging-map + [backing-map entity-name] + (->AccessLoggingMapType backing-map entity-name)) \ No newline at end of file From 7282094599e151cf1282707d7a48333f4ef5741f Mon Sep 17 00:00:00 2001 From: Nikolai Sinkov Date: Fri, 12 Nov 2021 21:53:41 -0600 Subject: [PATCH 3/6] recursively instrument all datomic maps --- scheduler/src/cook/other/map_mock.clj | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/scheduler/src/cook/other/map_mock.clj b/scheduler/src/cook/other/map_mock.clj index bc41a8e346..17550c17c0 100644 --- a/scheduler/src/cook/other/map_mock.clj +++ b/scheduler/src/cook/other/map_mock.clj @@ -53,9 +53,7 @@ (.increment adder)) (let [result (get backing-map field-name default-value)] (if (instance? datomic.query.EntityMap result) - (if-let [ix (str/index-of (str field-name) "/_")] - (make-access-logging-map result (keyword (str (name entity-name) (subs field-name (+ 1 ix))))) - result) + (make-access-logging-map result (keyword (str (name entity-name) "_" (str field-name)))) result))) (assoc [_ k v] (assoc backing-map k v)) (dissoc [_ k] (dissoc backing-map k)) From 5c08ced59bfb931f98a630bb88d0049466bcb240 Mon Sep 17 00:00:00 2001 From: Nikolai Sinkov Date: Mon, 15 Nov 2021 21:17:07 -0600 Subject: [PATCH 4/6] add timestamp to file names --- scheduler/src/cook/rest/api.clj | 45 +++++++++++++++++---------------- 1 file changed, 23 insertions(+), 22 deletions(-) diff --git a/scheduler/src/cook/rest/api.clj b/scheduler/src/cook/rest/api.clj index bf5ad0016e..a99267c248 100644 --- a/scheduler/src/cook/rest/api.clj +++ b/scheduler/src/cook/rest/api.clj @@ -3400,30 +3400,31 @@ (let [reason (get-in ctx [:request :body-params :reason]) request-user (get-in ctx [:request :authorization/user])] (log/info "Exiting due to /shutdown-leader request from" request-user "with reason:" reason) - (with-open [^java.io.BufferedWriter w (clojure.java.io/writer "datomic_field_access.txt")] - (doseq [[entity-name v] mm/access-map] - (.write w (str entity-name)) - (.newLine w) - (doseq [[field-name _] v] - (.write w (str " " field-name)) - (.newLine w)) - (.newLine w) - (.newLine w))) - (with-open [^java.io.BufferedWriter w (clojure.java.io/writer "datomic_field_access_detailed.txt")] - (doseq [[entity-name v] mm/access-map] - (.write w (str entity-name)) - (.newLine w) - (doseq [[field-name vv] v] - (.write w (str " " field-name)) + (let [timestamp (quot (System/currentTimeMillis) 1000)] + (with-open [^java.io.BufferedWriter w (clojure.java.io/writer "datomic_field_access_" timestamp ".txt")] + (doseq [[entity-name v] mm/access-map] + (.write w (str entity-name)) (.newLine w) - (doseq [[callstack count] (sort-by (fn [[k, v]] (- v)) vv)] - (.write w (str " " count)) + (doseq [[field-name _] v] + (.write w (str " " field-name)) + (.newLine w)) + (.newLine w) + (.newLine w))) + (with-open [^java.io.BufferedWriter w (clojure.java.io/writer "datomic_field_access_detailed_" timestamp ".txt")] + (doseq [[entity-name v] mm/access-map] + (.write w (str entity-name)) + (.newLine w) + (doseq [[field-name vv] v] + (.write w (str " " field-name)) (.newLine w) - (doseq [function callstack] - (.write w (str " " function)) - (.newLine w)))) - (.newLine w) - (.newLine w))) + (doseq [[callstack count] (sort-by (fn [[k, v]] (- v)) vv)] + (.write w (str " " count)) + (.newLine w) + (doseq [function callstack] + (.write w (str " " function)) + (.newLine w)))) + (.newLine w) + (.newLine w)))) (shutdown!))) (defn post-shutdown-leader-handler From dc383bff8dd10e9cbff6878bf33eed9b295a9168 Mon Sep 17 00:00:00 2001 From: Nikolai Sinkov Date: Mon, 15 Nov 2021 21:20:01 -0600 Subject: [PATCH 5/6] make entity name properly nested --- scheduler/src/cook/other/map_mock.clj | 2 +- scheduler/src/cook/queries.clj | 2 +- scheduler/src/cook/tools.clj | 2 +- 3 files changed, 3 insertions(+), 3 deletions(-) diff --git a/scheduler/src/cook/other/map_mock.clj b/scheduler/src/cook/other/map_mock.clj index 17550c17c0..a8912c4d6e 100644 --- a/scheduler/src/cook/other/map_mock.clj +++ b/scheduler/src/cook/other/map_mock.clj @@ -53,7 +53,7 @@ (.increment adder)) (let [result (get backing-map field-name default-value)] (if (instance? datomic.query.EntityMap result) - (make-access-logging-map result (keyword (str (name entity-name) "_" (str field-name)))) + (make-access-logging-map result (str entity-name "_" (str field-name))) result))) (assoc [_ k v] (assoc backing-map k v)) (dissoc [_ k] (dissoc backing-map k)) diff --git a/scheduler/src/cook/queries.clj b/scheduler/src/cook/queries.clj index d49958316a..5fa80dd136 100644 --- a/scheduler/src/cook/queries.clj +++ b/scheduler/src/cook/queries.clj @@ -51,7 +51,7 @@ [?cl :commit-latch/committed? ?committed?]] unfiltered-db :job.state/waiting committed?) (map (partial d/entity unfiltered-db)) - (map #(mm/->AccessLoggingMapType % :pending-job)))) + (map #(mm/->AccessLoggingMapType % "pending-job")))) (timers/deftimer [cook-mesos scheduler get-pending-jobs-duration]) diff --git a/scheduler/src/cook/tools.clj b/scheduler/src/cook/tools.clj index 3cbf38f3a3..09e6913534 100644 --- a/scheduler/src/cook/tools.clj +++ b/scheduler/src/cook/tools.clj @@ -490,7 +490,7 @@ [?i :instance/status ?status]] db [:instance.status/running :instance.status/unknown]) (map (partial d/entity db)) - (map #(mm/->AccessLoggingMapType % :running-task))))) + (map #(mm/->AccessLoggingMapType % "running-task"))))) (defn retrieve-instance "Given an instance UUID, return the instance entity." From 07cfbb8f0d3a24da7e5d40064feeecee7e7a577d Mon Sep 17 00:00:00 2001 From: Nikolai Sinkov Date: Mon, 15 Nov 2021 23:32:02 -0600 Subject: [PATCH 6/6] fix file name --- scheduler/src/cook/rest/api.clj | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/scheduler/src/cook/rest/api.clj b/scheduler/src/cook/rest/api.clj index a99267c248..08fad7ff30 100644 --- a/scheduler/src/cook/rest/api.clj +++ b/scheduler/src/cook/rest/api.clj @@ -3401,7 +3401,7 @@ request-user (get-in ctx [:request :authorization/user])] (log/info "Exiting due to /shutdown-leader request from" request-user "with reason:" reason) (let [timestamp (quot (System/currentTimeMillis) 1000)] - (with-open [^java.io.BufferedWriter w (clojure.java.io/writer "datomic_field_access_" timestamp ".txt")] + (with-open [^java.io.BufferedWriter w (clojure.java.io/writer (str "datomic_field_access_" timestamp ".txt"))] (doseq [[entity-name v] mm/access-map] (.write w (str entity-name)) (.newLine w) @@ -3410,7 +3410,7 @@ (.newLine w)) (.newLine w) (.newLine w))) - (with-open [^java.io.BufferedWriter w (clojure.java.io/writer "datomic_field_access_detailed_" timestamp ".txt")] + (with-open [^java.io.BufferedWriter w (clojure.java.io/writer (str "datomic_field_access_detailed_" timestamp ".txt"))] (doseq [[entity-name v] mm/access-map] (.write w (str entity-name)) (.newLine w)