Consider using more of goog.* Closure library for debugging/logging

[hura]

I've notice a little comment in your notes that you're wondering about better logging/debugging mechanism. I'd like to point you to:
https://github.com/google/closure-library/blob/master/closure/goog/demos/debug.html

The demo seems to not work anymore on the offical google closure docs:
http://docs.closure-library.googlecode.com/git/class_goog_debug_FancyWindow.html

So the easiest is to clone google closure repo and just open the debug.html in a browser.

Advantages:

• No deps, you already have all of google closure
• Flexible & tested
• Keeps emitted JS code small due to closure compiler & libarary

The logging of google closure is actually quite nice & flexible. For instance you can send exceptions automatically to the web server if wanted. Can probably also be easily adjusted to log to airbrake etc.

Feel free to ignore & close this issue.
HTH

[mike-thompson-day8]

@hura Thanks!

I'm quite intrigued by the re-frame debug story. With a bit more work, it is going to be excellent.

This cycle happens:

1. An event is dispatched
2. An event gets handled (which changes app-db)
3. Subscriptions fire (because app-db changed)
4. components rerender (because their subscriptions update)

At that point, the app pauses, waiting for the next event (user interaction, I/O, etc). Generally, this is the point at which you, the programmer, want to check that everything has just happened correctly.

At the moment, using debug middleware helps a bit with observing steps 1 and 2.

As well, I tend to wrap my entire handlers.cljs, subs.cljs and views.cljs in clairvoyant.

I put this immediately under the ns form:

(trace/trace-forms {:tracer trace/default-tracer}

and then I put a balancing ) at the end of the file.

When you do that, you can look in the devtools console to see the 4 steps of the cycle described above. You can see what subscriptions are firing, and which components are rendering (providing you put names on the various anonymous functions)

It is really quite neat. Unfortunately, it is also a bit crap ... because the default output from clairvoyant is not ideal. I wished it showed data via inspect in shodan. And the way it shows the hiccup output from components is terrible because there are functions in the hiccup and that produces MASSIVE amounts of meaningless javascript code. Detection and suppression of functions needs to happen.

Plus, I want a way to remove all the clairvoyant code when I compile for production. Without having to remove the wrapping. I want all trace of clairvoyant to disappear when goog.DEBUG is false.

If we can write a better tracer for clairvoyant then the debug story will be a nice one.

I guess I'm saying that I'm keen on a devtools console based solution, rather than something based on goog.logger. console gives a hierarchical display (via grouping) plus I'd like to eventually see all output for subscriptions show up with a light green background. trace for Components are faint yellow. Event handlers get light blue. It is possible

Anyone up for writing a few better clairvoyant tracers, one for each of handlers, subs and components?

(trace/trace-forms {:tracer re-frame-handlers-tracer}   ;; Ohh, custom tracer!!

To put all this another way ... I'd like to approach debugging as a data visualisation problem. How can clairvoyant-like trace data from steps 1 to 4 be displayed to me, so that I can easily assimilate and process the information. That's why I was talking about slightly different background colours for each of the 4 steps. Small things that help me to process the information. I want high level information, and then the ability to drill down into it (via console's hierarchical display).

[hura]

in that case check out this cljs library:
https://github.com/binaryage/cljs-devtools

I think in your case contributing a different printer to clairvoyant would make the most sense. From a first look, it doesn't look too difficult.

[hura]

IMO, logging should have the following "design":

• At its simplest case it simple centralizes data (that is to be logged) into one transaction log.
• It is append only and attaches some data. Such as
  • A timestamp
  • A namespace the log comes from (may or may not map to real cljs ns)
  • A log level

That's already it. The rest of the functionality of a good logger are just convenience.

From existing loggers a few patterns emerge:
The centralized implies the logger has to provide a factory
function that returns a logger.

This mostly follows the design of existing (server side) logging framework.

On server systems logging usually goes quickly to hard disk (or other
persistance) due to massive amount of data.

IMO on client side all logs should be kept in memory for easy
inspection/tracing/filtering.

Eg: "Only display re-frame.* with level INFO. Hide all re-frame.xyz"

Report Logs

Only one small task of a good logger is to actually output the message
somewhere:

• Popup
• Transparent overlay appearing on keypress
• Console
• Websocket/POST/airbrake

Those are called Appenders in timbre. And Reporters in goog closure.
We can do this in realtime, buffered or whatever we wish.
We can choose to only forward log messages for one namespace to appender x/y.
Arbitrarily flexible.

Existing libraries

I can't really find a great cljs library that does this.
My previous suggestion of goog.debug does pretty well however.
For instance, in the popup I can exactly map any namespace (and namespace.* to
also get all children) to display a certain verbosity level (DEBUG, TRACE).
To see how this works, edit the html of the example above and introduce some
new new loogers with different namespace.

I don't think it does buffering however, which means that once a message is out
and reported it's gone so all the filters etc needs to be setup beforehand.

The console isn't bad, but it provides little interaction. I can't filter
previous messages and hide them from the console. They're already out there.
So with this problem I don't see myself too exited about console logging when
I'm dealing with a large complex app.

Conclusion

All this isn't hard to implement. But it's work.

It would be super simple API:

(ns my-ns.list.item
  (:require awesome-logging :refer [logger]))

(def lg (logger)) ;; automatically create a default logger with ns "my-ns.list.item" and no level
;;or:
(def dlg (logger :DEBUG)) ;; change verbosity
;;or:
;; Some of my operations in this file pertain to the parent ns
(def plg (logger "my-ns.list"))

;; Then in the code
(lg :INFO :my-event :and-data)
(lg :DEBUG "added 1+1")
(dlg :db-dump @db) 
(plg :INFO "I messed with my-ns.list's stuff" :and-it-liked-it)

The logger attaches a time and I can filter/inspect and do whatever I want with
the stream: "When ns re-frame.core.this-that emits :crazy-error, then display
the previous 10 log events from every namespace".

I see the need for something flexible like this due to the async nature of
channels/events which makes debugging so much harder than traditional
javascript code.

Outro

When you think about, re-frame almost has all this, minus the presentation
layer. You have a central chan and you have a middlware that can just record
all the history of the events and store it in an atom.
Reaction are you real time output. Materialised view are your filters. (On all
log messages or just the current one).
All that's left is for a nice overlay (would be my favorite) that appears on a
CTRL-SHIFT-D keypress and has some buttons/fields to apply some filters.

Sorry for the wall of text, just wanted to brainstorm :)

[rauhs]

I've created such a library:

https://github.com/rauhs/klang

[mike-thompson-day8]

Will this change satisfy your logging needs?
https://github.com/Day8/re-frame/wiki/FAQ#3-can-re-frame-use-my-logging-functions

This change will be a part of v0.4.0

[mike-thompson-day8]

Silence is assent, so I'm closing this. If you find any problems, put them in here and we can reopen