Printing The component stack

mike-thompson-day8 commented 9 years ago

To improve debugging, I'm trying to print the "call stack" of components between (reagent/current-component) and the root .... but I'm failing :-( probably because of some fundamental misunderstanding on my side.

If it could be done, it would really make a difference to the quality of error messages, etc. Some kinds of errors would become so much easier to find.

My cunning plan was to start at the roots and work my way down the tree (via get-children) until I found a component which was identical? to (reagent/current-component). Then I've have a path. Then I'd extract the displayNames for each component in that path and print it out. And, bingo, a helpful stack.

Only there are some issues. Firstly, for example, roots seems to contain functions for creating roots, rather than the roots themselves. So, as a proof of concept, I kludged up access to the top component (don't ask!), but the process still failed for various reasons.

I'm out of time on this for the moment but I'm wondering if this is possible. Or am I barking up wrong trees (geddit)? I just don't want to let this go without at least asking.

marcloyal3 commented 9 years ago

Can you type your desired call stack and I'll give it a shot too (as a learning exercise) ? I assume it's for logging errors in nested components. You simply want to walk up the component call stack? I think it should be doable.

mike-thompson-day8 commented 9 years ago

@marcloyal3 that would be truly excellent! I would be seriously excited to see this feature (and was planning on circling back to it shortly).

My thought was:

Dan goes to a bit of trouble to give each component a user friendly "displayName" (see here)
so a "stack trace" would be as simple as printing out the list of displayNames from (reagent/current-component) to the root component.
While it would be lovely to get line numbers and file names, that would mean getting into macro territory (aka def-component) and then somehow store metadata on components, etc, etc. Better to make the first pass simple.

I had to stop half way through when I tried ... but I'd gained some insight:

the vals in roots is a component function and the container DOMElement.
so that's a bit useless for this exercise. It doesn't actually hold the root component ... just the means (function) to make the root component and the DOMElement (container).
but not completely useless, because roots does hold the root DOM element (container); and ...
... there is a React function which will give you a React component for any DOM element (container). (.' js/React some-method-xxxx container)) Hmm. At least, I thought there was ... I can't seem to find it now. Puzzling.
I'm not yet sure that get-children gives the components themselves OR the means to make them. (I suspect the later). So, again, that DOM to Component function (which I can't seem to find now) might have to be the way to traverse to children.

But these are just my impressions and half formed ideas from spending not enough time on it. I could wrong on any of these points. And it may yet not be possible.

marcloyal3 commented 9 years ago

Sure.

Here is an amateur implementation:

Syntax:

(defn inner-component1 [comp]
  [:div "inner component 1" comp]
  )
(defn inner-component2 [comp]
  [:div "inner component 2" comp]
  )

(defn inner-component3 [comp]
  [:div "inner component 3" comp]
  )

(defn top-component []
  [:div "top component"
   [monitor inner-component1 [monitor inner-component2 [monitor inner-component3] ]]
   ]
  )

(r/render [monitor top-component] (.getElementById js/document "app"))

with the following logging accomplished via "monitor" with NO error/exception logging or handling yet (but which can be added easily)

the "monitor" code:

(ns main.monitor
  (:require [reagent.core :as reagent]
            ))

(defn describe-phase [f args]
  (println "component"
    (get
      (re-find
        (re-pattern "(function)(\\s)(.*)([{}])")
        (str f)) 3) "is in" (args :phase) "phase in Virtual DOM")
  )
(defn monitor [f x]
  (let [start-time (atom nil)
        render-time (atom nil)
        now #(.now js/Date)
        lifecycle (fn [args]
                    (if (or (= (args :phase) "'Will Mount'") (= (args :phase) "'Will Update'"))
                      (do
                        (reset! start-time (now))
                        (println "--------------------------------------------------------------")
                        (describe-phase f args)
                        (if (= (args :phase) "'Will Update'")
                          (.log js/console "DOM State: " (.-outerHTML (reagent/as-element (reagent/dom-node (args :this)))))
                          )
                        )
                      )
                    (if (or (= (args :phase) "'Did Mount'") (= (args :phase) "'Did Update'"))
                      (do
                        (reset! render-time (- (now) @start-time))
                        (println "--------------------------------------------------------------")
                        (describe-phase f args)
                        (.log js/console "Render Time: " @render-time "ms")
                        (.log js/console "DOM State: " (.-outerHTML (reagent/as-element (reagent/dom-node (args :this)))))
                        )
                      )
                    )

        monitored-f (with-meta #(f x)
                      {
                        :component-will-mount #(lifecycle {:phase "'Will Mount'" :this %1 :arg1 %2 :arg2 %3})
                        :component-did-mount #(lifecycle {:phase "'Did Mount'" :this %1 :arg1 %2 :arg2 %3})
                        :component-will-update #(lifecycle {:phase "'Will Update'" :this %1 :arg1 %2 :arg2 %3})
                        :component-did-update #(lifecycle {:phase "'Did Update'" :this %1 :arg1 %2 :arg2 %3})
                        :component-will-unmount #(lifecycle {:phase "'Will Unmount'" :this %1 :arg1 %2 :arg2 %3})
                        })]
    [monitored-f]))

And the current output (no exception/error logging yet)

--------------------------------------------------------------
core.cljs:57 component top_component() is in 'Will Mount' phase in Virtual DOM
core.cljs:57 --------------------------------------------------------------
core.cljs:57 component inner_component1(i) is in 'Will Mount' phase in Virtual DOM
core.cljs:57 --------------------------------------------------------------
core.cljs:57 component inner_component2(i) is in 'Will Mount' phase in Virtual DOM
core.cljs:57 --------------------------------------------------------------
core.cljs:57 component inner_component3(i) is in 'Will Mount' phase in Virtual DOM
core.cljs:57 --------------------------------------------------------------
core.cljs:57 component inner_component3(i) is in 'Did Mount' phase in Virtual DOM
monitor.cljs:32 Render Time:  6 ms
monitor.cljs:33 Virtual DOM State:  <div data-reactid=".0.1.1.1"><span data-reactid=".0.1.1.1.0">inner component 3</span></div>
core.cljs:57 --------------------------------------------------------------
core.cljs:57 component inner_component2(i) is in 'Did Mount' phase in Virtual DOM
monitor.cljs:32 Render Time:  17 ms
monitor.cljs:33 Virtual DOM State:  <div data-reactid=".0.1.1"><span data-reactid=".0.1.1.0">inner component 2</span><div data-reactid=".0.1.1.1"><span data-reactid=".0.1.1.1.0">inner component 3</span></div></div>
core.cljs:57 --------------------------------------------------------------
core.cljs:57 component inner_component1(i) is in 'Did Mount' phase in Virtual DOM
monitor.cljs:32 Render Time:  25 ms
monitor.cljs:33 Virtual DOM State:  <div data-reactid=".0.1"><span data-reactid=".0.1.0">inner component 1</span><div data-reactid=".0.1.1"><span data-reactid=".0.1.1.0">inner component 2</span><div data-reactid=".0.1.1.1"><span data-reactid=".0.1.1.1.0">inner component 3</span></div></div></div>
core.cljs:57 --------------------------------------------------------------
core.cljs:57 component top_component() is in 'Did Mount' phase in Virtual DOM
monitor.cljs:32 Render Time:  58 ms
monitor.cljs:33 Virtual DOM State:  <div data-reactid=".0"><span data-reactid=".0.0">top component</span><div data-reactid=".0.1"><span data-reactid=".0.1.0">inner component 1</span><div data-reactid=".0.1.1"><span data-reactid=".0.1.1.0">inner component 2</span><div data-reactid=".0.1.1.1"><span data-reactid=".0.1.1.1.0">inner component 3</span></div></div></div></div>

pandeiro commented 9 years ago

This is awesome! Could it somehow evolve into an API where certain component functions in a namespace would be 'wrapped' in a monitor like so?

(defn some-component [x]
  [:div [:p x]])

;; ...

(monitor/wrap-components [some-component])

...or is that something that couldn't be done?

marcloyal3 commented 9 years ago

@pandeiro maybe..... time to read the Reagent source (before it gets too big for any one person to master ;)

mike-thompson-day8 commented 9 years ago

@holmsand I'm wondering if you can you supply any clarity around my original question and possible solutions? I'm happy to do the work on this, but I need a nudge in a direction which might work.

In everyday use of reagent, we find this to be the #1 most annoying/baffling issue we face: when we get an exception in a reusable component, we can't tell where this component is being used.

re-com goes to a lot of effort to detect parameter problems, but when it throws an exception because there is a problem, we don't know which "parent" component has the bug.

Any thoughts greatly appreciated.

holmsand commented 9 years ago

@mike-thompson-day8 I totally agree with your premise – it would be great to have some kind of print-component-stack or somesuch. I'm not sure that it can be reliably done, however, without relying on React internals (if I'm not mistaken, children are supposed to be opaque, or has that changed?). And I don't think that comparing children to already-mounted components will work anyway?

This is really something that should be done at the React level, I think. I can't think of a clean way to do this without keeping track of every parent, which React obviously has to do (that ends up in _owner).

mike-thompson-day8 commented 9 years ago

I'm now wondering if the "path" of a component, could be passed down from parent to child automagically, via react's "contexts" feature.

See https://github.com/reagent-project/reagent/pull/178

holmsand commented 9 years ago

@mike-thompson-day8 It could probably be done that way – but it seems a bit dangerous to rely on contexts, as they to change a lot (being undocumented, and all).

It might be just as reliable to add something that uses React's internal data structures, and prints nothing if they don't match expectations. I'll do some experiments...

holmsand commented 9 years ago

@mike-thompson-day8 Something like this seems to work:

(defn full-component-name [this]
  (when-some [elem (some-> (or (some-> this
                                       (.' :_reactInternalInstance))
                               this)
                           (.' :_currentElement))]
    (let [name (some-> (.' elem :type)
                       (.' :displayName))]
      (if-some [pname (full-component-name (.' elem :_owner))]
        (str pname " > " name)
        name))))

(given require [reagent.interop :refer-macros [.' .!]]).

It should be reasonably safe (returning null if React changes). Hopefully...

mike-thompson-day8 commented 9 years ago

@holmsand interesting. We'll do some experiments with that approach.

Question: could we simply start with (reagent/current-component) (in place of this) ?

mike-thompson-day8 commented 9 years ago

Oh, yeah. This is beautiful. So useful. Could we please have it in 0.5.1.

Below, I've tweaked your code as follows:

made the output more human readable, by replacing $ with dot
changed the defn name (I'm assuming this is to be added to the reagent.core API?)
have taken advantage of str handling nil nicely
tested it across a few of our apps

(defn component-path [c]
  (let [elem (some-> (or (some-> c
                                 (.' :_reactInternalInstance))
                          c)
                     (.' :_currentElement))
        name (some-> elem
                     (.' :type)
                     (.' :displayName)
                     (clojure.string/replace #"\$" "."))
        path (some-> elem
                     (.' :_owner)
                     component-path
                     (str " > "))]
    (str path name)))

Which can be used like this:

(component-path (reagent/current-component))

mike-thompson-day8 commented 9 years ago

Hours later I'm still giddy with excitement over this.

Just to state the obvious, apart from being added to the reagent API, this new function should be used to improve error messages in two places:

https://github.com/reagent-project/reagent/blob/master/src/reagent/impl/template.cljs#L323-L324

and

https://github.com/reagent-project/reagent/blob/5be5ace95d5bf96867469ea7b3c215a22bcae2d9/src/reagent/impl/util.cljs#L125-L127

I'd happily do a PR, but I've got a feeling you might want to do it yourself? Just say.

But definitely in 1.5.1-rc2 please. I think this is the most useful tweak to reagent since it was created.

holmsand commented 9 years ago

@mike-thompson-day8 Hope you're still giddy :)

I've now added component-path to core, and use it from impl.component/comp-name – so it should show up in all warnings and errors.

Unfortunately it can't be used in render-component, as far as I can tell – there's no way of knowing where the exception came from.

Perhaps we should add a try/catch to component rendering, so we can display some proper error message there (with component-path)? At least without :elide-asserts?

mike-thompson-day8 commented 9 years ago

Yeah, being able to report the full path for any component throwing an exception when rendering would be really useful.

Does that mean wrapping this function in a try catch? https://github.com/reagent-project/reagent/blob/e53a5c2b1357c0560f0c4c15b28f00d09e27237b/src/reagent/impl/component.cljs#L30-L55

Note: debugging has already improved a lot in recent times under Chrome because of this https://github.com/reagent-project/reagent/issues/120

holmsand commented 9 years ago

Yes, exactly. I ended up using try/finally instead (to not mess with un-handled exception settings in browsers), and a message that just says where that error happened.

Debugging should be even better now (even in Safari, etc), since render-component doesn't use catch anymore...

Anyway, give it a spin – and then I guess that 0.5.1 should be done :)

mike-thompson-day8 commented 9 years ago

@holmsand would you mind releasing an 0.5.1.rc2 to clojars please.

holmsand commented 9 years ago

Sure – done.

mike-thompson-day8 commented 9 years ago

From my point of view, this looks good to release. No problems in our apps.

mike-thompson-day8 commented 9 years ago

Released as part of 0.5.1

reagent-project / reagent

Printing The component stack #105