ClojureScript: compile-time logs mixed with JS code in output

olivergeorge commented 6 years ago

Seems like scope-capture would allow more convenient repl based development for my CLJS web apps. Can't see technical reasons it can't be made to work. (That would be exciting)

I gave it a try, there's currently a problem with how the repl output is generated. Print statements end up on the JS code which is compiled causing errors.

For example:

var CODE = cljs.core.get.call(null,map__68496__$1,new cljs.core.Keyword(null,"CODE","CODE",-1885949257));
var TITLE = cljs.core.get.call(null,map__68496__$1,new cljs.core.Keyword(null,"TITLE","TITLE",-120772486));
var link_to_project = (cljs.core.truth_(PROJ_PROJECT)?utas.routing.path_for_BANG_.call(null,new cljs.core.Keyword("pmr.project",...
return new cljs.core.PersistentVector(null, 3, 5, cljs.core.PersistentVector.EMPTY_NODE, [new cljs.core.Keyword(null,"div","div",1057191632),new cljs.core.PersistentVector(null, 2, 5, cljs.core.PersistentVector.EMPTY_NODE, ...;
});
SPY <-5> figwheel.clj:119 
  At Code Site -5, will save scope with locals [show-alloc? user show-wrf? props WR map__68500 insurance-program? p__68499 map__68502 comment-form]
wractioning_ui.views.connect_views.WRDetailsPage = (function wractioning_ui$views$connect_views$WRDetailsPage(p__68499){
var map__68500 = p__68499;
var map__68500__$1 = ((((!((map__68500 == null)))?((((map__68500.cljs$lang$protocol_mask$partition0$ & (64))) || ((cljs.core.PROTOCOL_SENTINEL === map__68500.cljs$core$ISeq$)))?true:false):false))?cljs.core.apply.call(null,cljs.core.hash_map,map__68500):map__68500);
var props = map__68500__$1;

Perhaps this can be avoided with a new register-cs-logger?

vvvvalvalval commented 6 years ago

Hi, yes ClojureScript support is definitely part of the intentions of this library (this release included). However, I confess I didn't try it on each one of the many CLJS REPLs out there...

I'm going on vacation for a week and won't really be able to help, but if you want to be unblocked right away I suggest you register a 'silent' cs logger for spy - see the Tutorial for how to register custom loggers. It should still be pretty usable, you will just get less feedback during compilation

olivergeorge commented 6 years ago

Thanks. I'll checkout the tutorial and give it a try.

Enjoy your vacation.

olivergeorge commented 6 years ago

Quick update to confirm this got me the reported error.

(ns can-i-debug.dev
  (:require [sc.api] [sc.impl] [sc.api.logging]))

(sc.api.logging/register-cs-logger ::dummy-logger (fn [_]))

(defmacro my-spy [form]
  `(sc.api/spy {:sc/spy-cs-logger-id ::dummy-logger} ~form))

vvvvalvalval commented 6 years ago

Alright, back from vacation.

So it seems the issue here is that both the logs from macro-expansion and the emission of JavaScript output get mingled in the same writer. I took the liberty of changing the title of the issue so that people don't think ClojureScript is not yet supported - (it is, in general).

@olivergeorge, can you describe the ClojureScript setup that led you to this situation please?

olivergeorge commented 6 years ago

Hope you had a good break.

I used lein new mies xxx to create the simplest test case possible. As mentioned the logger output appeared in the generated js files. Once that was silenced my-spy seemed to capture data but I couldn't get sc.api/letsc to work. It wasn't able to resolve the numbers in the atom.

I gave up after a while, if you think the basic case should work I'll try again.

vvvvalvalval commented 6 years ago

Thanks! I'll try to reproduce then get back to you.

vvvvalvalval commented 6 years ago

So first, not that it's critical to your issue, but the recommended way to define your own spy macro is to have it call spy-emit (so that it can pass to it the original &env and &form), like so:

(sc.api.logging/register-cs-logger
  ::dummy-logger
  (fn [_]))

(def my-spy-opts
  `{:sc/spy-cs-logger-id ::dummy-logger})

(defmacro my-spy
  ([] (sc.api/spy-emit my-spy-opts nil &env &form))
  ([expr] (sc.api/spy-emit my-spy-opts expr &env &form))
  ([opts expr] (sc.api/spy-emit (merge my-spy-opts opts) expr &env &form)))

This is detailed in the Customization section of the Tutorial.

vvvvalvalval commented 6 years ago

I was able to use scope-capture successfully in the browser REPL, as available in the mies template:

$ lein trampoline run -m clojure.main scripts/brepl.clj
Reading analysis cache for jar:file:/Users/val/.m2/repository/org/clojure/clojurescript/1.9.671/clojurescript-1.9.671.jar!/cljs/core.cljs
Compiling src/sccljs/core.cljs
[...]
Copying file:/Users/val/projects/sccljs/src/sccljs/core.cljs to out/sccljs/core.cljs
Compiling client js ...
Waiting for browser to connect ...
To quit, type: :cljs/quit
cljs.user=> (ns sccljs.core
  (:require [clojure.browser.repl :as repl]
            [sccljs.dev :refer-macros [my-spy]]
            [sc.api :refer-macros [spy brk letsc defsc]]))

sccljs.core=> (defn bar
  [x y]
  (+ x (spy (* 2 y))))
SPY <-1> /Users/val/projects/sccljs/scripts/brepl.clj:3 
  At Code Site -1, will save scope with locals [x y]
#'sccljs.core/bar
sccljs.core=> (bar 12 13)
SPY [1 -1] /Users/val/projects/sccljs/scripts/brepl.clj:3 
  At Execution Point 1 of Code Site -1, saved scope with locals [x y]
SPY [1 -1] /Users/val/projects/sccljs/scripts/brepl.clj:3 
(* 2 y)
=>
26
38
sccljs.core=> (defsc [1 -1])
[#'sccljs.core/x #'sccljs.core/y]
sccljs.core=> (+ x y)
25
sccljs.core=> (letsc [1 -1] [x y])
WARNING: Use of undeclared Var sccljs.core/yy at line 1 <cljs repl>
[12 nil]
sccljs.core=> (letsc [1 -1] [x y])
[12 13]
sccljs.core=> (bar 2 3)
SPY [2 -1] /Users/val/projects/sccljs/scripts/brepl.clj:3 
  At Execution Point 2 of Code Site -1, saved scope with locals [x y]
SPY [2 -1] /Users/val/projects/sccljs/scripts/brepl.clj:3 
(* 2 y)
=>
6
8
sccljs.core=> (letsc [2 -1] [x y])
[2 3]
sccljs.core=>

vvvvalvalval commented 6 years ago

@olivergeorge I also reproduced your first issue (logs in the emitted JS), which happens when you cljs.api.build/build or cljs.api.build/watch some CLJS code with an sc.api/spy call in it. The issue is that, for some reason, in these cases, the ClojureScript compiler emits JavaScript by binding *out* to some writer then calling print, which is why our scope-capture logs end up in the JS output.

You can get by these limitations by either using a silent logger (see above), or one that always prints to standard output or some defined file, e.g:

(sc.api.logging/register-cs-logger
  ::dummy-logger
  (fn [cs-data]
    (binding [*out* (java.io.OutputStreamWriter. System/out)]
      (println (:sc.cs/id cs-data) (:sc.cs/local-names cs-data)))))

Having said that, you typically don't want to use scope-capture at all outside of the context of a REPL!

vvvvalvalval commented 6 years ago

@olivergeorge Another issue you may have encountered is that, when several processes (e.g a REPL process and a watcher process) compile to the same runtime, they won't share their compile-time scope-capture database, leading to some Code Site Ids (e.g -3) not being identified. I'm currently thinking of ways to mitigate this issue. This was made worse by a bad error message in this case, which I'll be improving in the next minor release.

olivergeorge commented 6 years ago

Thanks @vvvvalvalval I'll give it another go. Thanks for all the details.

Having said that, you typically don't want to use scope-capture at all outside of the context of a REPL!

I agree that the REPL is the first and most important use case.

The two other use cases I see as important would be

simple mies style script/build.clj case (modify fn in source, save and compile, refresh browser, do test, look at captured scope)
figwheel which recompiles / loads new code (e.g. add spy to fn, save, browser recieves updated fns, do ui thing, look at captured scope)

vvvvalvalval commented 6 years ago

@olivergeorge Alright, I got a browser REPL + file watcher mostly working with the following script added to the mies template:

(require
  '[cljs.build.api :as b]
  '[cljs.repl :as repl]
  '[cljs.repl.browser :as browser])

(def opts
  {:main 'sccljs.core
   :output-to "out/sccljs.js"
   :output-dir "out"})

(println "Building...")

(b/build "src" opts)

(future
  (println "Watching in another thread...")
  (b/watch "src" opts))

(repl/repl (browser/repl-env)
  :output-dir "out")

Be careful, it interacts badly with compilation caching, which assumes that the compilation is stateless. Best to do a lein clean before you run the script.

vvvvalvalval commented 6 years ago

@olivergeorge I got it to run with Figwheel as well, it was actually easier as figwheel runs the REPL and file watcher in the same process by default. Be careful of what browser window your code is executing in though, or you may be missing some Execution Points (you can find out which window it is using (js/alert "where am I?"))

olivergeorge commented 6 years ago

I'm looking forward to putting it through it's paces. I wonder how I got into trouble. I'll keep an eye on the compilation cache and repl processes next time around.

vvvvalvalval commented 6 years ago

@olivergeorge:

regarding compilation pitfalls, see the new Wiki page: https://github.com/vvvvalvalval/scope-capture/wiki/Pitfalls-with-(browser-connected)-ClojureScript-REPLs
regarding the issue with loggers: refer to the new issue: https://github.com/vvvvalvalval/scope-capture/issues/15

Closing this issue.

vvvvalvalval commented 6 years ago

@olivergeorge Your initial problem with logs mixed with emmitted JS should be fixed by 0.1.3, can you try again? https://github.com/vvvvalvalval/scope-capture/releases/tag/v0.1.3

vvvvalvalval / scope-capture

ClojureScript: compile-time logs mixed with JS code in output #1