From baac41c82a914af6cca954ad3dbb1e35674ba46f Mon Sep 17 00:00:00 2001
From: Peter Taoussanis <peter@taoensso.com>
Date: Wed, 6 Sep 2023 12:30:31 +0200
Subject: [PATCH] [new] NB completely rewrite core

Refreshes the core implementation as I'd write it today.

Changes include:

  - Major code simplifications
  - Significant performance improvements
---
 project.clj                    |   2 +-
 src/taoensso/tufte.cljc        | 103 +++---
 src/taoensso/tufte/impl.cljc   | 577 ++++++++++++++++-----------------
 test/taoensso/tufte_tests.cljc | 180 +++++-----
 4 files changed, 433 insertions(+), 429 deletions(-)

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 <https://www.taoensso.com>"
   :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_] ; {<group-id> <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` - {<group-id> <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 {<group-id> <merged-pstats>}.
+  Returns the StatsAccumulator.
+  Deref it to drain the accumulator and return {<group-id> <merged-pstats>}.
 
-  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 {<group-id> <PStats>} and formats a combined
+  Takes a map of {<group-id> <pstats>} 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` -> [<result> <derefable-and-mergeable-pstats>].
-
-  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 [<id> <elapsed>]s into single mutable acc
-      - May compact acc      to id-times,  {<id> (<time>         ...)}
-      - May compact id-times to id-sstats, {<id> (<stats/sstats> ...)}
-    - Merge pours (read-only) acc0 + acc1 into id-times
-      - May compact id-times to id-sstats, {<id> (<stats/sstats> ...)}
-    - Realization:
-        - Generates {<id> <stats/sstats>} from id-times.
-        - Merges with id-sstats."
+  Ultimately returns `PStats` to be merged or derefed.
+
+  Flow:
+    1. Init pdata              ; On  thread
+    2. Capture times -> pdata  ; On  thread
+    3. Deref pdata -> pstats   ; On  thread
+    4. ?Merge pstats           ; Off thread, on demand (deferred cost)
+    5. ?Realize ?merged pstats ; Off thread, on demand (deferred cost)"
 
   (:require
    [clojure.string  :as str]
    [taoensso.encore :as enc :refer-macros []]
-   [taoensso.tufte.stats :as stats])
-
-  #?(:clj
-     (:import [java.util LinkedList Stack]
-              [java.util.concurrent ArrayBlockingQueue]))
+   [taoensso.encore.runner :as runner]
+   [taoensso.tufte.stats   :as stats])
 
   #?(:cljs
      (:require-macros
-      [taoensso.tufte.impl :refer [mt-acc mt-add mt-count atom?]])))
+      [taoensso.tufte.impl :refer [mt-acc mt-add! mt-count]])))
+
+(comment (remove-ns 'taoensso.tufte.impl))
+
+;;;; Basic types
 
-;;;; Mutable accumulators
+(do
+  (deftype Time     [id ^long runtime loc-info]) ; Runtime entry
+  (deftype TimeSpan [^long t0 ^long t1])         ; Accumulated during PStats merge
+  (deftype TimeAcc  [^long tsum ^long tmax])     ; Used during reductions, etc.
+  (deftype IdState  [id-times id-sstats]))       ; Used during reductions, etc.
 
-(deftype Time     [id ^long t location-info])
-(deftype TimeSpan [^long t0 ^long t1])
-(comment (enc/qb 1e6 (Time. :foo 1000 nil))) ; 33.59
+;;;; Mutable accumulators (for local-only profiling)
 
 #?(:clj
    (do
-     (defmacro ^:private mt-acc     [] `(enc/if-cljs (cljs.core/array) (LinkedList.)))
-     (defmacro ^:private mt-add [mt x] `(enc/if-cljs (.push   ~mt ~x) (.add  ~(with-meta mt {:tag 'LinkedList}) ~x)))
-     (defmacro ^:private mt-count [mt] `(enc/if-cljs (alength ~mt)    (.size ~(with-meta mt {:tag 'LinkedList}))))))
+     (defmacro ^:private mt-acc   [    ] (if (:ns &env) `(cljs.core/array)                             `(java.util.LinkedList.)))
+     (defmacro ^:private mt-add!  [mt x] (if (:ns &env) `(.push   ~mt ~x)  `(.add  ~(with-meta mt {:tag 'java.util.LinkedList}) ~x)))
+     (defmacro ^:private mt-count [mt  ] (if (:ns &env) `(alength ~mt)     `(.size ~(with-meta mt {:tag 'java.util.LinkedList}))))))
 
-(comment (enc/qb 1e6 (mt-acc) (atom nil))) ; [29.14 57.76]
+;;;; Main types
 
-;;;; PStats (Profiling Stats)
-;; API-level state we'll return from `profiled`: derefable, mergeable
+(deftype PStats ; Profiling Stats
+  [^long nmax ^long t0 ^long t1 acc id-times id-sstats tspans realized_]
+  ;; Public, mergeable, immutable version of PData.
+  ;; Deref to get {:keys [clock stats]} map.
+  ;; All fields but `realized_` to support merging.
 
-(deftype PStats [pd ^long t1 tspans realized_]
-  #?@(:clj  [clojure.lang.IDeref    (deref     [_]           @realized_)]
-      :cljs [             IDeref   (-deref     [_]           @realized_)])
-  #?@(:clj  [clojure.lang.IPending (isRealized [_] (realized? realized_))]
-      :cljs [             IPending (-realized? [_] (realized? realized_))]))
+  #?@(:clj  [clojure.lang.IDeref (deref  [this] @realized_)]
+      :cljs [             IDeref (-deref [this] @realized_)])
 
-;;;; PData (Profiling Data)
-;; Implementation-level state while profiling,
-;;   - id-times:  ?{<id> (<time>         ...)}
-;;   - id-sstats: ?{<id> (<stats/sstats> ...)}
+  #?@(:clj  [clojure.lang.IPending (isRealized [_] (realized? realized_))]
+      :cljs [             IPending (-realized? [_] (realized? realized_))])
+
+  Object (toString [_] (str "TuftePStats[" (if (realized? realized_) "ready" "pending") "]")))
+
+#?(:clj (enc/deftype-print-methods PStats))
+
+(declare
+  ^:private ^IdState compact-id-state
+  ^:private          deref-pstats)
+
+(deftype PData ; Profiling Data (private)
+  [dynamic? ^long nmax ^long t0
+   #?(:clj ^:volatile-mutable acc         :cljs ^:mutable acc)
+   #?(:clj ^:volatile-mutable id-times    :cljs ^:mutable id-times)
+   #?(:clj ^:volatile-mutable id-sstats   :cljs ^:mutable id-sstats)
+   #?(:clj ^:volatile-mutable compacting? :cljs ^:mutable compacting?)]
+
+  ;; `acc`       - mutable accumulator or (latom ())
+  ;; `id-times`  - ?{<id> [<Time>               ...]}
+  ;; `id-sstats` - ?{<id> [<stats/SummaryStats> ...]}
+
+  ;; Invoke [id nsecs loc] to capture Time
+  ;; Invoke [] to get immutable PStats
+
+  #?@(:clj  [clojure.lang.IDeref (deref  [this] (this))]
+      :cljs [             IDeref (-deref [this] (this))])
+
+  #?(:clj clojure.lang.IFn :cljs IFn)
+
+  ;; Captures time, compacting as necessary
+  (#?(:clj invoke :cljs -invoke) [this id nsecs-elapsed loc-info]
+    (when-let [acc-snap acc]
+      (let [new-time (Time. id ^long nsecs-elapsed loc-info)]
+        (enc/when-let
+          [need-compaction?
+           (if dynamic?
+             (> (count (acc-snap #(conj % new-time))) nmax)
+             (do (mt-add! acc-snap new-time) (> (mt-count acc-snap) nmax)))
+
+           pulled-times
+           (if-not dynamic?
+             acc-snap
+             (and
+               (not compacting?) ; Irrelevant for Cljs
+               (loop []
+                 (let [times (acc-snap)]
+                   (when (and (not compacting?) (> (count times) nmax))
+                     (if (enc/-cas!? acc-snap times nil) times (recur)))))))]
+
+          (set! compacting? true)
+          (let [t0        (enc/now-nano*)
+                compacted (compact-id-state nmax id-times id-sstats pulled-times)]
+            ;; Safe to `set!` here even when `dynamic?` since we're protected by
+            ;; CAS against `acc-snap`. Note that for performance reasons we tolerate
+            ;; a theoretical risk of losing times under high contention when `nmax`
+            ;; is ridiculously, unrealistically small.
+            (set! id-times  (.-id-times  compacted))
+            (set! id-sstats (.-id-sstats compacted))
+            (when-not dynamic? (set! acc (mt-acc)))
+            (this :tufte/compaction (- (enc/now-nano*) t0) nil)
+            (set! compacting? false))))
+      true))
+
+  ;; PData->PStats
+  (#?(:clj invoke :cljs -invoke)
+    [_]
+    (when-let [acc-snap acc]
+      (set! acc nil)
+      (let [t1     (enc/now-nano*)
+            tspans [(TimeSpan. t0 t1)]]
+        (PStats.               nmax t0 t1 acc-snap id-times id-sstats tspans
+          (delay (deref-pstats nmax t0 t1 acc-snap id-times id-sstats tspans)))))))
 
-(declare ^:private deref-pdata)
-(deftype PState [acc id-times id-sstats])
-(deftype  PData [^long nmax ^long t0 pstate_]
-  #?@(:clj  [clojure.lang.IDeref  (deref [this] (deref-pdata this))]
-      :cljs [             IDeref (-deref [this] (deref-pdata this))]))
+;;;;
 
-(defn new-pdata-local   [^long nmax] (let [t0 (enc/now-nano*)] (PData. nmax t0 (volatile! (PState. (mt-acc)   nil nil)))))
-(defn new-pdata-dynamic [^long nmax] (let [t0 (enc/now-nano*)] (PData. nmax t0 (atom      (PState. (atom nil) nil nil)))))
+(def ^:dynamic  *pdata* "nnil iff dynamic profiling active" nil)
+(defn ^PData new-pdata-local   [^long nmax] (let [t0 (enc/now-nano*)] (PData. false nmax t0 (mt-acc)        nil nil false)))
+(defn ^PData new-pdata-dynamic [^long nmax] (let [t0 (enc/now-nano*)] (PData. true  nmax t0 (enc/latom nil) nil nil false)))
 
-(comment (enc/qb 1e6 (new-pdata-local 10) (new-pdata-dynamic 10))) ; [98.18 138.28]
+(comment
+  (enc/qb 1e6 (new-pdata-local 10) (new-pdata-dynamic 10)) ; [78.4 102.78]
 
-(declare ^:private deref-pstats)
-(defn- deref-pdata "PData->PStats" [^PData pd]
-  ;; NB (.-acc pd) should never be mutated from this point!
-  (let [t1     (enc/now-nano*)
-        t0     (.-t0 pd)
-        tspans (list (TimeSpan. t0 t1))]
+  (let [pd (new-pdata-local   10)] (pd :pid1 100 nil) @(pd))
+  (let [pd (new-pdata-dynamic 10)] (pd :pid1 100 nil) @(pd))
 
-    (PStats. pd t1 tspans (delay (deref-pstats pd t1 tspans)))))
+  (let [pdl (new-pdata-local   5e6)
+        pdd (new-pdata-dynamic 5e6)]
 
-(comment (enc/qb 1e6 @(new-pdata-local 10))) ; 245.08
+    (enc/qb 1e6 ; [40.57 69.59]
+      (pdl :id 100 nil)
+      (pdd :id 100 nil))))
 
-(def ^:dynamic *pdata* "nnil iff dynamic profiling active" nil)
+;;;; Local PData utils
 
 #?(:clj
    (let [;; Stack to support `profile/d` nesting
-         ^ThreadLocal stack-proxy (proxy [ThreadLocal] [] (initialValue [] (Stack.)))
+         ^ThreadLocal stack-proxy (proxy [ThreadLocal] [] (initialValue [] (java.util.Stack.)))
          ^ThreadLocal pdata-proxy (proxy [ThreadLocal] [])]
 
-     (defn pdata-local-get [] (.get pdata-proxy)) ; => nnil iff thread-local profiling active
+     (defn pdata-local-get "nnil iff thread-local profiling active" [] (.get pdata-proxy))
      (defn pdata-local-pop []
-       (let [^Stack stack (.get stack-proxy)]
+       (let [^java.util.Stack stack (.get stack-proxy)]
          (if-let [stashed (when-not (.empty stack) (.pop stack))]
            (do (.set pdata-proxy stashed) stashed)
            (do (.set pdata-proxy nil)     nil))))
 
      (defn pdata-local-push [v]
-       (let [^Stack stack  (.get stack-proxy)]
+       (let [^java.util.Stack stack  (.get stack-proxy)]
          (if-let [to-stash (.get pdata-proxy)]
            (do (.push stack to-stash) (.set pdata-proxy v) v)
            (do                        (.set pdata-proxy v) v)))))
 
-   :cljs ; Note single-threaded platform
-   (let [stack #js [] ; To support `profile/d` nesting
-         pdata_ (volatile! false)]
+   :cljs ; Single-threaded
+   (let [pdata_ (volatile! nil)
+         stack #js []]
 
-     (defn pdata-local-get [] @pdata_) ; => nnil iff thread-local profiling active
+     (defn pdata-local-get "nnil iff thread-local profiling active" [] @pdata_)
      (defn pdata-local-pop []
        (if-let [stashed (.pop stack)]
          (vreset! pdata_ stashed)
@@ -120,8 +179,8 @@
 (comment
   (pdata-local-push "foo")
   (pdata-local-pop)
-  (enc/qb 1e6 *pdata* (pdata-local-get)) ; [63.7 48.77]
-  (enc/qb 1e6  ; [507.58 74.62]
+  (enc/qb 1e6 *pdata* (pdata-local-get)) ; [22.42 42.55]
+  (enc/qb 1e6  ; [337.03 97.05]
     (binding [*pdata* "foo"])
     (try (pdata-local-push "foo") (finally (pdata-local-pop))))
 
@@ -129,62 +188,15 @@
     (pdata-local-push "pd1")
     (pdata-local-push "pd2")
     [(let [pd (pdata-local-get)] (pdata-local-pop) pd)
-     (let [pd (pdata-local-get)] (pdata-local-pop) pd)]))
+     (let [pd (pdata-local-get)] (pdata-local-pop) pd)])
 
-;;;; TimeSpan utils
+  (enc/qb 1e3 ; 14.99
+    (try
+      (pdata-local-push (new-pdata-local 1e7))
+      (dotimes [_ 1e3] ((pdata-local-get) :foo 1 nil))
+      (finally (pdata-local-pop)))))
 
-(deftype ElapsedTimeAcc [^long tsum ^long max-t1])
-(let [sort-tspans (fn [tspans] (sort-by (fn [^TimeSpan tspan] (.-t0 tspan)) tspans))]
-  (defn- tspans->tsum
-    "Returns `tsum` (elapsed time) given collection of `TimeSpan`s.
-    Based on https://codereview.stackexchange.com/a/126927."
-    ^long [tspans]
-    (if (empty? tspans)
-      0
-      (let [sorted-tspans (sort-tspans tspans)] ; O(n.logn)
-        (.-tsum ^ElapsedTimeAcc
-          (reduce
-            (fn [^ElapsedTimeAcc acc ^TimeSpan tspan]
-              (let [t1     (.-t1     tspan)
-                    max-t1 (.-max-t1 acc)]
-                (if (> t1 max-t1)
-                  (let [t0   (.-t0   tspan)
-                        tsum (.-tsum acc)]
-                    (ElapsedTimeAcc. (+ tsum (- t1 (Math/max t0 max-t1))) t1))
-                  acc)))
-            (ElapsedTimeAcc. 0 0)
-            sorted-tspans))))))
-
-(comment
-  (tspans->tsum nil)
-  (tspans->tsum [])
-  (tspans->tsum [(TimeSpan. 1   3) (TimeSpan. 3 6)])
-  (tspans->tsum [(TimeSpan. 3   6) (TimeSpan. 1 3)])
-  (tspans->tsum [(TimeSpan. 1  10) (TimeSpan. 3 6)])
-  (enc/qb 1e6
-    (tspans->tsum
-      [(TimeSpan. 10 14)
-       (TimeSpan.  4 18)
-       (TimeSpan. 19 20)
-       (TimeSpan. 19 20)
-       (TimeSpan. 13 20)])))
-
-(defn- fast-into [c0 c1] (if (> (count c0) (count c1)) (into c0 c1) (into c1 c0)))
-(comment (fast-into nil nil))
-
-(defn- merge-tspans [^long nmax ^long t1 tspans0 tspans1]
-  (let [tspans2 (fast-into tspans0 tspans1)]
-    (if (> (count tspans2) nmax) ; Compact, may lose some accuracy
-      (let [tsum (tspans->tsum tspans2)]
-        (list (TimeSpan. (- t1 tsum) t1)))
-      tspans2)))
-
-(comment
-  (merge-tspans 2 50
-    (list (TimeSpan. 1 10) (TimeSpan. 5  20))
-    (list (TimeSpan. 1 10) (TimeSpan. 20 50))))
-
-;;;;
+;;;; Compaction, etc.
 
 (defn- times-into-id-times
   "NB treats `from-times` as read-only (may be mutable `acc`)!"
@@ -194,15 +206,15 @@
       (persistent!
         (reduce
           (fn [m ^Time in]
-            (let [t   (.-t             in)
-                  id  (.-id            in)
-                  loc (.-location-info in)
+            (let [rt  (.-runtime  in)
+                  id  (.-id       in)
+                  loc (.-loc-info in)
                   id* [id loc]]
 
               ;; We'll use [id loc] as a pseudo id from here on in
               ;; order to track location info. We'll then reverse
               ;; the wrapping on final `deref-pstats`.
-              (assoc! m id* (conj (get m id*) t))))
+              (assoc! m id* (conj (get m id*) rt))))
 
           (transient (or to-id-times {}))
           from-times))
@@ -213,23 +225,88 @@
   (times-into-id-times nil nil)
   (times-into-id-times {}  nil)
   (let [mt (mt-acc)]
-    (mt-add mt (Time. :foo 2 nil))
+    (mt-add! mt (Time. :foo 2 nil))
     (times-into-id-times {:foo '(1)} mt)))
 
+(defn- merge-sstats-when-needed [^long nmax sstats]
+  (if (<= (count sstats) nmax)
+    (do                                     sstats)
+    (list (reduce stats/summary-stats-merge sstats))))
+
+(defn- ^IdState compact-id-state
+  ;; Note that compaction cost doesn't distort p times unless there's
+  ;; p nesting (where outer p time includes inner p's capture time).
+  [nmax id-times id-sstats pulled-times]
+  (let [id-times (times-into-id-times id-times pulled-times)]
+    (reduce-kv
+      (fn [^IdState acc id times]
+        (if (<= (count times) ^long nmax)
+          acc
+          (let [id-times     (.-id-times  acc)
+                id-sstats    (.-id-sstats acc)
+                sstats<times (stats/summary-stats times)]
+
+            (IdState.
+              (assoc id-times  id nil)
+              (assoc id-sstats id
+                (merge-sstats-when-needed nmax
+                  (conj (get id-sstats id) sstats<times)))))))
+
+      (IdState. id-times id-sstats)
+      (do       id-times))))
+
+(defn- fast-into [c0 c1] (if (> (count c0) (count c1)) (into c0 c1) (into c1 c0)))
+(comment (fast-into nil nil))
+
+(let [tspans->tacc
+      (fn [tspans]
+        ;; Ref. <https://codereview.stackexchange.com/a/126927>
+        (let [sorted-tspans (sort-by (fn [^TimeSpan tspan] (.-t0 tspan)) tspans)] ; O(n.logn)
+          (reduce ; O(n)
+            (fn [^TimeAcc acc ^TimeSpan tspan]
+              (let [t1   (.-t1   tspan)
+                    tmax (.-tmax acc)]
+                (if (> t1 tmax)
+                  (let [t0   (.-t0   tspan)
+                        tsum (.-tsum acc)]
+                    (TimeAcc. (+ tsum (- t1 (Math/max t0 tmax))) t1))
+                  acc)))
+            (TimeAcc. 0 0)
+            sorted-tspans)))]
+
+  (defn- tspans->tsum
+    "Used for calculating total clock time when merging `PStats`."
+    ^long [tspans]
+    (if (= (count tspans) 1) ; Common case
+      (let [[^TimeSpan tspan1] tspans] (- (.-t1 tspan1) (.-t0 tspan1)))
+      (.-tsum ^TimeAcc (tspans->tacc tspans))))
+
+  (defn- merge-tspans [^long nmax tspans0 tspans1]
+    (let [tspans2 (fast-into tspans0 tspans1)]
+      (if (<= (count tspans2) nmax)
+        tspans2
+        ;; Compact (loses overlap info for future merges!)
+        (let [^TimeAcc tacc (tspans->tacc tspans2)
+              tsum (.-tsum tacc)
+              tmax (.-tmax tacc)]
+          [(TimeSpan. (- tmax tsum) tmax)])))))
+
+(comment
+  ;; [15 20 20]
+  [(tspans->tsum (merge-tspans 1e3 [(TimeSpan. 0 10)] [(TimeSpan. 15 20)]))
+   (tspans->tsum (merge-tspans 1e3 [(TimeSpan. 0 20)] [(TimeSpan. 10 15)]))
+   (tspans->tsum (merge-tspans 1e3 [(TimeSpan. 0 10)] [(TimeSpan.  5 20)]))])
+
+;;;; PStats realization
+
 (defn- deref-pstats
-  "PStats->{:clock _ :stats {<id> <stats/sstats-map>}} (API output)"
-  [^PData pd ^long t1 tspans]
-  (let [t0      (.-t0      pd)
-        pstate_ (.-pstate_ pd)
-        ^PState pstate (enc/force-ref pstate_)
-        id-times  (.-id-times  pstate)
-        id-sstats (.-id-sstats pstate)
-        id-times  (times-into-id-times id-times (.-acc pstate))
-
-        public-stats-output ; {<id*> <stats/sstats-map>}
+  "Returns {:clock _ :stats {<id> <stats/sstats-map>}}."
+  [nmax t0 t1 acc id-times id-sstats tspans]
+  (let [id-times (times-into-id-times id-times acc)
+        public-stats-map ; {<id*> <stats/sstats-map>}
         (when id-times
           (let [;;; Disposable internal state
-                id*-sstats_ (volatile! (transient {})) ; {<id*>  <sstats>}
+                id*-sstats_ (volatile! (transient {})) ; {<id*> <sstats>}
                 id*-loc_    (volatile! (transient {})) ; {<id*> <map-or-set>}
                 ]
 
@@ -270,181 +347,99 @@
                 id-times))))]
 
     {:clock {:t0 t0 :t1 t1 :total (tspans->tsum tspans)}
-     :stats public-stats-output}))
+     :stats public-stats-map}))
 
-(comment @@(new-pdata-local 10))
-
-(defn- merge-sstats-when-needed [^long nmax sstats]
-  (if (<= (count sstats) nmax)
-    (do                                     sstats)
-    (list (reduce stats/summary-stats-merge sstats))))
+;;;; PStats merging
 
-(defn merge-pstats "Compacting merge"
+(defn merge-pstats
+  "Merges given `PStats`, compacting as necessary."
   ([     ps0 ps1] (merge-pstats nil ps0 ps1))
   ([nmax ps0 ps1]
    (if ps0
      (if ps1
-       (let [^PStats ps0       ps0
-             ^PStats ps1       ps1
-             ^PData  pd0 (.-pd ps0)
-             ^PData  pd1 (.-pd ps1)
+       (let [^PStats ps0 ps0
+             ^PStats ps1 ps1
 
-             nmax (long (or nmax (.-nmax pd0)))
-             pd0-t0 (.-t0 pd0)
+             nmax   (long (or nmax (.-nmax ps0) (.-nmax ps1)))
+             ps0-t0 (.-t0 ps0)
              ps0-t1 (.-t1 ps0)
-             pd1-t0 (.-t0 pd1)
+             ps1-t0 (.-t0 ps1)
              ps1-t1 (.-t1 ps1)
 
-             pd2-t0  (if (< pd0-t0 pd1-t0) pd0-t0 pd1-t0)
-             ps2-t1  (if (> ps0-t1 ps1-t1) ps0-t1 ps1-t1)
-             tspans2 (merge-tspans nmax ps2-t1 (.-tspans ps0) (.-tspans ps1))
+             ps2-t0  (Math/min ps0-t0 ps1-t0)
+             ps2-t1  (Math/max ps0-t1 ps1-t1)
+             tspans2 (merge-tspans nmax (.-tspans ps0) (.-tspans ps1))
 
-             ^PState pd0-pstate (enc/force-ref (.-pstate_ pd0))
-             ^PState pd1-pstate (enc/force-ref (.-pstate_ pd1))
+             ps0-id-times  (times-into-id-times (.-id-times  ps0) (.-acc ps0))
+             ps1-id-times  (times-into-id-times (.-id-times  ps1) (.-acc ps1))
+             ps0-id-sstats                      (.-id-sstats ps0)
+             ps1-id-sstats                      (.-id-sstats ps1)
 
-             pd0-id-times  (times-into-id-times (.-id-times pd0-pstate) (.-acc pd0-pstate))
-             pd1-id-times  (times-into-id-times (.-id-times pd1-pstate) (.-acc pd1-pstate))
-             pd0-id-sstats (.-id-sstats pd0-pstate)
-             pd1-id-sstats (.-id-sstats pd1-pstate)
+             ;; All ids in ps0 or ps1
+             ps2-ids (keys (conj (or ps0-id-times {}) ps1-id-times))
 
-             ;; All ids in pd0 or pd1
-             pd2-ids (keys (conj (or pd0-id-times {}) pd1-id-times))
-
-             ;; Merge pd1 into pd0 to get pd2
-             [pd2-id-times pd2-id-sstats]
+             ;; ps2 = ps0 <- ps1
+             ^IdState ps2-id-state
              (reduce
-               (fn [[pd2-id-times pd2-id-sstats] id]
-                 (let [pd0-times  (get pd0-id-times  id)
-                       pd0-sstats (get pd0-id-sstats id)
-                       pd1-times  (get pd1-id-times  id)
-                       pd1-sstats (get pd1-id-sstats id)
+               (fn [^IdState acc id]
+                 (let [ps2-id-times  (.-id-times  acc)
+                       ps2-id-sstats (.-id-sstats acc)
+
+                       ps0-times  (get ps0-id-times  id)
+                       ps0-sstats (get ps0-id-sstats id)
+                       ps1-times  (get ps1-id-times  id)
+                       ps1-sstats (get ps1-id-sstats id)
 
-                       pd2-times  (fast-into pd0-times  pd1-times)
-                       pd2-sstats (fast-into pd0-sstats pd1-sstats)]
+                       ps2-times  (fast-into ps0-times  ps1-times)
+                       ps2-sstats (fast-into ps0-sstats ps1-sstats)]
 
-                   (if (<= (count pd2-times) nmax) ; Common case
-                     [(assoc pd2-id-times  id pd2-times)
-                      (assoc pd2-id-sstats id pd2-sstats)]
+                   (if (<= (count ps2-times) nmax) ; Common case
+                     (IdState.
+                       (assoc ps2-id-times  id ps2-times)
+                       (assoc ps2-id-sstats id ps2-sstats))
 
                      ;; Times need compaction
-                     (let [sstats<times (stats/summary-stats pd2-times)]
-                       [(assoc pd2-id-times  id nil)
-                        (assoc pd2-id-sstats id
-                          (merge-sstats-when-needed nmax
-                            (conj pd2-sstats sstats<times)))]))))
+                     (let [sstats<times (stats/summary-stats ps2-times)]
+                       (IdState.
+                         (assoc ps2-id-times  id nil)
+                         (assoc ps2-id-sstats id
+                           (merge-sstats-when-needed nmax
+                             (conj ps2-sstats sstats<times))))))))
 
-               [pd0-id-times pd0-id-sstats]
-               pd2-ids)
+               (IdState. ps0-id-times ps0-id-sstats)
+               ps2-ids)
 
-             pd2 (PData. nmax pd2-t0 (PState. nil pd2-id-times pd2-id-sstats))]
-         (PStats. pd2 ps2-t1 tspans2 (delay (deref-pstats pd2 ps2-t1 tspans2))))
+             ps2-id-times  (.-id-times  ps2-id-state)
+             ps2-id-sstats (.-id-sstats ps2-id-state)]
 
+         (PStats.               nmax ps2-t0 ps2-t1 nil ps2-id-times ps2-id-sstats tspans2
+           (delay (deref-pstats nmax ps2-t0 ps2-t1 nil ps2-id-times ps2-id-sstats tspans2))))
        ps0)
      ps1)))
 
-;;;; Time capture
-
-#?(:clj
-   (defmacro ^:private atom? [x]
-     `(enc/if-cljs
-        (instance?    cljs.core.Atom ~x)
-        (instance? clojure.lang.Atom ~x))))
-
-(declare ^:private compact-pstate)
-(defn capture-time! [^PData pd id ns-elapsed location-info]
-  (let [nmax    (.-nmax    pd)
-        pstate_ (.-pstate_ pd)
-        ^PState pstate @pstate_
-        acc (.-acc pstate)]
-
-    (if (atom? acc)
-
-      ;; Dynamic profiling
-      (let [new-time (Time. id ns-elapsed location-info)
-            ?pulled-times
-            (loop []
-              (let [old-times @acc
-                    new-times (conj old-times new-time)]
-                (if (<= (count new-times) nmax)
-                  (if (compare-and-set! acc old-times new-times) nil (recur))
-                  (if (compare-and-set! acc old-times nil) new-times (recur)))))]
-
-        (when-let [times ?pulled-times] ; Do compaction, rare
-          (let [t0 (enc/now-nano*)]
-            ;; Contention against `pstate_` unlikely since we just drained `acc`
-            (swap! pstate_ (fn [pstate] (compact-pstate pstate times nmax true)))
-            (recur pd :tufte/compaction (- (enc/now-nano*) t0) nil))))
-
-      (do ; Common case: thread-local profiling
-        (mt-add acc (Time. id ns-elapsed location-info))
-
-        (when (> (mt-count acc) nmax) ; Do compaction, rare
-          (let [t0 (enc/now-nano*)]
-            (vreset! pstate_ (compact-pstate pstate acc nmax false))
-            (recur pd :tufte/compaction (- (enc/now-nano*) t0) nil)))))))
-
-(defn- compact-pstate [^PState pstate pulled-times ^long nmax dynamic?]
-  ;; Note that compaction expense doesn't distort p times unless there's
-  ;; p nesting (where outer p time includes inner p's capture time).
-  (let [id-times  (.-id-times  pstate)
-        id-sstats (.-id-sstats pstate)
-        id-times  (times-into-id-times id-times pulled-times)
-
-        [id-times id-sstats]
-        (reduce-kv
-          (fn [acc id times]
-            (if (<= (count times) nmax)
-              acc
-              (let [[id-times id-sstats] acc
-                    sstats<times (stats/summary-stats times)]
-                [(assoc id-times  id nil)
-                 (assoc id-sstats id
-                   (merge-sstats-when-needed nmax
-                     (conj (get id-sstats id) sstats<times)))])))
+;;;; `profile` handlers
 
-          [id-times id-sstats]
-          id-times)
+(enc/defonce handlers_ "{<handler-id> <handler-fn>}" (atom nil))
+(defn- handle-blocking! [m] (enc/run-kv! (fn [handler-id handler-fn] (handler-fn m)) @handlers_))
 
-        new-acc (if dynamic? (.-acc pstate) (mt-acc))]
-
-    (PState. new-acc id-times id-sstats)))
-
-(comment
-  (try
-    (pdata-local-push (new-pdata-local 1e7))
-    (enc/qb 1e6 (capture-time! (pdata-local-get) :foo 1 nil))
-    (finally (pdata-local-pop)))) ; 98.35
-
-;;;; Output handlers
-
-(enc/defonce handlers_ "{<hid> <handler-fn>}" (atom nil))
-
-#?(:clj
-   (enc/defonce ^:private ^ArrayBlockingQueue handler-queue
-     "While user handlers should ideally be non-blocking, we'll use a queue
-     here to be safe + make sure we never tie up the execution thread."
-     (ArrayBlockingQueue. 1024)))
-
-(defn- handle-blocking! [m]
-  (enc/run-kv!
-    (fn [id f]
-      (enc/catching (f m) e
-        (enc/catching ; Esp. nb for Cljs
-          (println (str "WARNING: Uncaught Tufte `" id "` handler error\n" e)))))
-    @handlers_))
-
-#?(:clj  (declare ^:private handler-thread_))
-#?(:cljs (defn handle! [m] (handle-blocking! m) nil))
-#?(:clj  (defn handle! [m] (.offer handler-queue m) @handler-thread_ nil))
 #?(:clj
-   (defonce ^:private handler-thread_
-     (delay
-       (let [f (fn []
-                 (loop []
-                   (let [m (.take handler-queue)]
-                     ;; Note: just drop if no registered handlers
-                     (handle-blocking! m)
-                     (recur))))]
-         (doto (Thread. f)
-           (.setDaemon true)
-           (.start))))))
+   (let [default-opts {:mode :dropping, :buffer-size 1024, :n-threads 1, :daemon-threads? true}
+         sys-config   (enc/get-config {:as :edn :prop :taoensso.tufte.handler/runner-opts})
+         opts         (enc/nested-merge default-opts (get sys-config :config))]
+
+     (enc/defonce          handler-runner (runner/runner opts))
+     (enc/defonce ^:public handler-runner-opts
+       "Debug info for compile-time options used by Tufte's `profile` handler runner.
+       See `taoensso.encore/runner` ns for more info.
+
+       (Advanced) Override with one of the following (as edn):
+         `taoensso.tufte.handler.runner-opts` JVM         property value
+         `TAOENSSO_TUFTE_HANDLER_RUNNER_OPTS` environment variable value
+         `taoensso.tufte.handler.runner-opts` classpath   resource content"
+
+       {:added "vX.Y.Z (YYYY-MM-DD)"}
+       {:value opts, :default default-opts, :sys-config sys-config})))
+
+(defn handle! [m]
+  #?(:clj  (handler-runner (fn [] (handle-blocking! m)))
+     :cljs (do      (enc/catching (handle-blocking! m)) nil)))
diff --git a/test/taoensso/tufte_tests.cljc b/test/taoensso/tufte_tests.cljc
index ac4ce74..3850f5a 100644
--- a/test/taoensso/tufte_tests.cljc
+++ b/test/taoensso/tufte_tests.cljc
@@ -6,10 +6,9 @@
    [taoensso.tufte  :as tufte :refer [profiled profile p]]
 
    #?(:clj  [taoensso.tufte.impl  :as impl]
-      :cljs [taoensso.tufte.impl  :as impl :refer
-             [PState PData PStats TimeSpan]]))
+      :cljs [taoensso.tufte.impl  :as impl :refer [PStats PData TimeSpan]]))
 
-  #?(:clj  (:import [taoensso.tufte.impl PState PData PStats TimeSpan]))
+  #?(:clj  (:import [taoensso.tufte.impl PStats PData TimeSpan]))
   #?(:cljs (:require-macros
             [taoensso.tufte-tests
              :refer [looped nested-profiled]])))
@@ -68,8 +67,7 @@
 
        [(is (= r "foo"))
         (is (ps? ps))
-        (is (= (get-in @ps [:stats :foo :n]) 110))
-        (is (= (get-in @ps [:stats :bar :n]) 50))])
+        (is (enc/submap? @ps {:stats {:foo {:n 110} :bar {:n 50}}}))])
 
      (let [[r ps]
            (profiled {:dynamic? true}
@@ -79,8 +77,7 @@
 
        [(is (= r "foo"))
         (is (ps? ps))
-        (is (= (get-in @ps [:stats :foo :n]) 110))
-        (is (= (get-in @ps [:stats :bar :n]) 50))])
+        (is (enc/submap? @ps {:stats {:foo {:n 110} :bar {:n 50}}}))])
 
      (let [[r ps] (profiled {} (p :foo) (p ::foo) (p 'foo) (p `foo))]
        [(is (enc/submap? @ps {:stats {:foo {} ::foo {} 'foo {} `foo {}}})
@@ -100,8 +97,7 @@
 
        [(is (= r "foo"))
         (is (ps? ps))
-        (is (= (get-in @ps [:stats :foo :n]) 110))
-        (is (= (get-in @ps [:stats :bar :n]) 125))])
+        (is (enc/submap? @ps {:stats {:foo {:n 110} :bar {:n 125}}}))])
 
      (let [[r ps]
            (profiled {:dynamic? true}
@@ -111,8 +107,7 @@
 
        [(is (= r "foo"))
         (is (ps? ps))
-        (is (= (get-in @ps [:stats :foo :n]) 110))
-        (is (= (get-in @ps [:stats :bar :n]) 125))])]))
+        (is (enc/submap? @ps {:stats {:foo {:n 110} :bar {:n 125}}}))])]))
 
 #?(:clj
    (deftest capture-threaded
@@ -127,8 +122,7 @@
 
           [(is (= r "foo"))
            (is (ps? ps))
-           (is (= (get-in @ps [:stats :foo :n]) 1))
-           (is (= (get-in @ps [:stats :bar :n]) nil))])
+           (is (enc/submap? @ps {:stats {:foo {:n 1} :bar :submap/nx}}))])
 
         (let [[r ps]
               (profiled {:dynamic? true}
@@ -139,8 +133,7 @@
 
           [(is (= r "foo"))
            (is (ps? ps))
-           (is (= (get-in @ps [:stats :foo :n]) 2))
-           (is (= (get-in @ps [:stats :bar :n]) 1))])])))
+           (is (enc/submap? @ps {:stats {:foo {:n 2} :bar {:n 1}}}))])])))
 
 (deftest merging-basics
   [(testing "Merging/basics"
@@ -151,9 +144,7 @@
             [_ ps2] (profiled {:dynamic? true} (looped  30 (p :baz)))
             ps3 (reduce tufte/merge-pstats [nil ps0 nil nil ps1 ps2 nil])]
         [(is (ps? ps3))
-         (is (= (get-in @ps3 [:stats :foo :n]) 120))
-         (is (= (get-in @ps3 [:stats :bar :n]) 100))
-         (is (= (get-in @ps3 [:stats :baz :n])  30))])
+         (is (enc/submap? @ps3 {:stats {:foo {:n 120} :bar {:n 100} :baz {:n 30}}}))])
 
       ;; Invert dynamic/non-dynamic
       (let [[_ ps0] (profiled {}               (looped 100 (p :foo) (p :bar)))
@@ -161,9 +152,7 @@
             [_ ps2] (profiled {}               (looped  30 (p :baz)))
             ps3 (reduce tufte/merge-pstats [nil ps0 nil nil ps1 ps2 nil])]
         [(is (ps? ps3))
-         (is (= (get-in @ps3 [:stats :foo :n]) 120))
-         (is (= (get-in @ps3 [:stats :bar :n]) 100))
-         (is (= (get-in @ps3 [:stats :baz :n])  30))])])
+         (is (enc/submap? @ps3 {:stats {:foo {:n 120} :bar {:n 100} :baz {:n 30}}}))])])
 
    #?(:clj
       (testing "ps1 starting before ps0 should sum clock total correctly, Ref. #48"
@@ -183,11 +172,14 @@
 
        [(is (= r "qux"))
         (is (ps? ps))
-        (is (= (get-in @ps [:stats :foo :n]) 150))
-        (is (= (get-in @ps [:stats :bar :n])  50))
-        (is (= (get-in @ps [:stats :baz :n])  50))
-        (is (= (get-in @ps [:stats :tufte/compaction :n]) (/ 250 10)))
-        (is (= (count (.-acc ^PState @(.-pstate_ ^PData (.-pd ^PStats ps)))) 2))])
+        (is (enc/submap? @ps
+              {:stats
+               {:foo              {:n 150}
+                :bar              {:n  50}
+                :baz              {:n  50}
+                :tufte/compaction {:n (/ 250 10)}}}))
+
+        (is (= (count (.-acc ^PStats ps)) 2))])
 
      (let [[r ps]
            (profiled {:nmax 10 :dynamic? true}
@@ -197,11 +189,15 @@
 
        [(is (= r "qux"))
         (is (ps? ps))
-        (is (= (get-in @ps [:stats :foo :n]) 150))
-        (is (= (get-in @ps [:stats :bar :n])  50))
-        (is (= (get-in @ps [:stats :baz :n])  50))
-        (is (= (get-in @ps [:stats :tufte/compaction :n]) (/ 250 10)))
-        (is (= (count @(.-acc ^PState @(.-pstate_ ^PData (.-pd ^PStats ps)))) 2))])]))
+
+        (is (enc/submap? @ps
+              {:stats
+               {:foo              {:n 150}
+                :bar              {:n  50}
+                :baz              {:n  50}
+                :tufte/compaction {:n (/ 250 10)}}}))
+
+        (is (= (count @(.-acc ^PStats ps)) 2))])]))
 
 (deftest compaction-merge
   (testing "Compaction/merge"
@@ -216,10 +212,12 @@
         (is (= (get-in @ps1 [:stats :tufte/compaction :n]) nil))
         (is (= (get-in @ps2 [:stats :tufte/compaction :n]) 1))
 
-        (is (= (get-in @ps3 [:stats :foo :n]) 170))
-        (is (= (get-in @ps3 [:stats :bar :n])  60))
-        (is (= (get-in @ps3 [:stats :tufte/compaction :n]) 20)) ; Merging does uncounted compaction
-        ])
+        (is (= (enc/submap? @ps3
+                 {:stats
+                  {:foo              {:n 170}
+                   :bar              {:n  60}
+                   :tufte/compaction {:n  20}}}))
+          "Merging does uncounted compaction")])
 
      ;; Invert dynamic/non-dynamic
      (let [[_ ps0] (profiled {:nmax 10}       (looped 100 (p :foo)) (looped 50 (p :foo (p :bar))))
@@ -231,22 +229,25 @@
         (is (= (get-in @ps1 [:stats :tufte/compaction :n]) nil))
         (is (= (get-in @ps2 [:stats :tufte/compaction :n]) 1))
 
-        (is (= (get-in @ps3 [:stats :foo :n]) 170))
-        (is (= (get-in @ps3 [:stats :bar :n])  60))
-        (is (= (get-in @ps3 [:stats :tufte/compaction :n]) 20)) ; Merging does uncounted compaction
-        ])
+        (is (enc/submap? @ps3
+              {:stats
+               {:foo              {:n 170}
+                :bar              {:n  60}
+                :tufte/compaction {:n  20}}})
+          "Merging does uncounted compaction")])
 
      ;; [#54] merging PStats with times still (only) in accumulator
-     (let [[_ ps0] (profiled {:nmax 10} (p :foo))
+     (let [[_ ^PStats ps0] (profiled {:nmax 10} (p :foo))
            ps (enc/reduce-n (fn [ps _] (tufte/merge-pstats ps ps0)) nil 1000)]
 
-       [(is (<= (count (:foo (.-id-times  ^PState (.-pstate_ ^PData (.-pd ^PStats ps))))) 10))
-        (is (<= (count (:foo (.-id-sstats ^PState (.-pstate_ ^PData (.-pd ^PStats ps))))) 10))])]))
+       [(is (<= (count (:foo (.-id-times  ps0))) 10))
+        (is (<= (count (:foo (.-id-sstats ps0))) 10))])]))
 
 (defn- pstats-tspan [t0 t1]
-  (let [pd (PData. 8e5 t0 (PState. nil nil nil))
-        time-span [(TimeSpan. t0 t1)]]
-    (PStats. pd t1 time-span (delay (#'impl/deref-pstats pd t1 time-span)))))
+  (let [pd (PData. false 8e5 t0 nil nil nil false)
+        tspans [(TimeSpan. t0 t1)]]
+    (PStats. 8e5 t0 t1 nil nil nil tspans
+      (delay (#'impl/deref-pstats 8e5 t0 t1 nil nil nil tspans)))))
 
 (deftest merge-time-spans
   [(testing "Merge discrete time-spans"
@@ -299,8 +300,7 @@
 
        [(is (= r "foo"))
         (is (ps? ps))
-        (is (:clock @ps))
-        (is (nil? (:stats @ps)))])
+        (is (enc/submap? @ps {:clock :submap/ex :stats nil}))])
 
      (let [th (add-test-handler!)
            r  (profile {:dynamic? true} "foo")
@@ -309,8 +309,7 @@
 
        [(is (= r "foo"))
         (is (ps? ps))
-        (is (:clock @ps))
-        (is (nil? (:stats @ps)))])
+        (is (enc/submap? @ps {:clock :submap/ex :stats nil}))])
 
      #?(:clj
         (let [th (add-test-handler!)
@@ -320,9 +319,10 @@
 
           [(is (= r "bar"))
            (is (ps? ps))
-           (is (:clock @ps))
-           (is (= (get-in @ps [:stats :foo :n]) nil))
-           (is (= (get-in @ps [:stats :bar :n]) 1))
+           (is (enc/submap? @ps
+                 {:clock       :submap/ex
+                  :stats {:foo :submap/nx
+                          :bar {:n 1}}}))
            (is (string? @(:pstats-str_ m)))]))
 
      #?(:clj
@@ -333,9 +333,10 @@
 
           [(is (= r "bar"))
            (is (ps? ps))
-           (is (:clock @ps))
-           (is (= (get-in @ps [:stats :foo :n]) 1))
-           (is (= (get-in @ps [:stats :bar :n]) 1))
+           (is (enc/submap? @ps
+                 {:clock :submap/ex
+                  :stats {:foo {:n 1}
+                          :bar {:n 1}}}))
            (is (string? @(:pstats-str_ m)))]))
 
      (tufte/remove-handler! :testing)]))
@@ -385,24 +386,24 @@
 
     [;; Capture in `profiled`
      (let [[_ ps] (profiled {} (tufte/capture-time! :foo 100))]
-       (is (= (get-in @ps [:stats :foo :n]) 1)))
+       (is (enc/submap? @ps {:stats {:foo {:n 1}}})))
 
      ;; Capture to local pdata
      (let [n  (long 2e6)
            pd (tufte/new-pdata)
            _  (looped n (tufte/capture-time! pd :foo 100))]
-       (is (= (get-in @@pd [:stats :foo :n]) n)))
+       (is (enc/submap? @@pd {:stats {:foo {:n n}}})))
 
      #?(:clj
         [;; Capture to dynamic pdata from separate threads
          (let [n  (long 100)
-               pd (tufte/new-pdata {:dynamic? true :nmax 88})
+               pd (tufte/new-pdata {:dynamic? true :nmax 20})
                f1 (future (looped n (tufte/capture-time! pd :foo 100)))
                f2 (future (looped n (tufte/capture-time! pd :foo 100)))
                f3 (future (looped n (tufte/capture-time! pd :foo 100)))
                f4 (future (looped n (tufte/capture-time! pd :foo 100)))]
 
-           (do @f1 @f2 @f3 @f4)
+           [@f1 @f2 @f3 @f4] ; Block for futures to complete
            (is (= (get-in @@pd [:stats :foo :n]) (* 4 n))))
 
          ;; local `p`s against local pdata
@@ -412,9 +413,11 @@
                     (p :bar (Thread/sleep 200))
                     (tufte/capture-time! :baz 100))]
 
-           [(is (= (get-in @@pd [:stats :foo :n]) 1))
-            (is (= (get-in @@pd [:stats :bar :n]) 1))
-            (is (= (get-in @@pd [:stats :baz :n]) 1))])
+           [(is (enc/submap? @@pd
+                  {:stats
+                   {:foo {:n 1}
+                    :bar {:n 1}
+                    :baz {:n 1}}}))])
 
          ;; local `p`s against dynamic pdata
          (let [pd (tufte/new-pdata         {:dynamic? true})
@@ -423,9 +426,11 @@
                     (p :bar (Thread/sleep 200))
                     (tufte/capture-time! :baz 100))]
 
-           [(is (= (get-in @@pd [:stats :foo :n]) 1))
-            (is (= (get-in @@pd [:stats :bar :n]) 1))
-            (is (= (get-in @@pd [:stats :baz :n]) 1))])
+           [(is (enc/submap? @@pd
+                  {:stats
+                   {:foo {:n 1}
+                    :bar {:n 1}
+                    :baz {:n 1}}}))])
 
          ;; dynamic `p`s against dynamic pdata
          (let [pd (tufte/new-pdata         {:dynamic? true})
@@ -435,10 +440,11 @@
                     (tufte/capture-time! :baz 100))]
 
            (Thread/sleep 100)
-
-           [(is (= (get-in @@pd [:stats :foo :n]) 1))
-            (is (= (get-in @@pd [:stats :bar :n]) 1))
-            (is (= (get-in @@pd [:stats :baz :n]) 1))])])]))
+           [(is (enc/submap? @@pd
+                  {:stats
+                   {:foo {:n 1}
+                    :bar {:n 1}
+                    :baz {:n 1}}}))])])]))
 
 (deftest format-pstats
   [(testing "Basic format-pstats"
@@ -546,7 +552,7 @@
 ;;;; Util macros
 
 (do
-  (tufte/defnp                      fn1  [x] x) ; Line 549
+  (tufte/defnp                      fn1  [x] x) ; Line 555
   (tufte/defnp                      fn2  [x] x)
   (tufte/defnp ^{:tufte/id :__fn3}  fn3  [x] x)
   (tufte/defnp ^{:tufte/id "__fn4"} fn4 ([x] x) ([x y] [x y]))
@@ -586,19 +592,20 @@
   ;; need to be updated when line numbers change.
   [(let [[r ps]
          (profiled {}
-           (p :foo) (p :bar) ; Line 589
+           (p :foo) (p :bar) ; Line 595
            (p :baz
              (p :qux)))]
 
      [(is (enc/submap? @ps
-            {:stats {:foo {:loc {:line 589}}
-                     :bar {:loc {:line 589}}
-                     :baz {:loc {:line 590}}
-                     :qux {:loc {:line 591}}}}))])
+            (let [nref 595]
+              {:stats {:foo {:loc {:line nref}}
+                       :bar {:loc {:line nref}}
+                       :baz {:loc {:line (+ nref 1)}}
+                       :qux {:loc {:line (+ nref 2)}}}})))])
 
    (let [[r ps]
          (profiled {}
-           (p          :foo) ; Line 601
+           (p          :foo) ; Line 608
            (p          :foo)
            (p          :foo)
            (tufte/pspy :foo))
@@ -606,21 +613,22 @@
          loc (get-in @ps [:stats :foo :loc])]
 
      [(is (set? loc) "id with >1 locations")
-      (is (= (into #{} (map :line) loc) #{601 602 603 604}))
+      (is (= (into #{} (map :line) loc) (let [nref 608] #{nref (+ nref 1) (+ nref 2) (+ nref 3)})))
       (is (enc/submap? @ps {:stats {:foo {:n 4}}}) "id's stats include all locations")])
 
    (let [[r ps] (profiled {} (run-test-fns))]
      [(is
         (enc/submap? @ps
-          {:stats {::defn_fn1 {:loc {:line 549}}
-                   ::defn_fn2 {:loc {:line 550}}
-                   :__fn3     {:loc {:line 551}}
-                   :__fn4     {:loc {:line 552}}
-                   :__fn4_1   {:loc {:line 552}}
-                   :__fn4_2   {:loc {:line 552}}
-                   ::defn_fn5 {:loc {:line 553}}
-                   ::fn_fn6   {:loc {:line 556}}
-                   :__fn7     {:loc {:line 557}}}}))])])
+          (let [nref 555]
+           {:stats {::defn_fn1 {:loc {:line    nref}}
+                    ::defn_fn2 {:loc {:line (+ nref 1)}}
+                    :__fn3     {:loc {:line (+ nref 2)}}
+                    :__fn4     {:loc {:line (+ nref 3)}}
+                    :__fn4_1   {:loc {:line (+ nref 3)}}
+                    :__fn4_2   {:loc {:line (+ nref 3)}}
+                    ::defn_fn5 {:loc {:line (+ nref 4)}}
+                    ::fn_fn6   {:loc {:line (+ nref 7)}}
+                    :__fn7     {:loc {:line (+ nref 8)}}}})))])])
 
 (comment (let [f1 (tufte/fnp foo [x] x #_(p :x x))]))