Trace do-fx and event-handler interceptors

This gives us more granular insight into event handling.

CHANGES.md

@@ -1,5 +1,8 @@
-## Unreleased
+## 0.10.5 (Unreleased)
 
+#### Changed
+
+- Event handlers and fx are now traced, to provide more granular timing info in re-frame-trace. This has no impact on your code execution if you haven't [enabled tracing](https://github.com/Day8/re-frame-trace#installation).
 
 ## 0.10.4 (2018.01.31)
 
@@ -217,7 +220,7 @@ Joking aside, this is a substantial release which will change how you use re-fra
   - the undo/redo features buried in re-frame has been factored out into
    [a standalone library](https://github.com/Day8/re-frame-undo).
 
-    undo and redo have been a part of re-frame from the beginning, but they have never officially  
+    undo and redo have been a part of re-frame from the beginning, but they have never officially
     been made a part of the API, and have not been documented. So it nice to see it available, and fully
     documented.
 
@@ -234,7 +237,7 @@ Joking aside, this is a substantial release which will change how you use re-fra
     But recently @steveb8n gave a cljsyd talk on
     Pedestal's Interceptor pattern which suddenly transformed them from
     arcane to delightfully simple in 20 mins. Interceptors are
-    really "middleware via data" rather than "middleware via higher order functions".  
+    really "middleware via data" rather than "middleware via higher order functions".
     So it is another way of doing the same thing, but thanks to @steveb8n
     Interceptors appear a more flexible base, and simpler.
 

src/re_frame/fx.cljc

@@ -6,7 +6,8 @@
     [re-frame.interop     :refer [set-timeout!]]
     [re-frame.events      :as events]
     [re-frame.registrar   :refer [get-handler clear-handlers register-handler]]
-    [re-frame.loggers     :refer [console]]))
+    [re-frame.loggers     :refer [console]]
+    [re-frame.trace :as trace :include-macros true]))
 
 
 ;; -- Registration ------------------------------------------------------------
@@ -68,10 +69,12 @@
     :id :do-fx
     :after (fn do-fx-after
              [context]
-             (doseq [[effect-key effect-value] (:effects context)]
-               (if-let [effect-fn (get-handler kind effect-key false)]
-                 (effect-fn effect-value)
-                 (console :error "re-frame: no handler registered for effect:" effect-key ". Ignoring."))))))
+             (trace/with-trace
+               {:op-type :event/do-fx}
+               (doseq [[effect-key effect-value] (:effects context)]
+                 (if-let [effect-fn (get-handler kind effect-key false)]
+                   (effect-fn effect-value)
+                   (console :error "re-frame: no handler registered for effect:" effect-key ". Ignoring.")))))))
 
 ;; -- Builtin Effect Handlers  ------------------------------------------------
 

src/re_frame/std_interceptors.cljc

@@ -107,9 +107,15 @@
     :id     :db-handler
     :before (fn db-handler-before
               [context]
-              (let [{:keys [db event]} (:coeffects context)
-                    new-context (->> (handler-fn db event)
-                                     (assoc-effect context :db))]
+              (let [new-context
+                    (trace/with-trace
+                      {:op-type   :event/handler
+                       :operation (get-in context [:coeffects :event])}
+                      (let [{:keys [db event]} (:coeffects context)]
+                        (->> (handler-fn db event)
+                             (assoc-effect context :db))))]
+                ;; We merge these tags outside of the :event/handler trace because we want them to be assigned to the parent
+                ;; wrapping trace.
                 (trace/merge-trace!
                   {:tags {:effects   (:effects new-context)
                           :coeffects (:coeffects context)}})
@@ -135,8 +141,12 @@
   :before (fn fx-handler-before
             [context]
             (let [{:keys [event] :as coeffects} (:coeffects context)
-                  new-context (->> (handler-fn coeffects event)
-                                   (assoc context :effects))]
+                  new-context
+                  (trace/with-trace
+                    {:op-type   :event/handler
+                     :operation (get-in context [:coeffects :event])}
+                    (->> (handler-fn coeffects event)
+                         (assoc context :effects)))]
               (trace/merge-trace!
                 {:tags {:effects   (:effects new-context)
                         :coeffects (:coeffects context)}})
@@ -154,7 +164,11 @@
     :id     :ctx-handler
     :before (fn ctx-handler-before
               [context]
-              (let [new-context (handler-fn context)]
+              (let [new-context
+                    (trace/with-trace
+                      {:op-type   :event/handler
+                       :operation (get-in context [:coeffects :event])}
+                      (handler-fn context))]
                 (trace/merge-trace!
                   {:tags {:effects   (:effects new-context)
                           :coeffects (:coeffects context)}})