Repository: wilkerlucio/pathom
Pull request #103 (2019-07-25 04:12:07)

Parallel process processing checks


Patch:
diff --git a/.gitignore b/.gitignore
index 264e5cbd..60c0b664 100644
--- a/.gitignore
+++ b/.gitignore
@@ -1,21 +1,22 @@
-/target
-/classes
-/checkouts
-pom.xml
-pom.xml.asc
-*.jar
 *.class
+*.iml
+*.jar
+.cpcache
+.DS_Store
+.hg/
+.hgignore
+.idea
+.shadow-cljs
 /.lein-*
 /.nrepl-port
-.hgignore
-.hg/
-*.iml
-node_modules
+/checkouts
+/classes
+/target
 docs/assets/js/book/cljs-runtime
 docs/assets/js/book/manifest.edn
-.idea
+node_modules
 notes
-.cpcache 
-.shadow-cljs 
-out 
+out
+pom.xml
+pom.xml.asc
 workspaces/assets/js
diff --git a/CHANGELOG.md b/CHANGELOG.md
index f6098f9e..c891366e 100644
--- a/CHANGELOG.md
+++ b/CHANGELOG.md
@@ -1,5 +1,8 @@
 # Change Log
 
+## [2.2.18]
+- Add new `::pp/processing-recheck-timer` option to parallel parser
+
 ## [2.2.17]
 - Looser spec on `::pc/transform`
 - Use `contains?` instead of `find` in map reader to support wider range of custom maps
diff --git a/deps.edn b/deps.edn
index bbdc87ab..08bfdb52 100644
--- a/deps.edn
+++ b/deps.edn
@@ -3,7 +3,7 @@
 
  :deps
  {camel-snake-kebab      {:mvn/version "0.4.0"}
-  edn-query-language/eql {:mvn/version "0.0.6"}
+  edn-query-language/eql {:mvn/version "0.0.8"}
   org.clojure/core.async {:mvn/version "0.4.474"}
   org.clojure/data.json  {:mvn/version "0.2.6"}
   org.clojure/test.check {:mvn/version "0.10.0-alpha3"}
diff --git a/project.clj b/project.clj
index dae91c13..67df9282 100644
--- a/project.clj
+++ b/project.clj
@@ -1,4 +1,4 @@
-(defproject com.wsscode/pathom "2.2.17"
+(defproject com.wsscode/pathom "2.2.18"
   :description "A Clojure library designed to provide a collection of helper functions to support Clojure(script) graph parsers using\nom.next graph syntax."
   :url "https://github.com/wilkerlucio/pathom"
   :license {:name "MIT"
@@ -10,7 +10,7 @@
                  [com.wsscode/spec-inspec "1.0.0-alpha2"]
                  [org.clojure/data.json "0.2.6"]
                  [spec-coerce "1.0.0-alpha6"]
-                 [edn-query-language/eql "0.0.5"]
+                 [edn-query-language/eql "0.0.8"]
                  [org.clojure/core.async "0.4.474"]
                  [org.clojure/test.check "0.10.0-alpha3"]
 
diff --git a/src/com/wsscode/pathom/core.cljc b/src/com/wsscode/pathom/core.cljc
index 2408def6..a7c2e620 100644
--- a/src/com/wsscode/pathom/core.cljc
+++ b/src/com/wsscode/pathom/core.cljc
@@ -985,6 +985,13 @@
            :target          target})
         tx)))))
 
+(defn wrap-parallel-setup [parser]
+  (fn wrap-async-done-signal-internal [env tx]
+    (let [signal (atom false)]
+      (let-chan [res (parser (assoc env ::pp/done-signal* signal ::pp/active-paths (atom #{}) ::path []) tx)]
+        (reset! signal true)
+        res))))
+
 (defn wrap-setup-async-cache [parser]
   (fn wrap-setup-async-cache-internal [env tx]
     (let [async-cache-ch (async/chan (get env ::async-request-cache-ch-size 1024))]
@@ -1091,14 +1098,17 @@
   issues with concurrency, each request gets its own channel, so you can consider this
   size needs to accomodate the max parallelism for a single query. Default: 1024
 
-  ::pt/max-key-iterations - there is a loop that happens when processing attributes in
+  ::pp/max-key-iterations - there is a loop that happens when processing attributes in
   parallel, this loop will cause multiple iterations to happen in order for a single
   atribute to be processed, but in some conditions this loop can go indefinely, to
   prevent this situation this option allows to control the max number of iterations, after
   that it will give up on processing that attribute. Default: 10
 
-  ::pt/key-process-timeout - Max time allowed to run the full query. This is a cascading
-  timeout, the first level will have the total amount"
+  ::pp/key-process-timeout - Max time allowed to run the full query. This is a cascading
+  timeout, the first level will have the total amount. Default: 60000
+
+  ::pp/processing-recheck-timer - Periodic time to run a checker to verify no parts are
+  stuck during the processing. Default: 3000"
   [settings]
   (let [plugins (easy-plugins settings)
         mutate  (settings-mutation settings)]
@@ -1109,6 +1119,7 @@
                              :add-error add-error})
         (apply-plugins plugins ::wrap-parser)
         (apply-plugins plugins ::wrap-parser2 settings)
+        (wrap-parallel-setup)
         (wrap-setup-async-cache)
         (wrap-normalize-env plugins))))
 
diff --git a/src/com/wsscode/pathom/parser.cljc b/src/com/wsscode/pathom/parser.cljc
index 9544418c..10ac9164 100644
--- a/src/com/wsscode/pathom/parser.cljc
+++ b/src/com/wsscode/pathom/parser.cljc
@@ -10,7 +10,8 @@
   #?(:clj (:import (clojure.lang IDeref))))
 
 (when p.misc/INCLUDE_SPECS
-  (s/def ::max-key-iterations int?))
+  (s/def ::max-key-iterations int?)
+  (s/def ::processing-recheck-timer pos-int?))
 
 (declare expr->ast)
 
@@ -340,7 +341,9 @@
                     :key       key})
         [res
          (into waiting provides)
-         (conj processing stream)
+         (conj processing {::process-channel stream
+                           ::process-source  ::channel-response
+                           ::provides        provides})
          key-iterations
          tail])
 
@@ -351,7 +354,9 @@
                     ::provides provides})
         [res
          (into waiting provides)
-         (conj processing stream)
+         (conj processing {::process-channel stream
+                           ::process-source  ::parallel-reader
+                           ::provides        provides})
          key-iterations
          tail])
 
@@ -377,6 +382,73 @@
 (defn default-step-fn [amount min]
   (fn [env x] (Math/max (- x amount) min)))
 
+(defn process-next-message
+  [{::keys                        [done-signal* processing-recheck-timer active-paths]
+    :com.wsscode.pathom.core/keys [path]
+    :as                           env}
+   tx waiting indexed-props processing key-iterations key-watchers res]
+  (go-catch
+    (let [_                        (trace env {::pt/event         ::processing-wait-next
+                                               ::processing-count (count processing)})
+          processing-recheck-timer (async/timeout (or processing-recheck-timer 3000))
+          [msg p] (async/alts! (conj (into [] (map ::process-channel) processing) processing-recheck-timer) :priority true)]
+      (if (= p processing-recheck-timer)
+        (let [all-props     (into #{} (keys indexed-props))
+              current-props (into #{} (keys res))
+              missing-props (set/difference all-props current-props)]
+          (pt/trace env {::pt/event   ::trigger-recheck-timer-result
+                         ::processing {:processes     processing
+                                       :missing-props missing-props}})
+          (if (some #(contains? @active-paths (conj path %)) missing-props)
+            [res waiting processing key-iterations []]
+            (do
+              (pt/trace env {::pt/event ::trigger-recheck-schedule})
+              (doseq [{::keys [process-channel]} processing]
+                (async/close! process-channel))
+              (if @done-signal*
+                res
+                [res #{} #{} key-iterations (into [] (map indexed-props) missing-props)]))))
+        (let [{::keys [response-value provides merge-result? error]} msg
+              waiting'       (::waiting msg)
+              provides'      (set/difference provides waiting')
+              key-as         (:pathom/as response-value)
+              response-value (dissoc response-value :pathom/as)
+              waiting        (into waiting waiting')]
+          (if msg
+            (do
+              (trace env (cond-> {::pt/event       ::process-pending
+                                  ::provides       provides
+                                  ::response-value response-value
+                                  ::merge-result?  (boolean merge-result?)}
+                           waiting' (assoc ::waiting waiting')))
+              (swap! (:com.wsscode.pathom.core/entity env) #(merge response-value %))
+
+              (parallel-flush-watchers env key-watchers provides' error)
+
+              (if merge-result?
+                (do
+                  (pt/trace env {::pt/event ::merge-result ::response-value response-value})
+                  [(assoc res key-as (first (vals response-value)))
+                   (into #{} (remove provides') waiting)
+                   processing
+                   key-iterations
+                   []])
+
+                (let [next-children (->> (vec provides')
+                                         (focus-subquery tx)
+                                         (query->ast)
+                                         :children
+                                         (remove (comp (set (keys res)) ast->out-key))
+                                         (distinct))]
+                  (pt/trace env {::pt/event  ::reset-loop
+                                 ::loop-keys (mapv :key next-children)})
+                  [res
+                   (into #{} (remove provides') waiting)
+                   processing
+                   (reduce (fn [iter {:keys [key]}] (update iter key (fnil inc 0))) key-iterations next-children)
+                   next-children])))
+            [res waiting (into #{} (remove (comp #{p} ::process-channel)) processing) key-iterations []]))))))
+
 (defn call-parallel-parser
   [{:keys [read mutate]}
    {::keys                        [waiting key-watchers max-key-iterations
@@ -388,7 +460,7 @@
   (go-catch
     (let [key-process-timeout-step (or key-process-timeout-step (default-step-fn 1000 1000))
           key-process-timeout      (if key-process-timeout (key-process-timeout-step env key-process-timeout))
-          {:keys [children]}       (query->ast tx)
+          {:keys [children]} (query->ast tx)
           key-watchers             (or key-watchers (atom {}))
           path-entity              (get @entity-path-cache path {})
           env                      (-> env
@@ -400,7 +472,8 @@
                                              (do
                                                (swap! x #(merge path-entity %))
                                                x)
-                                             (atom (merge path-entity x))))))]
+                                             (atom (merge path-entity x))))))
+          indexed-props            (into {} (map (fn [{:keys [key] :as ast}] [key ast])) children)]
       (tracing env {::pt/event            ::parse-loop
                     ::key-process-timeout key-process-timeout}
         (loop [res            {}
@@ -408,7 +481,9 @@
                processing     #{}
                key-iterations {}
                [{:keys [key] :as ast} & tail] children]
-          (if ast
+          (cond
+            ; processing attributes
+            ast
             (let [out-key (ast->out-key ast)]
               (trace env {::pt/event ::process-key :key key})
               (cond
@@ -429,7 +504,9 @@
                 (do
                   (trace env {::pt/event ::external-wait-key :key key})
                   (recur res waiting
-                    (conj processing (watch-pending-key env key))
+                    (conj processing {::process-channel (watch-pending-key env key)
+                                      ::process-source  ::pending-key-watch
+                                      ::provides        #{key}})
                     key-iterations
                     tail))
 
@@ -447,62 +524,36 @@
                         read mutate key-iterations tail)]
                   (recur res waiting processing key-iterations tail))))
 
-            (if (seq processing)
-              (let [[{::keys [response-value provides merge-result? error] :as msg} p] (async/alts! (vec processing))
-                    waiting'       (::waiting msg)
-                    provides'      (set/difference provides waiting')
-                    key-as         (:pathom/as response-value)
-                    response-value (dissoc response-value :pathom/as)
-                    waiting        (into waiting waiting')]
-                (if msg
-                  (do
-                    (trace env (cond-> {::pt/event       ::process-pending
-                                        ::provides       provides
-                                        ::response-value response-value
-                                        ::merge-result?  (boolean merge-result?)}
-                                 waiting' (assoc ::waiting waiting')))
-                    (swap! (:com.wsscode.pathom.core/entity env) #(merge response-value %))
-
-                    (parallel-flush-watchers env key-watchers provides' error)
-
-                    (if merge-result?
-                      (do
-                        (pt/trace env {::pt/event ::merge-result ::response-value response-value})
-                        (recur
-                          (assoc res key-as (first (vals response-value)))
-                          (into #{} (remove provides') waiting)
-                          processing
-                          key-iterations
-                          []))
-
-                      (let [next-children (->> (vec provides')
-                                               (focus-subquery tx)
-                                               (query->ast)
-                                               :children
-                                               (remove (comp (set (keys res)) ast->out-key))
-                                               (distinct))]
-                        (pt/trace env {::pt/event  ::reset-loop
-                                       ::loop-keys (mapv :key next-children)})
-                        (recur res
-                          (into #{} (remove provides') waiting)
-                          processing
-                          (reduce (fn [iter {:keys [key]}] (update iter key (fnil inc 0))) key-iterations next-children)
-                          next-children))))
-                  (recur res waiting (disj processing p) key-iterations [])))
-              res)))))))
+            ; waiting for results
+            (seq processing)
+            (let [processing-step-result (<! (process-next-message env tx waiting indexed-props processing key-iterations key-watchers res))]
+              (if (vector? processing-step-result)
+                (let [[res waiting processing key-iterations tail] processing-step-result]
+                  (recur res waiting processing key-iterations tail))
+                processing-step-result))
+
+            ; done
+            :else
+            res))))))
 
 (defn parallel-parser [{:keys [add-error] :as pconfig}]
-  (fn self [{::keys [key-process-timeout]
-             :or    {key-process-timeout 60000}
-             :as    env} tx]
+  (fn self [{::keys                        [key-process-timeout active-paths]
+             :com.wsscode.pathom.core/keys [path]
+             :or                           {key-process-timeout 60000}
+             :as                           env} tx]
     (go-catch
+      (swap! active-paths conj path)
       (let [res-ch   (call-parallel-parser pconfig (assoc env :parser self ::key-process-timeout key-process-timeout) tx)
             channels (cond-> [res-ch] key-process-timeout (conj (async/timeout key-process-timeout)))
             [res p] (async/alts! channels)]
 
+        (swap! active-paths disj path)
+
         (if (= res-ch p)
           res
           (do
+            (trace env {::pt/event            ::timeout-reach
+                        ::key-process-timeout key-process-timeout})
             (add-error env (ex-info "Parallel read timeout" {:timeout key-process-timeout}))
             {}))))))
 
diff --git a/src/com/wsscode/pathom/trace.cljc b/src/com/wsscode/pathom/trace.cljc
index 1ee9f25f..ba1a9827 100644
--- a/src/com/wsscode/pathom/trace.cljc
+++ b/src/com/wsscode/pathom/trace.cljc
@@ -119,6 +119,10 @@
               :com.wsscode.pathom.parser/skip-resolved-key :com.wsscode.pathom.parser/external-wait-key)
             (update-in x [:response ::children key ::details] (fnil conj []) (select-keys row [::event ::label ::style ::relative-timestamp :key]))
 
+            (:com.wsscode.pathom.parser/trigger-recheck-timer-result :com.wsscode.pathom.parser/trigger-recheck-schedule)
+            (update-in x [:response ::details] (fnil conj [])
+              (select-keys row [::event ::label ::style ::relative-timestamp :com.wsscode.pathom.parser/processing :key]))
+
             :com.wsscode.pathom.parser/max-iterations-reached
             (update-in x [:response ::children key ::details] (fnil conj []) (select-keys row [::event ::label ::style ::relative-timestamp :com.wsscode.pathom.parser/max-key-iterations]))
 


Test patch:
diff --git a/src/com/wsscode/pathom/test.cljc b/src/com/wsscode/pathom/test.cljc
index 083864a8..246d17a4 100644
--- a/src/com/wsscode/pathom/test.cljc
+++ b/src/com/wsscode/pathom/test.cljc
@@ -123,5 +123,5 @@
     :ret nat-int?)
 
   (s/fdef key-ex-value
-    :args (s/cat :key ::eql/key :env (s/keys :opt [::throw-errors?
-                                                   ::include-nils?]))))
+    :args (s/cat :key ::eql/join-key :env (s/keys :opt [::throw-errors?
+                                                        ::include-nils?]))))
diff --git a/test/com/wsscode/pathom/connect_test.cljc b/test/com/wsscode/pathom/connect_test.cljc
index 23cfef33..20a013d5 100644
--- a/test/com/wsscode/pathom/connect_test.cljc
+++ b/test/com/wsscode/pathom/connect_test.cljc
@@ -3315,7 +3315,7 @@
                   [:c :d]}]))))
 
      (testing "global resolver times out"
-       (is (= {:com.wsscode.pathom.core/errors {nil "class clojure.lang.ExceptionInfo: Parallel read timeout - {:timeout 200}"}}
+       (is (= {:com.wsscode.pathom.core/errors {[] "class clojure.lang.ExceptionInfo: Parallel read timeout - {:timeout 200}"}}
               (quick-parser {::p/env       {::pp/key-process-timeout 200}
                              ::pc/register [(pc/resolver 'a
                                                          {::pc/input  #{}
diff --git a/test/com/wsscode/pathom/parser_test.clj b/test/com/wsscode/pathom/parser_test.clj
index bfc61017..7d5e6d10 100644
--- a/test/com/wsscode/pathom/parser_test.clj
+++ b/test/com/wsscode/pathom/parser_test.clj
@@ -7,6 +7,16 @@
             [com.wsscode.pathom.trace :as pt]
             [com.wsscode.pathom.connect :as pc]))
 
+(defn insist
+  ([f] (insist f 10))
+  ([f n]
+   (loop [n n]
+     (if (pos? n)
+       (if-let [res (f)]
+         res
+         (recur (dec n)))
+       false))))
+
 (deftest test-parser
   (let [parser (pp/parser {:read (fn [{:keys [ast]}]
                                    (case (:dispatch-key ast)
@@ -231,6 +241,9 @@
             {:com.wsscode.pathom.core/path   []
              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/skip-wait-key
              :key                            :b}
+            {:com.wsscode.pathom.core/path               []
+             :com.wsscode.pathom.parser/processing-count 1
+             :com.wsscode.pathom.trace/event             :com.wsscode.pathom.parser/processing-wait-next}
             {:com.wsscode.pathom.core/path             []
              :com.wsscode.pathom.parser/merge-result?  false
              :com.wsscode.pathom.parser/provides       #{:a
@@ -276,6 +289,9 @@
             {:com.wsscode.pathom.core/path   []
              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/value-return
              :key                            :a}
+            {:com.wsscode.pathom.core/path               []
+             :com.wsscode.pathom.parser/processing-count 1
+             :com.wsscode.pathom.trace/event             :com.wsscode.pathom.parser/processing-wait-next}
             {:com.wsscode.pathom.core/path                  []
              :com.wsscode.pathom.parser/key-process-timeout 59000
              :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/leave
@@ -305,6 +321,9 @@
             {:com.wsscode.pathom.core/path   []
              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/async-return
              :key                            :a}
+            {:com.wsscode.pathom.core/path               []
+             :com.wsscode.pathom.parser/processing-count 1
+             :com.wsscode.pathom.trace/event             :com.wsscode.pathom.parser/processing-wait-next}
             {:com.wsscode.pathom.core/path             []
              :com.wsscode.pathom.parser/merge-result?  true
              :com.wsscode.pathom.parser/provides       #{:a}
@@ -319,159 +338,178 @@
             {:com.wsscode.pathom.core/path             []
              :com.wsscode.pathom.parser/response-value {:a :done}
              :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/merge-result}
+            {:com.wsscode.pathom.core/path               []
+             :com.wsscode.pathom.parser/processing-count 1
+             :com.wsscode.pathom.trace/event             :com.wsscode.pathom.parser/processing-wait-next}
             {:com.wsscode.pathom.core/path                  []
              :com.wsscode.pathom.parser/key-process-timeout 59000
              :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/leave
              :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}])))
 
   (testing "skip-resolved-key"
-    (reset! trace [])
     (is (= (<!! (pparser (quick-reader {::pt/trace* trace} {:a (constantly "HO!")})
                   [:a :a]))
            {:a "HO!"}))
-    (is (= (comparable-trace @trace)
-           [{:com.wsscode.pathom.core/path                  []
-             :com.wsscode.pathom.parser/key-process-timeout 59000
-             :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/enter
-             :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}
-            {:com.wsscode.pathom.core/path   []
-             :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
-             :key                            :a}
-            {:com.wsscode.pathom.core/path       []
-             :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
-             :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
-             :key                                :a}
-            {:com.wsscode.pathom.core/path       []
-             :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
-             :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
-             :key                                :a}
-            {:com.wsscode.pathom.core/path   []
-             :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/value-return
-             :key                            :a}
-            {:com.wsscode.pathom.core/path   []
-             :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
-             :key                            :a}
-            {:com.wsscode.pathom.core/path   []
-             :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/skip-resolved-key
-             :key                            :a}
-            {:com.wsscode.pathom.core/path                  []
-             :com.wsscode.pathom.parser/key-process-timeout 59000
-             :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/leave
-             :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}])))
+    (is (insist
+          (fn []
+            (reset! trace [])
+            (<!! (pparser (quick-reader {::pt/trace* trace} {:a (constantly "HO!")})
+                   [:a :a]))
+            (= (comparable-trace @trace)
+               [{:com.wsscode.pathom.core/path                  []
+                 :com.wsscode.pathom.parser/key-process-timeout 59000
+                 :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/enter
+                 :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}
+                {:com.wsscode.pathom.core/path   []
+                 :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
+                 :key                            :a}
+                {:com.wsscode.pathom.core/path       []
+                 :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
+                 :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
+                 :key                                :a}
+                {:com.wsscode.pathom.core/path       []
+                 :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
+                 :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
+                 :key                                :a}
+                {:com.wsscode.pathom.core/path   []
+                 :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/value-return
+                 :key                            :a}
+                {:com.wsscode.pathom.core/path   []
+                 :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
+                 :key                            :a}
+                {:com.wsscode.pathom.core/path   []
+                 :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/skip-resolved-key
+                 :key                            :a}
+                {:com.wsscode.pathom.core/path                  []
+                 :com.wsscode.pathom.parser/key-process-timeout 59000
+                 :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/leave
+                 :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}])))))
 
   (testing "external wait"
-    (reset! trace [])
     (is (= (<!! (pparser (quick-reader {::pt/trace* trace} {:b r-ab-quick :c r-b-dep})
                   [:b :c]))
            {:b 2 :c 12}))
-    (is (= (comparable-trace-in-any-order @trace)
-           '{{:com.wsscode.pathom.core/path                  [:c]
-              :com.wsscode.pathom.parser/key-process-timeout 58000
-              :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/enter
-              :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop} 1
-             {:com.wsscode.pathom.core/path                  [:c]
-              :com.wsscode.pathom.parser/key-process-timeout 58000
-              :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/leave
-              :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop} 1
-             {:com.wsscode.pathom.core/path        [:c]
-              :com.wsscode.pathom.parser/loop-keys [:b]
-              :com.wsscode.pathom.trace/event      :com.wsscode.pathom.parser/reset-loop}           1
-             {:com.wsscode.pathom.core/path             [:c]
-              :com.wsscode.pathom.parser/merge-result?  false
-              :com.wsscode.pathom.parser/provides       #{:b}
-              :com.wsscode.pathom.parser/response-value nil
-              :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/process-pending} 1
-             {:com.wsscode.pathom.core/path       [:c]
-              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
-              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
-              :key                                :b}                                               1
-             {:com.wsscode.pathom.core/path       [:c]
-              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
-              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}   1
-             {:com.wsscode.pathom.core/path       [:c]
-              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
-              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
-              :key                                :b}                                               1
-             {:com.wsscode.pathom.core/path       [:c]
-              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
-              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}   1
-             {:com.wsscode.pathom.core/path   [:c]
-              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/external-wait-key
-              :key                            :b}                                                   1
-             {:com.wsscode.pathom.core/path   [:c]
-              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
-              :key                            :b}                                                   2
-             {:com.wsscode.pathom.core/path   [:c]
-              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/value-return
-              :key                            :b}                                                   1
-             {:com.wsscode.pathom.core/path                  []
-              :com.wsscode.pathom.parser/key-process-timeout 59000
-              :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/enter
-              :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop} 1
-             {:com.wsscode.pathom.core/path                  []
-              :com.wsscode.pathom.parser/key-process-timeout 59000
-              :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/leave
-              :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop} 1
-             {:com.wsscode.pathom.core/path        []
-              :com.wsscode.pathom.parser/loop-keys [:b]
-              :com.wsscode.pathom.trace/event      :com.wsscode.pathom.parser/reset-loop}           1
-             {:com.wsscode.pathom.core/path             []
-              :com.wsscode.pathom.parser/merge-result?  false
-              :com.wsscode.pathom.parser/provides       #{:a
-                                                          :b}
-              :com.wsscode.pathom.parser/response-value {:a 1
-                                                         :b 2}
-              :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/process-pending} 1
-             {:com.wsscode.pathom.core/path             []
-              :com.wsscode.pathom.parser/merge-result?  true
-              :com.wsscode.pathom.parser/provides       #{:c}
-              :com.wsscode.pathom.parser/response-value {:c 12}
-              :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/process-pending} 1
-             {:com.wsscode.pathom.core/path       []
-              :com.wsscode.pathom.parser/provides #{:a
-                                                    :b}
-              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/provided-return}       1
-             {:com.wsscode.pathom.core/path             []
-              :com.wsscode.pathom.parser/response-value {:c 12}
-              :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/merge-result}    1
-             {:com.wsscode.pathom.core/path            []
-              :com.wsscode.pathom.parser/watcher-count 1
-              :com.wsscode.pathom.trace/event          :com.wsscode.pathom.parser/flush-watchers
-              :key                                     :b}                                          1
-             {:com.wsscode.pathom.core/path       []
-              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
-              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
-              :key                                :b}                                               2
-             {:com.wsscode.pathom.core/path       []
-              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
-              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
-              :key                                :c}                                               1
-             {:com.wsscode.pathom.core/path       []
-              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
-              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}   2
-             {:com.wsscode.pathom.core/path       []
-              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
-              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
-              :key                                :b}                                               2
-             {:com.wsscode.pathom.core/path       []
-              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
-              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
-              :key                                :c}                                               1
-             {:com.wsscode.pathom.core/path       []
-              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
-              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}   2
-             {:com.wsscode.pathom.core/path   []
-              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/async-return
-              :key                            :c}                                                   1
-             {:com.wsscode.pathom.core/path   []
-              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
-              :key                            :b}                                                   2
-             {:com.wsscode.pathom.core/path   []
-              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
-              :key                            :c}                                                   1
-             {:com.wsscode.pathom.core/path   []
-              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/value-return
-              :key                            :b}                                                   1})))
+    (is (insist (fn []
+                  (reset! trace [])
+                  (<!! (pparser (quick-reader {::pt/trace* trace} {:b r-ab-quick :c r-b-dep})
+                         [:b :c]))
+                  (= (comparable-trace-in-any-order @trace)
+                    '{{:com.wsscode.pathom.core/path                  [:c]
+                       :com.wsscode.pathom.parser/key-process-timeout 58000
+                       :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/enter
+                       :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}        1
+                      {:com.wsscode.pathom.core/path                  [:c]
+                       :com.wsscode.pathom.parser/key-process-timeout 58000
+                       :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/leave
+                       :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}        1
+                      {:com.wsscode.pathom.core/path        [:c]
+                       :com.wsscode.pathom.parser/loop-keys [:b]
+                       :com.wsscode.pathom.trace/event      :com.wsscode.pathom.parser/reset-loop}                  1
+                      {:com.wsscode.pathom.core/path             [:c]
+                       :com.wsscode.pathom.parser/merge-result?  false
+                       :com.wsscode.pathom.parser/provides       #{:b}
+                       :com.wsscode.pathom.parser/response-value nil
+                       :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/process-pending}        1
+                      {:com.wsscode.pathom.core/path               [:c]
+                       :com.wsscode.pathom.parser/processing-count 1
+                       :com.wsscode.pathom.trace/event             :com.wsscode.pathom.parser/processing-wait-next} 2
+                      {:com.wsscode.pathom.core/path       [:c]
+                       :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
+                       :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
+                       :key                                :b}                                                      1
+                      {:com.wsscode.pathom.core/path       [:c]
+                       :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
+                       :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}          1
+                      {:com.wsscode.pathom.core/path       [:c]
+                       :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
+                       :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
+                       :key                                :b}                                                      1
+                      {:com.wsscode.pathom.core/path       [:c]
+                       :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
+                       :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}          1
+                      {:com.wsscode.pathom.core/path   [:c]
+                       :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/external-wait-key
+                       :key                            :b}                                                          1
+                      {:com.wsscode.pathom.core/path   [:c]
+                       :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
+                       :key                            :b}                                                          2
+                      {:com.wsscode.pathom.core/path   [:c]
+                       :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/value-return
+                       :key                            :b}                                                          1
+                      {:com.wsscode.pathom.core/path                  []
+                       :com.wsscode.pathom.parser/key-process-timeout 59000
+                       :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/enter
+                       :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}        1
+                      {:com.wsscode.pathom.core/path                  []
+                       :com.wsscode.pathom.parser/key-process-timeout 59000
+                       :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/leave
+                       :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}        1
+                      {:com.wsscode.pathom.core/path        []
+                       :com.wsscode.pathom.parser/loop-keys [:b]
+                       :com.wsscode.pathom.trace/event      :com.wsscode.pathom.parser/reset-loop}                  1
+                      {:com.wsscode.pathom.core/path             []
+                       :com.wsscode.pathom.parser/merge-result?  false
+                       :com.wsscode.pathom.parser/provides       #{:a
+                                                                   :b}
+                       :com.wsscode.pathom.parser/response-value {:a 1
+                                                                  :b 2}
+                       :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/process-pending}        1
+                      {:com.wsscode.pathom.core/path             []
+                       :com.wsscode.pathom.parser/merge-result?  true
+                       :com.wsscode.pathom.parser/provides       #{:c}
+                       :com.wsscode.pathom.parser/response-value {:c 12}
+                       :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/process-pending}        1
+                      {:com.wsscode.pathom.core/path               []
+                       :com.wsscode.pathom.parser/processing-count 1
+                       :com.wsscode.pathom.trace/event             :com.wsscode.pathom.parser/processing-wait-next} 2
+                      {:com.wsscode.pathom.core/path               []
+                       :com.wsscode.pathom.parser/processing-count 2
+                       :com.wsscode.pathom.trace/event             :com.wsscode.pathom.parser/processing-wait-next} 2
+                      {:com.wsscode.pathom.core/path       []
+                       :com.wsscode.pathom.parser/provides #{:a
+                                                             :b}
+                       :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/provided-return}              1
+                      {:com.wsscode.pathom.core/path             []
+                       :com.wsscode.pathom.parser/response-value {:c 12}
+                       :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/merge-result}           1
+                      {:com.wsscode.pathom.core/path            []
+                       :com.wsscode.pathom.parser/watcher-count 1
+                       :com.wsscode.pathom.trace/event          :com.wsscode.pathom.parser/flush-watchers
+                       :key                                     :b}                                                 1
+                      {:com.wsscode.pathom.core/path       []
+                       :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
+                       :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
+                       :key                                :b}                                                      2
+                      {:com.wsscode.pathom.core/path       []
+                       :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
+                       :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
+                       :key                                :c}                                                      1
+                      {:com.wsscode.pathom.core/path       []
+                       :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
+                       :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}          2
+                      {:com.wsscode.pathom.core/path       []
+                       :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
+                       :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
+                       :key                                :b}                                                      2
+                      {:com.wsscode.pathom.core/path       []
+                       :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
+                       :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
+                       :key                                :c}                                                      1
+                      {:com.wsscode.pathom.core/path       []
+                       :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
+                       :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}          2
+                      {:com.wsscode.pathom.core/path   []
+                       :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/async-return
+                       :key                            :c}                                                          1
+                      {:com.wsscode.pathom.core/path   []
+                       :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
+                       :key                            :b}                                                          2
+                      {:com.wsscode.pathom.core/path   []
+                       :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
+                       :key                            :c}                                                          1
+                      {:com.wsscode.pathom.core/path   []
+                       :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/value-return
+                       :key                            :b}                                                          1})))))
 
   (testing "max key iterations"
     (reset! trace [])
@@ -479,7 +517,7 @@
                                         ::pp/max-key-iterations 5} {:a r-provide-miss})
                   [:a]))
            {:a ::p/not-found}))
-    (is (= (comparable-trace @trace)
+    (is (= (remove (comp #{::pp/processing-wait-next} ::pt/event) (comparable-trace @trace))
            [{:com.wsscode.pathom.core/path                  []
              :com.wsscode.pathom.parser/key-process-timeout 59000
              :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/enter
@@ -637,41 +675,49 @@
              :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}])))
 
   (testing "call sync mutation"
-    (reset! trace [])
     (is (= (<!! (pparser {::pt/trace* trace} '[(operation {:foo "bar"})]))
            '{operation {:value "return"}}))
-    (is (= (comparable-trace @trace)
-           '[{:com.wsscode.pathom.core/path                  []
-              :com.wsscode.pathom.parser/key-process-timeout 59000
-              :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/enter
-              :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}
-             {:com.wsscode.pathom.core/path   []
-              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
-              :key                            operation}
-             {:com.wsscode.pathom.core/path   []
-              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/async-return
-              :key                            operation}
-             {:com.wsscode.pathom.core/path   []
-              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/call-mutation
-              :mutation                       operation}
-             {:com.wsscode.pathom.core/path             []
-              :com.wsscode.pathom.parser/merge-result?  true
-              :com.wsscode.pathom.parser/provides       #{operation}
-              :com.wsscode.pathom.parser/response-value {operation {:value "return"}}
-              :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/process-pending}
-             {:com.wsscode.pathom.core/path       []
-              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
-              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
-             {:com.wsscode.pathom.core/path       []
-              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
-              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
-             {:com.wsscode.pathom.core/path             []
-              :com.wsscode.pathom.parser/response-value {operation {:value "return"}}
-              :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/merge-result}
-             {:com.wsscode.pathom.core/path                  []
-              :com.wsscode.pathom.parser/key-process-timeout 59000
-              :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/leave
-              :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}])))
+    (is (insist (fn []
+                  (reset! trace [])
+                  (<!! (pparser {::pt/trace* trace} '[(operation {:foo "bar"})]))
+                  (= (comparable-trace @trace)
+                     '[{:com.wsscode.pathom.core/path                  []
+                        :com.wsscode.pathom.parser/key-process-timeout 59000
+                        :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/enter
+                        :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}
+                       {:com.wsscode.pathom.core/path   []
+                        :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
+                        :key                            operation}
+                       {:com.wsscode.pathom.core/path   []
+                        :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/async-return
+                        :key                            operation}
+                       {:com.wsscode.pathom.core/path   []
+                        :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/call-mutation
+                        :mutation                       operation}
+                       {:com.wsscode.pathom.core/path               []
+                        :com.wsscode.pathom.parser/processing-count 1
+                        :com.wsscode.pathom.trace/event             :com.wsscode.pathom.parser/processing-wait-next}
+                       {:com.wsscode.pathom.core/path             []
+                        :com.wsscode.pathom.parser/merge-result?  true
+                        :com.wsscode.pathom.parser/provides       #{operation}
+                        :com.wsscode.pathom.parser/response-value {operation {:value "return"}}
+                        :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/process-pending}
+                       {:com.wsscode.pathom.core/path       []
+                        :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
+                        :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
+                       {:com.wsscode.pathom.core/path       []
+                        :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
+                        :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
+                       {:com.wsscode.pathom.core/path             []
+                        :com.wsscode.pathom.parser/response-value {operation {:value "return"}}
+                        :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/merge-result}
+                       {:com.wsscode.pathom.core/path               []
+                        :com.wsscode.pathom.parser/processing-count 1
+                        :com.wsscode.pathom.trace/event             :com.wsscode.pathom.parser/processing-wait-next}
+                       {:com.wsscode.pathom.core/path                  []
+                        :com.wsscode.pathom.parser/key-process-timeout 59000
+                        :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/leave
+                        :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}])))))
 
   (testing "call async mutation"
     (reset! trace [])
@@ -691,6 +737,9 @@
              {:com.wsscode.pathom.core/path   []
               :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/call-mutation
               :mutation                       operation}
+             {:com.wsscode.pathom.core/path               []
+              :com.wsscode.pathom.parser/processing-count 1
+              :com.wsscode.pathom.trace/event             :com.wsscode.pathom.parser/processing-wait-next}
              {:com.wsscode.pathom.core/path             []
               :com.wsscode.pathom.parser/merge-result?  true
               :com.wsscode.pathom.parser/provides       #{operation}
@@ -705,190 +754,230 @@
              {:com.wsscode.pathom.core/path             []
               :com.wsscode.pathom.parser/response-value {operation {:value "return"}}
               :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/merge-result}
+             {:com.wsscode.pathom.core/path               []
+              :com.wsscode.pathom.parser/processing-count 1
+              :com.wsscode.pathom.trace/event             :com.wsscode.pathom.parser/processing-wait-next}
              {:com.wsscode.pathom.core/path                  []
               :com.wsscode.pathom.parser/key-process-timeout 59000
               :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/leave
               :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}])))
 
   (testing "call sync mutation error"
-    (reset! trace [])
     (is (= (<!! (pparser {::pt/trace*       trace
                           ::error?          true
                           ::p/process-error #(.getMessage %2)}
                   '[(operation {:foo "bar"})]))
            '{operation #:com.wsscode.pathom.parser{:error "Error"}}))
-    (is (= (comparable-trace @trace)
-           '[{:com.wsscode.pathom.core/path                  []
-              :com.wsscode.pathom.parser/key-process-timeout 59000
-              :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/enter
-              :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}
-             {:com.wsscode.pathom.core/path   []
-              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
-              :key                            operation}
-             {:com.wsscode.pathom.core/path   []
-              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/async-return
-              :key                            operation}
-             {:com.wsscode.pathom.core/path   []
-              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/call-mutation
-              :mutation                       operation}
-             {:com.wsscode.pathom.core/path             []
-              :com.wsscode.pathom.parser/merge-result?  true
-              :com.wsscode.pathom.parser/provides       #{operation}
-              :com.wsscode.pathom.parser/response-value {operation #:com.wsscode.pathom.parser{:error "Error"}}
-              :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/process-pending}
-             {:com.wsscode.pathom.core/path       []
-              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
-              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
-             {:com.wsscode.pathom.core/path       []
-              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
-              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
-             {:com.wsscode.pathom.core/path             []
-              :com.wsscode.pathom.parser/response-value {operation #:com.wsscode.pathom.parser{:error "Error"}}
-              :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/merge-result}
-             {:com.wsscode.pathom.core/path                  []
-              :com.wsscode.pathom.parser/key-process-timeout 59000
-              :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/leave
-              :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}])))
+    (is (fn []
+          (reset! trace [])
+          (<!! (pparser {::pt/trace*       trace
+                         ::error?          true
+                         ::p/process-error #(.getMessage %2)}
+                 '[(operation {:foo "bar"})]))
+          (= (comparable-trace @trace)
+             '[{:com.wsscode.pathom.core/path                  []
+                :com.wsscode.pathom.parser/key-process-timeout 59000
+                :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/enter
+                :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}
+               {:com.wsscode.pathom.core/path   []
+                :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
+                :key                            operation}
+               {:com.wsscode.pathom.core/path   []
+                :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/async-return
+                :key                            operation}
+               {:com.wsscode.pathom.core/path   []
+                :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/call-mutation
+                :mutation                       operation}
+               {:com.wsscode.pathom.core/path               []
+                :com.wsscode.pathom.parser/processing-count 1
+                :com.wsscode.pathom.trace/event             :com.wsscode.pathom.parser/processing-wait-next}
+               {:com.wsscode.pathom.core/path             []
+                :com.wsscode.pathom.parser/merge-result?  true
+                :com.wsscode.pathom.parser/provides       #{operation}
+                :com.wsscode.pathom.parser/response-value {operation #:com.wsscode.pathom.parser{:error "Error"}}
+                :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/process-pending}
+               {:com.wsscode.pathom.core/path       []
+                :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
+                :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
+               {:com.wsscode.pathom.core/path       []
+                :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
+                :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
+               {:com.wsscode.pathom.core/path             []
+                :com.wsscode.pathom.parser/response-value {operation #:com.wsscode.pathom.parser{:error "Error"}}
+                :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/merge-result}
+               {:com.wsscode.pathom.core/path               []
+                :com.wsscode.pathom.parser/processing-count 1
+                :com.wsscode.pathom.trace/event             :com.wsscode.pathom.parser/processing-wait-next}
+               {:com.wsscode.pathom.core/path                  []
+                :com.wsscode.pathom.parser/key-process-timeout 59000
+                :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/leave
+                :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}]))))
 
   (testing "call async mutation error"
-    (reset! trace [])
-
     (is (= (<!! (pparser {::pt/trace*       trace
                           ::error?          true
                           ::async?          true
                           ::p/process-error #(.getMessage %2)}
                   '[(operation {:foo "bar"})]))
            '{operation #:com.wsscode.pathom.parser{:error "Error"}}))
-    (is (= (comparable-trace @trace)
-           '[{:com.wsscode.pathom.core/path                  []
-              :com.wsscode.pathom.parser/key-process-timeout 59000
-              :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/enter
-              :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}
-             {:com.wsscode.pathom.core/path   []
-              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
-              :key                            operation}
-             {:com.wsscode.pathom.core/path   []
-              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/async-return
-              :key                            operation}
-             {:com.wsscode.pathom.core/path   []
-              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/call-mutation
-              :mutation                       operation}
-             {:com.wsscode.pathom.core/path             []
-              :com.wsscode.pathom.parser/merge-result?  true
-              :com.wsscode.pathom.parser/provides       #{operation}
-              :com.wsscode.pathom.parser/response-value {operation #:com.wsscode.pathom.parser{:error "Error"}}
-              :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/process-pending}
-             {:com.wsscode.pathom.core/path       []
-              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
-              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
-             {:com.wsscode.pathom.core/path       []
-              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
-              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
-             {:com.wsscode.pathom.core/path             []
-              :com.wsscode.pathom.parser/response-value {operation #:com.wsscode.pathom.parser{:error "Error"}}
-              :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/merge-result}
-             {:com.wsscode.pathom.core/path                  []
-              :com.wsscode.pathom.parser/key-process-timeout 59000
-              :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/leave
-              :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}])))
+    (is (fn []
+          (reset! trace [])
+          (<!! (pparser {::pt/trace*       trace
+                         ::error?          true
+                         ::async?          true
+                         ::p/process-error #(.getMessage %2)}
+                 '[(operation {:foo "bar"})]))
+          (= (comparable-trace @trace)
+            '[{:com.wsscode.pathom.core/path                  []
+               :com.wsscode.pathom.parser/key-process-timeout 59000
+               :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/enter
+               :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}
+              {:com.wsscode.pathom.core/path   []
+               :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
+               :key                            operation}
+              {:com.wsscode.pathom.core/path   []
+               :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/async-return
+               :key                            operation}
+              {:com.wsscode.pathom.core/path   []
+               :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/call-mutation
+               :mutation                       operation}
+              {:com.wsscode.pathom.core/path               []
+               :com.wsscode.pathom.parser/processing-count 1
+               :com.wsscode.pathom.trace/event             :com.wsscode.pathom.parser/processing-wait-next}
+              {:com.wsscode.pathom.core/path             []
+               :com.wsscode.pathom.parser/merge-result?  true
+               :com.wsscode.pathom.parser/provides       #{operation}
+               :com.wsscode.pathom.parser/response-value {operation #:com.wsscode.pathom.parser{:error "Error"}}
+               :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/process-pending}
+              {:com.wsscode.pathom.core/path       []
+               :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
+               :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
+              {:com.wsscode.pathom.core/path       []
+               :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
+               :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
+              {:com.wsscode.pathom.core/path             []
+               :com.wsscode.pathom.parser/response-value {operation #:com.wsscode.pathom.parser{:error "Error"}}
+               :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/merge-result}
+              {:com.wsscode.pathom.core/path               []
+               :com.wsscode.pathom.parser/processing-count 1
+               :com.wsscode.pathom.trace/event             :com.wsscode.pathom.parser/processing-wait-next}
+              {:com.wsscode.pathom.core/path                  []
+               :com.wsscode.pathom.parser/key-process-timeout 59000
+               :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/leave
+               :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}]))))
 
   (testing "provides waiting"
     (reset! trace [])
     (is (= (<!! (pparser (quick-reader {::pt/trace* trace} r-provide-waiting)
                   [:d]))
            {:d "ddd"}))
-    (is (= (comparable-trace @trace)
-           [{:com.wsscode.pathom.core/path                  []
-             :com.wsscode.pathom.parser/key-process-timeout 59000
-             :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/enter
-             :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}
-            {:com.wsscode.pathom.core/path   []
-             :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
-             :key                            :d}
-            {:com.wsscode.pathom.core/path       []
-             :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
-             :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
-             :key                                :d}
-            {:com.wsscode.pathom.core/path       []
-             :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
-             :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
-             :key                                :d}
-            {:com.wsscode.pathom.core/path       []
-             :com.wsscode.pathom.parser/provides #{:a
-                                                   :b
-                                                   :c
-                                                   :d}
-             :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/provided-return}
-            {:com.wsscode.pathom.core/path             []
-             :com.wsscode.pathom.parser/merge-result?  false
-             :com.wsscode.pathom.parser/provides       #{:a}
-             :com.wsscode.pathom.parser/response-value {:a "aaa"}
-             :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/process-pending}
-            {:com.wsscode.pathom.core/path       []
-             :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
-             :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
-            {:com.wsscode.pathom.core/path       []
-             :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
-             :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
-            {:com.wsscode.pathom.core/path        []
-             :com.wsscode.pathom.parser/loop-keys []
-             :com.wsscode.pathom.trace/event      :com.wsscode.pathom.parser/reset-loop}
-            {:com.wsscode.pathom.core/path             []
-             :com.wsscode.pathom.parser/merge-result?  false
-             :com.wsscode.pathom.parser/provides       #{:a
-                                                         :b
-                                                         :c
-                                                         :d}
-             :com.wsscode.pathom.parser/response-value {}
-             :com.wsscode.pathom.parser/waiting        #{:b
-                                                         :d}
-             :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/process-pending}
-            {:com.wsscode.pathom.core/path       []
-             :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
-             :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
-            {:com.wsscode.pathom.core/path       []
-             :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
-             :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
-            {:com.wsscode.pathom.core/path        []
-             :com.wsscode.pathom.parser/loop-keys []
-             :com.wsscode.pathom.trace/event      :com.wsscode.pathom.parser/reset-loop}
-            {:com.wsscode.pathom.core/path             []
-             :com.wsscode.pathom.parser/merge-result?  false
-             :com.wsscode.pathom.parser/provides       #{:b
-                                                         :d}
-             :com.wsscode.pathom.parser/response-value {:b "bbb"
-                                                        :d "ddd"}
-             :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/process-pending}
-            {:com.wsscode.pathom.core/path       []
-             :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
-             :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
-            {:com.wsscode.pathom.core/path       []
-             :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
-             :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
-            {:com.wsscode.pathom.core/path        []
-             :com.wsscode.pathom.parser/loop-keys [:d]
-             :com.wsscode.pathom.trace/event      :com.wsscode.pathom.parser/reset-loop}
-            {:com.wsscode.pathom.core/path   []
-             :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
-             :key                            :d}
-            {:com.wsscode.pathom.core/path       []
-             :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
-             :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
-             :key                                :d}
-            {:com.wsscode.pathom.core/path       []
-             :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
-             :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
-             :key                                :d}
-            {:com.wsscode.pathom.core/path   []
-             :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/value-return
-             :key                            :d}
-            {:com.wsscode.pathom.core/path                  []
-             :com.wsscode.pathom.parser/key-process-timeout 59000
-             :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/leave
-             :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}])))
+    (is (insist (fn []
+                  (reset! trace [])
+                  (<!! (pparser (quick-reader {::pt/trace* trace} r-provide-waiting)
+                         [:d]))
+                  (= (comparable-trace @trace)
+                    [{:com.wsscode.pathom.core/path                  []
+                      :com.wsscode.pathom.parser/key-process-timeout 59000
+                      :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/enter
+                      :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}
+                     {:com.wsscode.pathom.core/path   []
+                      :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
+                      :key                            :d}
+                     {:com.wsscode.pathom.core/path       []
+                      :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
+                      :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
+                      :key                                :d}
+                     {:com.wsscode.pathom.core/path       []
+                      :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
+                      :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
+                      :key                                :d}
+                     {:com.wsscode.pathom.core/path       []
+                      :com.wsscode.pathom.parser/provides #{:a
+                                                            :b
+                                                            :c
+                                                            :d}
+                      :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/provided-return}
+                     {:com.wsscode.pathom.core/path               []
+                      :com.wsscode.pathom.parser/processing-count 1
+                      :com.wsscode.pathom.trace/event             :com.wsscode.pathom.parser/processing-wait-next}
+                     {:com.wsscode.pathom.core/path             []
+                      :com.wsscode.pathom.parser/merge-result?  false
+                      :com.wsscode.pathom.parser/provides       #{:a}
+                      :com.wsscode.pathom.parser/response-value {:a "aaa"}
+                      :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/process-pending}
+                     {:com.wsscode.pathom.core/path       []
+                      :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
+                      :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
+                     {:com.wsscode.pathom.core/path       []
+                      :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
+                      :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
+                     {:com.wsscode.pathom.core/path        []
+                      :com.wsscode.pathom.parser/loop-keys []
+                      :com.wsscode.pathom.trace/event      :com.wsscode.pathom.parser/reset-loop}
+                     {:com.wsscode.pathom.core/path               []
+                      :com.wsscode.pathom.parser/processing-count 1
+                      :com.wsscode.pathom.trace/event             :com.wsscode.pathom.parser/processing-wait-next}
+                     {:com.wsscode.pathom.core/path             []
+                      :com.wsscode.pathom.parser/merge-result?  false
+                      :com.wsscode.pathom.parser/provides       #{:a
+                                                                  :b
+                                                                  :c
+                                                                  :d}
+                      :com.wsscode.pathom.parser/response-value {}
+                      :com.wsscode.pathom.parser/waiting        #{:b
+                                                                  :d}
+                      :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/process-pending}
+                     {:com.wsscode.pathom.core/path       []
+                      :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
+                      :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
+                     {:com.wsscode.pathom.core/path       []
+                      :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
+                      :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
+                     {:com.wsscode.pathom.core/path        []
+                      :com.wsscode.pathom.parser/loop-keys []
+                      :com.wsscode.pathom.trace/event      :com.wsscode.pathom.parser/reset-loop}
+                     {:com.wsscode.pathom.core/path               []
+                      :com.wsscode.pathom.parser/processing-count 1
+                      :com.wsscode.pathom.trace/event             :com.wsscode.pathom.parser/processing-wait-next}
+                     {:com.wsscode.pathom.core/path             []
+                      :com.wsscode.pathom.parser/merge-result?  false
+                      :com.wsscode.pathom.parser/provides       #{:b
+                                                                  :d}
+                      :com.wsscode.pathom.parser/response-value {:b "bbb"
+                                                                 :d "ddd"}
+                      :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/process-pending}
+                     {:com.wsscode.pathom.core/path       []
+                      :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
+                      :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
+                     {:com.wsscode.pathom.core/path       []
+                      :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
+                      :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}
+                     {:com.wsscode.pathom.core/path        []
+                      :com.wsscode.pathom.parser/loop-keys [:d]
+                      :com.wsscode.pathom.trace/event      :com.wsscode.pathom.parser/reset-loop}
+                     {:com.wsscode.pathom.core/path   []
+                      :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
+                      :key                            :d}
+                     {:com.wsscode.pathom.core/path       []
+                      :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
+                      :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
+                      :key                                :d}
+                     {:com.wsscode.pathom.core/path       []
+                      :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
+                      :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
+                      :key                                :d}
+                     {:com.wsscode.pathom.core/path   []
+                      :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/value-return
+                      :key                            :d}
+                     {:com.wsscode.pathom.core/path               []
+                      :com.wsscode.pathom.parser/processing-count 1
+                      :com.wsscode.pathom.trace/event             :com.wsscode.pathom.parser/processing-wait-next}
+                     {:com.wsscode.pathom.core/path                  []
+                      :com.wsscode.pathom.parser/key-process-timeout 59000
+                      :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/leave
+                      :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}])))))
 
   (testing "read timeout"
-    (reset! trace [])
     (is (= (<!! (pparser (quick-reader {::pp/key-process-timeout 2000
                                         ::pt/trace* trace
                                         ::p/entity (atom {:sub {}})}
@@ -899,58 +988,94 @@
                                                                    ::pp/response-value {:long "cant reach"}})})})
                   [{:sub [:long]}]))
            {:sub {}}))
-    (is (= (comparable-trace-in-any-order @trace)
-           {{:com.wsscode.pathom.core/path                  [:sub]
-             :com.wsscode.pathom.parser/key-process-timeout 1000
-             :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/enter
-             :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop} 1
-            {:com.wsscode.pathom.core/path       [:sub]
-             :com.wsscode.pathom.parser/provides #{:long}
-             :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/provided-return}       1
-            {:com.wsscode.pathom.core/path       [:sub]
-             :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
-             :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
-             :key                                :long}                                            1
-            {:com.wsscode.pathom.core/path       [:sub]
-             :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
-             :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
-             :key                                :long}                                            1
-            {:com.wsscode.pathom.core/path   [:sub]
-             :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
-             :key                            :long}                                                1
-            {:com.wsscode.pathom.core/path                  []
-             :com.wsscode.pathom.parser/key-process-timeout 1000
-             :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/enter
-             :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop} 1
-            {:com.wsscode.pathom.core/path                  []
-             :com.wsscode.pathom.parser/key-process-timeout 1000
-             :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/leave
-             :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop} 1
-            {:com.wsscode.pathom.core/path             []
-             :com.wsscode.pathom.parser/merge-result?  true
-             :com.wsscode.pathom.parser/provides       #{:sub}
-             :com.wsscode.pathom.parser/response-value {:sub {}}
-             :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/process-pending} 1
-            {:com.wsscode.pathom.core/path             []
-             :com.wsscode.pathom.parser/response-value {:sub {}}
-             :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/merge-result}    1
-            {:com.wsscode.pathom.core/path       []
-             :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
-             :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
-             :key                                :sub}                                             1
-            {:com.wsscode.pathom.core/path       []
-             :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
-             :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}   1
-            {:com.wsscode.pathom.core/path       []
-             :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
-             :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
-             :key                                :sub}                                             1
-            {:com.wsscode.pathom.core/path       []
-             :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
-             :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}   1
-            {:com.wsscode.pathom.core/path   []
-             :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/async-return
-             :key                            :sub}                                                 1
-            {:com.wsscode.pathom.core/path   []
-             :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
-             :key                            :sub}                                                 1}))))
+    (is (fn []
+          (reset! trace [])
+          (<!! (pparser (quick-reader {::pp/key-process-timeout 2000
+                                       ::pt/trace* trace
+                                       ::p/entity (atom {:sub {}})}
+                          {:long (fn [_] {::pp/provides        #{:long}
+                                          ::pp/response-stream (go
+                                                                 (<! (async/timeout 5000))
+                                                                 {::pp/provides       #{:long}
+                                                                  ::pp/response-value {:long "cant reach"}})})})
+                 [{:sub [:long]}]))
+          (= (comparable-trace-in-any-order @trace)
+            {{:com.wsscode.pathom.core/path                  [:sub]
+              :com.wsscode.pathom.parser/key-process-timeout 1000
+              :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/enter
+              :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}        1
+             {:com.wsscode.pathom.core/path                  [:sub]
+              :com.wsscode.pathom.parser/key-process-timeout 1000
+              :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/timeout-reach}     1
+             {:com.wsscode.pathom.core/path               [:sub]
+              :com.wsscode.pathom.parser/processing-count 1
+              :com.wsscode.pathom.trace/event             :com.wsscode.pathom.parser/processing-wait-next} 1
+             {:com.wsscode.pathom.core/path       [:sub]
+              :com.wsscode.pathom.parser/provides #{:long}
+              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/provided-return}              1
+             {:com.wsscode.pathom.core/path       [:sub]
+              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
+              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
+              :key                                :long}                                                   1
+             {:com.wsscode.pathom.core/path       [:sub]
+              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
+              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
+              :key                                :long}                                                   1
+             {:com.wsscode.pathom.core/path   [:sub]
+              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
+              :key                            :long}                                                       1
+             {:com.wsscode.pathom.core/path                  []
+              :com.wsscode.pathom.parser/key-process-timeout 1000
+              :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/enter
+              :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}        1
+             {:com.wsscode.pathom.core/path                  []
+              :com.wsscode.pathom.parser/key-process-timeout 1000
+              :com.wsscode.pathom.trace/direction            :com.wsscode.pathom.trace/leave
+              :com.wsscode.pathom.trace/event                :com.wsscode.pathom.parser/parse-loop}        1
+             {:com.wsscode.pathom.core/path             []
+              :com.wsscode.pathom.parser/merge-result?  true
+              :com.wsscode.pathom.parser/provides       #{:sub}
+              :com.wsscode.pathom.parser/response-value {:sub {}}
+              :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/process-pending}        1
+             {:com.wsscode.pathom.core/path               []
+              :com.wsscode.pathom.parser/processing-count 1
+              :com.wsscode.pathom.trace/event             :com.wsscode.pathom.parser/processing-wait-next} 2
+             {:com.wsscode.pathom.core/path             []
+              :com.wsscode.pathom.parser/response-value {:sub {}}
+              :com.wsscode.pathom.trace/event           :com.wsscode.pathom.parser/merge-result}           1
+             {:com.wsscode.pathom.core/path       []
+              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
+              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
+              :key                                :sub}                                                    1
+             {:com.wsscode.pathom.core/path       []
+              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/enter
+              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}          1
+             {:com.wsscode.pathom.core/path       []
+              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
+              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/call-read
+              :key                                :sub}                                                    1
+             {:com.wsscode.pathom.core/path       []
+              :com.wsscode.pathom.trace/direction :com.wsscode.pathom.trace/leave
+              :com.wsscode.pathom.trace/event     :com.wsscode.pathom.parser/flush-watchers-loop}          1
+             {:com.wsscode.pathom.core/path   []
+              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/async-return
+              :key                            :sub}                                                        1
+             {:com.wsscode.pathom.core/path   []
+              :com.wsscode.pathom.trace/event :com.wsscode.pathom.parser/process-key
+              :key                            :sub}                                                        1})))))
+
+(comment
+  @trace
+
+  (do
+    (reset! trace [])
+    (<!! (pparser (quick-reader {::pp/key-process-timeout 3000
+                                 ::pt/trace*              trace
+                                 ::p/entity               (atom {:sub {:deep {}}})}
+                    {:base (fn [_] 42)
+                     :long (fn [_] {::pp/provides        #{:long}
+                                    ::pp/response-stream (go
+                                                           (<! (async/timeout 1000))
+                                                           {::pp/provides       #{:long}
+                                                            ::pp/response-value {:long "cant reach"}})})})
+           [:base {:sub [{:deep [:long]}]}]))))