diff --git a/project.clj b/project.clj index a9fdf62..041325a 100644 --- a/project.clj +++ b/project.clj @@ -1,4 +1,4 @@ -(defproject com.taoensso/tufte "2.6.1" +(defproject com.taoensso/tufte "2.7.0-alpha2" :author "Peter Taoussanis " :description "Simple performance monitoring for Clojure/Script applications" :url "https://github.com/taoensso/tufte" diff --git a/src/taoensso/tufte.cljc b/src/taoensso/tufte.cljc index dadf285..7e65887 100644 --- a/src/taoensso/tufte.cljc +++ b/src/taoensso/tufte.cljc @@ -33,16 +33,25 @@ {:author "Peter Taoussanis (@ptaoussanis)"} (:require - [taoensso.encore :as enc :refer [have have?]] - [taoensso.tufte.stats :as stats] + [taoensso.encore :as enc :refer [have have?]] + [taoensso.encore.runner :as runner] + [taoensso.tufte.stats :as stats] #?(:clj [taoensso.tufte.impl :as impl] :cljs [taoensso.tufte.impl :as impl :refer [PStats]])) - #?(:clj (:import [taoensso.tufte.impl PStats])) + #?(:clj (:import [taoensso.tufte.impl PStats])) #?(:cljs (:require-macros [taoensso.tufte :refer [profiled]]))) -(enc/assert-min-encore-version [3 66 0]) +(comment (remove-ns 'taoensso.tufte)) + +(enc/assert-min-encore-version [3 67 0]) + +;;;; TODO +;; - Use new `enc/ctx-filter` and config utils for filtering. +;; - Add gs pid stack (w/ max length and recursion detection). +;; - Use new Telemere-style handler registration, with per-handler opts? +;; Replace impl/handler-runner, and accumulating-handler runner. ;;;; Level filtering ;; Terminology note: we distinguish between call/form and min levels to ensure @@ -175,9 +184,10 @@ (not (string? ns-str-form)) ; Not a compile-time ns-str const (may-profile-ns? compile-time-ns-filter ns-str-form)))))) -;;;; Output handlers -;; Handlers are used for `profile` output, let us nicely decouple stat -;; creation and consumption. +;;;; `profile` handlers +;; Handlers decouples stat creation and consumption + +#?(:clj (enc/defalias impl/handler-runner-opts)) (defrecord HandlerVal [ns-str level ?id ?data pstats pstats-str_ ?file ?line]) @@ -311,16 +321,14 @@ (impl/new-pdata-local nmax)))) (comment - @@(new-pdata) - - ;; Note that dynamic pdata with non-dynamic `with-profiling` is fine: + @((new-pdata)) (let [pd (new-pdata) t0 (System/nanoTime)] + ;; Note that dynamic pdata with non-dynamic `with-profiling` is fine: (with-profiling pd {} - (p :foo (Thread/sleep 100)) - (capture-time! pd :bar (- t0 (System/nanoTime)))) - @pd) ; => pstats - ) + (p :pid1 (Thread/sleep 100)) + (pd :pid2 (- t0 (System/nanoTime)) nil)) + @(pd))) #?(:clj (defmacro with-profiling @@ -349,17 +357,17 @@ See `new-pdata` for more info on low-level primitives. See also `capture-time!*`." - ([pdata id nano-secs-elapsed] `(impl/capture-time! ~pdata ~id ~nano-secs-elapsed ~(enc/get-source &form &env))) + ([pdata id nano-secs-elapsed] `(~pdata ~id ~nano-secs-elapsed ~(enc/get-source &form &env))) ([ id nano-secs-elapsed] `(when-let [~'pd (or impl/*pdata* (impl/pdata-local-get))] - (impl/capture-time! ~'pd ~id ~nano-secs-elapsed ~(enc/get-source &form &env)))))) + (~'pd ~id ~nano-secs-elapsed ~(enc/get-source &form &env)))))) (defn capture-time!* "Like `capture-time!` but: a function, and does not collect callsite location info." - ([pdata id nano-secs-elapsed] (impl/capture-time! pdata id nano-secs-elapsed nil)) + ([pdata id nano-secs-elapsed] (pdata id nano-secs-elapsed nil)) ([ id nano-secs-elapsed] (when-let [pd (or impl/*pdata* (impl/pdata-local-get))] - (impl/capture-time! pd id nano-secs-elapsed nil)))) + (pd id nano-secs-elapsed nil)))) (comment @(second @@ -370,14 +378,14 @@ (capture-time! :foo (- t1 t0))))) (let [pd (new-pdata)] - (enc/qb 1e6 (capture-time! pd :foo 100)) - @@pd) + (enc/qb 1e6 (pd :foo 100 nil)) + @(pd)) (let [pd (new-pdata)] (with-profiling pd {} (p :foo (Thread/sleep 100)) (p :bar (Thread/sleep 200))) - @@pd)) + @(pd))) ;;;; Core macros @@ -631,7 +639,7 @@ ;; ~(println [id-form (:line loc)]) ; Debug location info ;; Note that `capture-time!` expense is excl. from p time - (impl/capture-time! ~'__pd ~id-form (- ~'__t1 ~'__t0) ~loc ) + (~'__pd ~id-form (- ~'__t1 ~'__t0) ~loc ) ~'__result) (do ~@body))))))) @@ -794,14 +802,15 @@ (defn- sacc-add! [pstats_ group-id ps] (when (and group-id ps) ;; Contention would be expensive, consumer should serialize: - (swap! pstats_ (fn [m] (assoc m group-id (impl/merge-pstats (get m group-id) ps)))) + (pstats_ group-id #(impl/merge-pstats % ps)) true)) -(deftype StatsAccumulator [pstats_] ; { } - #?@(:clj [clojure.lang.IFn (invoke [_ group-id ps] (sacc-add! pstats_ group-id ps))] - :cljs [ IFn (-invoke [_ group-id ps] (sacc-add! pstats_ group-id ps))]) +(deftype StatsAccumulator [pstats_] + ;; `pstats` - { } #?@(:clj [clojure.lang.IDeref (deref [_] (sacc-drain-and-merge! pstats_))] - :cljs [ IDeref (-deref [_] (sacc-drain-and-merge! pstats_))])) + :cljs [ IDeref (-deref [_] (sacc-drain-and-merge! pstats_))]) + #?@(:clj [clojure.lang.IFn (invoke [_] (sacc-drain-and-merge! pstats_)) (invoke [_ group-id ps] (sacc-add! pstats_ group-id ps))] + :cljs [ IFn (-invoke [_] (sacc-drain-and-merge! pstats_)) (-invoke [_ group-id ps] (sacc-add! pstats_ group-id ps))])) (defn stats-accumulator "Alpha, subject to change. @@ -814,9 +823,9 @@ Note that you may want some kind of async/buffer/serialization mechanism in front of merge calls for performance (e.g. by using an agent). - See also `add-accumulating-handler!`, example clj project." + See also `add-accumulating-handler!` example clj project." - [] (StatsAccumulator. (atom {}))) + [] (StatsAccumulator. (enc/latom {}))) (comment (enc/qb 1e6 (stats-accumulator)) ; 66.75 @@ -829,20 +838,18 @@ (defn add-accumulating-handler! "Alpha, subject to change. - Creates a new StatsAccumulator (and agent in clj), then - registers a handler to accumulate `profile` output to the - StatsAccumulator using the agent. + Creates a new StatsAccumulator and registeres a handler to + accumulate `profile` output to the StatsAccumulator. - Returns the StatsAccumulator. You can deref the result to - drain the accumulator and return { }. + Returns the StatsAccumulator. + Deref it to drain the accumulator and return { }. - One common pattern is to deref the accumulator every n - minutes/etc. to get a view of total-system performance over - the period, e.g.: + One common pattern is to deref the accumulator every n minutes/etc. + to get a view of total-system performance over the period, e.g.: (defonce my-sacc (add-accumulating-handler! {:ns-pattern \"*\"})) (defonce my-sacc-drainer - ;; Will drain and print formatted stats every minute + ;; Drain and print formatted stats every minute (future (while true (when-let [m (not-empty @my-sacc)] @@ -854,18 +861,20 @@ See also `format-grouped-pstats`, example clj project." - [{:keys [ns-pattern handler-id] + [{:keys [ns-pattern handler-id runner-opts] :or {ns-pattern "*" handler-id :accumulating}}] (let [sacc (stats-accumulator) - agent_ #?(:clj (delay (agent nil :error-mode :continue)) :cljs nil)] + ;; runner #?(:clj (runner/runner (conj {:daemon-threads? true} runner-opts)) :cljs nil) + runner (fn [f] (f)) + ] (add-handler! handler-id ns-pattern (fn [{:keys [?id ?data pstats]}] (let [id (or ?id :tufte/nil-id)] - #?(:clj (send @agent_ (fn [_] (sacc id pstats))) - :cljs (sacc id pstats))))) + #?(:clj (runner (fn [] (sacc id pstats))) + :cljs (sacc id pstats))))) sacc)) @@ -879,7 +888,7 @@ (defn format-grouped-pstats "Alpha, subject to change. - Takes a map of { } and formats a combined + Takes a map of { } and formats a combined output string using `format-pstats`. See also example clj project." @@ -993,11 +1002,3 @@ (format-pstats (second (profiled {} (p :foo (Thread/sleep 100))))))) - -(comment ; Disjoint time union - (let [[_ ps1] (profiled {} (p :foo (Thread/sleep 100))) - _ (Thread/sleep 500) - [_ ps2] (profiled {} (p :foo (Thread/sleep 100)))] - (println (format-pstats (merge-pstats ps2 ps1))) - ;;@(merge-pstats ps2 ps1) - )) diff --git a/src/taoensso/tufte/impl.cljc b/src/taoensso/tufte/impl.cljc index 72786a1..bbf0ec1 100644 --- a/src/taoensso/tufte/impl.cljc +++ b/src/taoensso/tufte/impl.cljc @@ -1,112 +1,171 @@ (ns ^:no-doc taoensso.tufte.impl "Private implementation details. - `profiled` -> [ ]. - - Profiling consists of: - 1. State init ; On thread - 2. Capture ; On thread - 3. State deref ; On thread - 4. ?Merging ; Off thread, on demand (deferred cost) - 5. ?Realization ; Off thread, on demand (deferred cost) - - Basic implementation: - - Capture [ ]s into single mutable acc - - May compact acc to id-times, { (