Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Spy logging interferes with compiled JS in CLJS #24

Open
mrrodriguez opened this issue Jun 11, 2018 · 9 comments
Open

Spy logging interferes with compiled JS in CLJS #24

mrrodriguez opened this issue Jun 11, 2018 · 9 comments

Comments

@mrrodriguez
Copy link

I still get logger output interleaved with the JS output that was discussed in #1
when using [vvvvalvalval/scope-capture "0.2.0"] in ClojureScript with Leiningen/cljs-build/figwheel setup.

This problem seems to come and go from project to project or release to release of scope-capture for me. I haven't been able to narrow it down to a basic new project to reproduce it. I think it may be something with the combination of the tools involved.

I'll add that I used to be able to use scope-capture with this same setup around the 2nd release. I am not sure I have enough details to be actionable here. I'm curious if anyone else is facing similar.

@vvvvalvalval
Copy link
Owner

@mrrodriguez I suspect this only happens when cold-compiling a codebase that already has spy statements in it, can you confirm?

@mrrodriguez
Copy link
Author

mrrodriguez commented Jun 14, 2018

@vvvvalvalval
The app can be running and then hot-reloaded and still have this problem. However, I think I have to do a page refresh for this bad cljs to be generated via the logger crossing into the same output stream.

If I add a
[sc.api] to a ns :require that already exists, put a (sc.api/spy :foo) anywhere, and let figwheel hot-reload - with no manual page refresh, I instead get a

"Could not analyze"

java.lang.NullPointerException: at line <line where I have the `sc.api/spy` call.

So either way, it won't work with a lein + figwheel setup.

My leiningen version is

Leiningen 2.8.1 on Java 1.8.0_112 Java HotSpot(TM) 64-Bit Server VM

and using Figwheel

[lein-figwheel "0.5.16"]
[figwheel-sidecar "0.5.16"]

The NPE from the analyzer is pretty hard to troubleshoot. I tried for a few hours one day and failed. I have to figure out how to recreate it with the Figwheel REPL analyzer pass and then walk through that.

If I'm in a Figwheel CLJS (via piggieback) REPL, I have tried

(require 'sc.api)
;;= nil
sc.api/spy
;;= #object[sc$api$spy]

Both of those work.

However, if I then do

(sc.api/spy :foo)

;; throws an error

----  Could not Analyze  <cljs form>   line:1  column:1  ----

   at line 1 <cljs repl>

  1  (sc.api/spy :foo)
     ^--- 

----  Analysis Error  ----
nil

Interestingly I can do:

(#'sc.api/spy nil nil :foo)

;;= returns the macroexpanded form

I'm not sure if the NPE problem, analysis error, and the problem with the logger printing to the same out stream as the cljs compiler are all related. All of these issues have been hard to troubleshoot so far.

This is actually happening to me in 2 separate CLJS projects too, so it isn't just something completely unique to one codebase. However, the lein + figwheel stack is the same. I've tried different recent versions of figwheel, and that doesn't change anything.

I've read the relevant chunks of the scope-capture codebase, and I don't see what would be wrong still though.

@nickstares
Copy link

I am also having this same issue, with the same figwheel and lein versions that @mrrodriguez is using.

@nickstares
Copy link

Any progress on this? Debugging the analyzer is a bit beyond my abilities, but happy to help with evidence collection etc.

@vvvvalvalval
Copy link
Owner

@nickstares yes I'd need a precise repro to make progress please - a minimal project reproducing the problem with the exact dependencies would be ideal.

@mrrodriguez
Copy link
Author

@vvvvalvalval I may try to get a reproducing case again today. I've had a hard time doing so before. When I make a small, dummy project, with a bunch of the same core dev dependencies, it hasn't happened. I have 2 "real" separate projects though, where it happens the same in each. I've been completely unable to use scope-capture in my CLJS-side due to that.
So since it doesn't happen easily in a repro-case, the problem becomes trying to have a clue what is happening in the analyzer to try to recreate it...
Hopefully I can figure something out. I know there isn't much for you to go on from this issue so far.

@nickstares
Copy link

nickstares commented Aug 3, 2018

I can reproduce this using figwheel template.

Once the app is up and running with cider and figwheel, All I have to do is add (sc.api/spy) to core.cljs, save the file, and figwheel will throw the error on reload.

I do notice that this doesn't happen when using only lein figwheel (without cider). So maybe it is an issue with figwheel-sidecar or piggieback?

See more info below.

I created the project with:
lein new figwheel scope-capture-demo

project.clj
(defproject scope-capture-demo "0.1.0-SNAPSHOT"
  :description "FIXME: write this!"
  :url "http://example.com/FIXME"
  :license {:name "Eclipse Public License"
            :url "http://www.eclipse.org/legal/epl-v10.html"}

  :min-lein-version "2.7.1"

  :dependencies [[org.clojure/clojure "1.9.0"]
                 [org.clojure/clojurescript "1.10.238"]
                 [org.clojure/core.async  "0.4.474"]]

  :plugins [[lein-figwheel "0.5.16"]
            [lein-cljsbuild "1.1.7" :exclusions [[org.clojure/clojure]]]]

  :source-paths ["src"]

  :cljsbuild {:builds
              [{:id "dev"
                :source-paths ["src"]
                :figwheel {:on-jsload "scope-capture-demo.core/on-js-reload"
                           :open-urls ["http://localhost:3449/index.html"]}
                :compiler {:main scope-capture-demo.core
                           :asset-path "js/compiled/out"
                           :output-to "resources/public/js/compiled/scope_capture_demo.js"
                           :output-dir "resources/public/js/compiled/out"
                           :source-map-timestamp true
                           :preloads [devtools.preload]}}
               {:id "min"
                :source-paths ["src"]
                :compiler {:output-to "resources/public/js/compiled/scope_capture_demo.js"
                           :main scope-capture-demo.core
                           :optimizations :advanced
                           :pretty-print false}}]}

  :figwheel {:css-dirs ["resources/public/css"]}


  :profiles {:dev {:dependencies [[binaryage/devtools "0.9.9"]
                                  [figwheel-sidecar "0.5.16"]
                                  [cider/piggieback "0.3.1"]]
                   :source-paths ["src" "dev"]
                   :repl-options {:nrepl-middleware [cider.piggieback/wrap-cljs-repl]}
                   ;; need to add the compliled assets to the :clean-targets
                   :clean-targets ^{:protect false} ["resources/public/js/compiled"
                                                     :target-path]}})
core.cljs:
(ns scope-capture-demo.core)

(require 'sci.api)

(defonce app-state (atom {:text "Hello world!"}))

(defn on-js-reload []
  (sc.api/spy)
  (prn @app-state))
profiles.clj:
{:user {:dependencies [[vvvvalvalval/scope-capture "0.3.1"]]
        :injections   [(require 'sc.api)]}}
stacktrace:
clojure.lang.ExceptionInfo:  at line 1 <cljs repl> {:file "<cljs repl>", :line 1, :column 1, :root-source-info {:source-type :fragment, :source-form (sc.api/spy)}, :tag :cljs/analysis-error}
	at clojure.core$ex_info.invokeStatic(core.clj:4739)
	at clojure.core$ex_info.invoke(core.clj:4739)
	at cljs.analyzer$error.invokeStatic(analyzer.cljc:697)
	at cljs.analyzer$error.invoke(analyzer.cljc:693)
	at cljs.analyzer$macroexpand_1.invokeStatic(analyzer.cljc:3342)
	at cljs.analyzer$macroexpand_1.invoke(analyzer.cljc:3338)
	at cljs.analyzer$analyze_seq.invokeStatic(analyzer.cljc:3375)
	at cljs.analyzer$analyze_seq.invoke(analyzer.cljc:3355)
	at cljs.analyzer$analyze_form.invokeStatic(analyzer.cljc:3545)
	at cljs.analyzer$analyze_form.invoke(analyzer.cljc:3541)
	at cljs.analyzer$analyze_STAR_.invokeStatic(analyzer.cljc:3595)
	at cljs.analyzer$analyze_STAR_.invoke(analyzer.cljc:3586)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3616)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3607)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3605)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze_let_binding_init.invokeStatic(analyzer.cljc:1870)
	at cljs.analyzer$analyze_let_binding_init.invoke(analyzer.cljc:1868)
	at cljs.analyzer$analyze_let_bindings_STAR_.invokeStatic(analyzer.cljc:1890)
	at cljs.analyzer$analyze_let_bindings_STAR_.invoke(analyzer.cljc:1879)
	at cljs.analyzer$analyze_let_bindings.invokeStatic(analyzer.cljc:1921)
	at cljs.analyzer$analyze_let_bindings.invoke(analyzer.cljc:1920)
	at cljs.analyzer$analyze_let.invokeStatic(analyzer.cljc:1936)
	at cljs.analyzer$analyze_let.invoke(analyzer.cljc:1931)
	at cljs.analyzer$fn__1840.invokeStatic(analyzer.cljc:1957)
	at cljs.analyzer$fn__1840.invoke(analyzer.cljc:1955)
	at clojure.lang.MultiFn.invoke(MultiFn.java:251)
	at cljs.analyzer$analyze_seq_STAR_.invokeStatic(analyzer.cljc:3348)
	at cljs.analyzer$analyze_seq_STAR_.invoke(analyzer.cljc:3346)
	at cljs.analyzer$analyze_seq_STAR__wrap.invokeStatic(analyzer.cljc:3353)
	at cljs.analyzer$analyze_seq_STAR__wrap.invoke(analyzer.cljc:3351)
	at cljs.analyzer$analyze_seq.invokeStatic(analyzer.cljc:3377)
	at cljs.analyzer$analyze_seq.invoke(analyzer.cljc:3355)
	at cljs.analyzer$analyze_form.invokeStatic(analyzer.cljc:3545)
	at cljs.analyzer$analyze_form.invoke(analyzer.cljc:3541)
	at cljs.analyzer$analyze_STAR_.invokeStatic(analyzer.cljc:3595)
	at cljs.analyzer$analyze_STAR_.invoke(analyzer.cljc:3586)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3616)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze_seq.invokeStatic(analyzer.cljc:3378)
	at cljs.analyzer$analyze_seq.invoke(analyzer.cljc:3355)
	at cljs.analyzer$analyze_form.invokeStatic(analyzer.cljc:3545)
	at cljs.analyzer$analyze_form.invoke(analyzer.cljc:3541)
	at cljs.analyzer$analyze_STAR_.invokeStatic(analyzer.cljc:3595)
	at cljs.analyzer$analyze_STAR_.invoke(analyzer.cljc:3586)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3616)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3607)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3605)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$parse_invoke_STAR_$ana_expr__2332.invoke(analyzer.cljc:3154)
	at clojure.core$map$fn__5587.invoke(core.clj:2747)
	at clojure.lang.LazySeq.sval(LazySeq.java:40)
	at clojure.lang.LazySeq.seq(LazySeq.java:49)
	at clojure.lang.RT.seq(RT.java:528)
	at clojure.lang.LazilyPersistentVector.create(LazilyPersistentVector.java:44)
	at clojure.core$vec.invokeStatic(core.clj:377)
	at clojure.core$vec.invoke(core.clj:367)
	at cljs.analyzer$parse_invoke_STAR_.invokeStatic(analyzer.cljc:3156)
	at cljs.analyzer$parse_invoke_STAR_.invoke(analyzer.cljc:3103)
	at cljs.analyzer$parse_invoke.invokeStatic(analyzer.cljc:3161)
	at cljs.analyzer$parse_invoke.invoke(analyzer.cljc:3159)
	at cljs.analyzer$analyze_seq_STAR_.invokeStatic(analyzer.cljc:3349)
	at cljs.analyzer$analyze_seq_STAR_.invoke(analyzer.cljc:3346)
	at cljs.analyzer$analyze_seq_STAR__wrap.invokeStatic(analyzer.cljc:3353)
	at cljs.analyzer$analyze_seq_STAR__wrap.invoke(analyzer.cljc:3351)
	at cljs.analyzer$analyze_seq.invokeStatic(analyzer.cljc:3377)
	at cljs.analyzer$analyze_seq.invoke(analyzer.cljc:3355)
	at cljs.analyzer$analyze_form.invokeStatic(analyzer.cljc:3545)
	at cljs.analyzer$analyze_form.invoke(analyzer.cljc:3541)
	at cljs.analyzer$analyze_STAR_.invokeStatic(analyzer.cljc:3595)
	at cljs.analyzer$analyze_STAR_.invoke(analyzer.cljc:3586)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3616)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3607)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3605)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$fn__1821.invokeStatic(analyzer.cljc:1849)
	at cljs.analyzer$fn__1821.invoke(analyzer.cljc:1845)
	at clojure.lang.MultiFn.invoke(MultiFn.java:251)
	at cljs.analyzer$analyze_seq_STAR_.invokeStatic(analyzer.cljc:3348)
	at cljs.analyzer$analyze_seq_STAR_.invoke(analyzer.cljc:3346)
	at cljs.analyzer$analyze_seq_STAR__wrap.invokeStatic(analyzer.cljc:3353)
	at cljs.analyzer$analyze_seq_STAR__wrap.invoke(analyzer.cljc:3351)
	at cljs.analyzer$analyze_seq.invokeStatic(analyzer.cljc:3377)
	at cljs.analyzer$analyze_seq.invoke(analyzer.cljc:3355)
	at cljs.analyzer$analyze_form.invokeStatic(analyzer.cljc:3545)
	at cljs.analyzer$analyze_form.invoke(analyzer.cljc:3541)
	at cljs.analyzer$analyze_STAR_.invokeStatic(analyzer.cljc:3595)
	at cljs.analyzer$analyze_STAR_.invoke(analyzer.cljc:3586)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3616)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3607)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3605)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$fn__1692$fn__1716.invoke(analyzer.cljc:1448)
	at cljs.analyzer$fn__1692.invokeStatic(analyzer.cljc:1448)
	at cljs.analyzer$fn__1692.invoke(analyzer.cljc:1396)
	at clojure.lang.MultiFn.invoke(MultiFn.java:251)
	at cljs.analyzer$analyze_seq_STAR_.invokeStatic(analyzer.cljc:3348)
	at cljs.analyzer$analyze_seq_STAR_.invoke(analyzer.cljc:3346)
	at cljs.analyzer$analyze_seq_STAR__wrap.invokeStatic(analyzer.cljc:3353)
	at cljs.analyzer$analyze_seq_STAR__wrap.invoke(analyzer.cljc:3351)
	at cljs.analyzer$analyze_seq.invokeStatic(analyzer.cljc:3377)
	at cljs.analyzer$analyze_seq.invoke(analyzer.cljc:3355)
	at cljs.analyzer$analyze_form.invokeStatic(analyzer.cljc:3545)
	at cljs.analyzer$analyze_form.invoke(analyzer.cljc:3541)
	at cljs.analyzer$analyze_STAR_.invokeStatic(analyzer.cljc:3595)
	at cljs.analyzer$analyze_STAR_.invoke(analyzer.cljc:3586)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3616)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.repl$evaluate_form$__GT_ast__6355.invoke(repl.cljc:502)
	at cljs.repl$evaluate_form.invokeStatic(repl.cljc:504)
	at cljs.repl$evaluate_form.invoke(repl.cljc:484)
	at cider.piggieback$eval_cljs.invokeStatic(piggieback.clj:147)
	at cider.piggieback$eval_cljs.invoke(piggieback.clj:146)
	at cider.piggieback$do_eval.invokeStatic(piggieback.clj:172)
	at cider.piggieback$do_eval.invoke(piggieback.clj:155)
	at cider.piggieback$evaluate.invokeStatic(piggieback.clj:195)
	at cider.piggieback$evaluate.invoke(piggieback.clj:193)
	at clojure.lang.Var.invoke(Var.java:381)
	at cider.piggieback$wrap_cljs_repl$fn__21728$fn__21730$fn__21731.invoke(piggieback.clj:224)
	at cider.piggieback$enqueue$fn__21708.invoke(piggieback.clj:129)
	at clojure.tools.nrepl.middleware.interruptible_eval$run_next$fn__18135.invoke(interruptible_eval.clj:190)
	at clojure.lang.AFn.run(AFn.java:22)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.NullPointerException
	at clojure.core$deref_future.invokeStatic(core.clj:2292)
	at clojure.core$deref.invokeStatic(core.clj:2312)
	at clojure.core$deref.invoke(core.clj:2298)
	at cider.nrepl.middleware.out$print_stream$fn__27410.invoke(out.clj:85)
	at cider.nrepl.middleware.out.proxy$java.io.OutputStream$ff19274a.write(Unknown Source)
	at java.io.PrintStream.write(PrintStream.java:480)
	at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
	at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:291)
	at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:104)
	at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:185)
	at java.io.PrintStream.write(PrintStream.java:527)
	at java.io.PrintStream.print(PrintStream.java:669)
	at java.io.PrintStream.println(PrintStream.java:806)
	at sc.api.logging$portable_println.invokeStatic(logging.cljc:17)
	at sc.api.logging$portable_println.invoke(logging.cljc:15)
	at sc.api.logging$log_cs.invokeStatic(logging.cljc:22)
	at sc.api.logging$log_cs.invoke(logging.cljc:20)
	at sc.api.logging$eval27016$fn__27017.invoke(logging.cljc:31)
	at sc.api.logging$register_cs_logger$fn__27010.invoke(logging.cljc:8)
	at clojure.lang.MultiFn.invoke(MultiFn.java:233)
	at sc.impl$spy_emit.invokeStatic(impl.cljc:219)
	at sc.impl$spy_emit.invoke(impl.cljc:205)
	at sc.api$spy_emit.invokeStatic(api.cljc:11)
	at sc.api$spy_emit.invoke(api.cljc:7)
	at sc.api$spy.invokeStatic(api.cljc:75)
	at sc.api$spy.invoke(api.cljc:13)
	at clojure.lang.AFn.applyToHelper(AFn.java:156)
	at clojure.lang.AFn.applyTo(AFn.java:144)
	at clojure.core$apply.invokeStatic(core.clj:661)
	at clojure.core$apply.invoke(core.clj:652)
	at cljs.analyzer$macroexpand_1_STAR_$fn__2369.invoke(analyzer.cljc:3295)
	at cljs.analyzer$macroexpand_1_STAR_.invokeStatic(analyzer.cljc:3294)
	at cljs.analyzer$macroexpand_1_STAR_.invoke(analyzer.cljc:3281)
	... 129 more
clojure.lang.ExceptionInfo:  at line 2 <cljs repl> {:file "<cljs repl>", :line 2, :column 3, :root-source-info {:source-type :fragment, :source-form (defn on-js-reload [] (sc.api/spy))}, :tag :cljs/analysis-error}
	at clojure.core$ex_info.invokeStatic(core.clj:4739)
	at clojure.core$ex_info.invoke(core.clj:4739)
	at cljs.analyzer$error.invokeStatic(analyzer.cljc:697)
	at cljs.analyzer$error.invoke(analyzer.cljc:693)
	at cljs.analyzer$macroexpand_1.invokeStatic(analyzer.cljc:3342)
	at cljs.analyzer$macroexpand_1.invoke(analyzer.cljc:3338)
	at cljs.analyzer$analyze_seq.invokeStatic(analyzer.cljc:3375)
	at cljs.analyzer$analyze_seq.invoke(analyzer.cljc:3355)
	at cljs.analyzer$analyze_form.invokeStatic(analyzer.cljc:3545)
	at cljs.analyzer$analyze_form.invoke(analyzer.cljc:3541)
	at cljs.analyzer$analyze_STAR_.invokeStatic(analyzer.cljc:3595)
	at cljs.analyzer$analyze_STAR_.invoke(analyzer.cljc:3586)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3616)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3607)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3605)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$fn__1821.invokeStatic(analyzer.cljc:1849)
	at cljs.analyzer$fn__1821.invoke(analyzer.cljc:1845)
	at clojure.lang.MultiFn.invoke(MultiFn.java:251)
	at cljs.analyzer$analyze_seq_STAR_.invokeStatic(analyzer.cljc:3348)
	at cljs.analyzer$analyze_seq_STAR_.invoke(analyzer.cljc:3346)
	at cljs.analyzer$analyze_seq_STAR__wrap.invokeStatic(analyzer.cljc:3353)
	at cljs.analyzer$analyze_seq_STAR__wrap.invoke(analyzer.cljc:3351)
	at cljs.analyzer$analyze_seq.invokeStatic(analyzer.cljc:3377)
	at cljs.analyzer$analyze_seq.invoke(analyzer.cljc:3355)
	at cljs.analyzer$analyze_form.invokeStatic(analyzer.cljc:3545)
	at cljs.analyzer$analyze_form.invoke(analyzer.cljc:3541)
	at cljs.analyzer$analyze_STAR_.invokeStatic(analyzer.cljc:3595)
	at cljs.analyzer$analyze_STAR_.invoke(analyzer.cljc:3586)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3616)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3607)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3605)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze_fn_method_body.invokeStatic(analyzer.cljc:1664)
	at cljs.analyzer$analyze_fn_method_body.invoke(analyzer.cljc:1662)
	at cljs.analyzer$analyze_fn_method.invokeStatic(analyzer.cljc:1685)
	at cljs.analyzer$analyze_fn_method.invoke(analyzer.cljc:1666)
	at cljs.analyzer$analyze_fn_methods_pass2_STAR_$fn__1778.invoke(analyzer.cljc:1716)
	at clojure.core$map$fn__5587.invoke(core.clj:2747)
	at clojure.lang.LazySeq.sval(LazySeq.java:40)
	at clojure.lang.LazySeq.seq(LazySeq.java:49)
	at clojure.lang.RT.seq(RT.java:528)
	at clojure.core$seq__5124.invokeStatic(core.clj:137)
	at clojure.core$dorun.invokeStatic(core.clj:3125)
	at clojure.core$doall.invokeStatic(core.clj:3140)
	at clojure.core$doall.invoke(core.clj:3140)
	at cljs.analyzer$analyze_fn_methods_pass2_STAR_.invokeStatic(analyzer.cljc:1716)
	at cljs.analyzer$analyze_fn_methods_pass2_STAR_.invoke(analyzer.cljc:1715)
	at cljs.analyzer$analyze_fn_methods_pass2.invokeStatic(analyzer.cljc:1719)
	at cljs.analyzer$analyze_fn_methods_pass2.invoke(analyzer.cljc:1718)
	at cljs.analyzer$fn__1784$fn__1789.invoke(analyzer.cljc:1764)
	at cljs.analyzer$fn__1784.invokeStatic(analyzer.cljc:1764)
	at cljs.analyzer$fn__1784.invoke(analyzer.cljc:1721)
	at clojure.lang.MultiFn.invoke(MultiFn.java:251)
	at cljs.analyzer$analyze_seq_STAR_.invokeStatic(analyzer.cljc:3348)
	at cljs.analyzer$analyze_seq_STAR_.invoke(analyzer.cljc:3346)
	at cljs.analyzer$analyze_seq_STAR__wrap.invokeStatic(analyzer.cljc:3353)
	at cljs.analyzer$analyze_seq_STAR__wrap.invoke(analyzer.cljc:3351)
	at cljs.analyzer$analyze_seq.invokeStatic(analyzer.cljc:3377)
	at cljs.analyzer$analyze_seq.invoke(analyzer.cljc:3355)
	at cljs.analyzer$analyze_form.invokeStatic(analyzer.cljc:3545)
	at cljs.analyzer$analyze_form.invoke(analyzer.cljc:3541)
	at cljs.analyzer$analyze_STAR_.invokeStatic(analyzer.cljc:3595)
	at cljs.analyzer$analyze_STAR_.invoke(analyzer.cljc:3586)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3616)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze_seq.invokeStatic(analyzer.cljc:3378)
	at cljs.analyzer$analyze_seq.invoke(analyzer.cljc:3355)
	at cljs.analyzer$analyze_form.invokeStatic(analyzer.cljc:3545)
	at cljs.analyzer$analyze_form.invoke(analyzer.cljc:3541)
	at cljs.analyzer$analyze_STAR_.invokeStatic(analyzer.cljc:3595)
	at cljs.analyzer$analyze_STAR_.invoke(analyzer.cljc:3586)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3616)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3607)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$fn__1733$fn__1736.invoke(analyzer.cljc:1541)
	at cljs.analyzer$fn__1733.invokeStatic(analyzer.cljc:1539)
	at cljs.analyzer$fn__1733.invoke(analyzer.cljc:1473)
	at clojure.lang.MultiFn.invoke(MultiFn.java:251)
	at cljs.analyzer$analyze_seq_STAR_.invokeStatic(analyzer.cljc:3348)
	at cljs.analyzer$analyze_seq_STAR_.invoke(analyzer.cljc:3346)
	at cljs.analyzer$analyze_seq_STAR__wrap.invokeStatic(analyzer.cljc:3353)
	at cljs.analyzer$analyze_seq_STAR__wrap.invoke(analyzer.cljc:3351)
	at cljs.analyzer$analyze_seq.invokeStatic(analyzer.cljc:3377)
	at cljs.analyzer$analyze_seq.invoke(analyzer.cljc:3355)
	at cljs.analyzer$analyze_form.invokeStatic(analyzer.cljc:3545)
	at cljs.analyzer$analyze_form.invoke(analyzer.cljc:3541)
	at cljs.analyzer$analyze_STAR_.invokeStatic(analyzer.cljc:3595)
	at cljs.analyzer$analyze_STAR_.invoke(analyzer.cljc:3586)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3616)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze_seq.invokeStatic(analyzer.cljc:3378)
	at cljs.analyzer$analyze_seq.invoke(analyzer.cljc:3355)
	at cljs.analyzer$analyze_form.invokeStatic(analyzer.cljc:3545)
	at cljs.analyzer$analyze_form.invoke(analyzer.cljc:3541)
	at cljs.analyzer$analyze_STAR_.invokeStatic(analyzer.cljc:3595)
	at cljs.analyzer$analyze_STAR_.invoke(analyzer.cljc:3586)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3616)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3607)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3605)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze_let_binding_init.invokeStatic(analyzer.cljc:1870)
	at cljs.analyzer$analyze_let_binding_init.invoke(analyzer.cljc:1868)
	at cljs.analyzer$analyze_let_bindings_STAR_.invokeStatic(analyzer.cljc:1890)
	at cljs.analyzer$analyze_let_bindings_STAR_.invoke(analyzer.cljc:1879)
	at cljs.analyzer$analyze_let_bindings.invokeStatic(analyzer.cljc:1921)
	at cljs.analyzer$analyze_let_bindings.invoke(analyzer.cljc:1920)
	at cljs.analyzer$analyze_let.invokeStatic(analyzer.cljc:1936)
	at cljs.analyzer$analyze_let.invoke(analyzer.cljc:1931)
	at cljs.analyzer$fn__1840.invokeStatic(analyzer.cljc:1957)
	at cljs.analyzer$fn__1840.invoke(analyzer.cljc:1955)
	at clojure.lang.MultiFn.invoke(MultiFn.java:251)
	at cljs.analyzer$analyze_seq_STAR_.invokeStatic(analyzer.cljc:3348)
	at cljs.analyzer$analyze_seq_STAR_.invoke(analyzer.cljc:3346)
	at cljs.analyzer$analyze_seq_STAR__wrap.invokeStatic(analyzer.cljc:3353)
	at cljs.analyzer$analyze_seq_STAR__wrap.invoke(analyzer.cljc:3351)
	at cljs.analyzer$analyze_seq.invokeStatic(analyzer.cljc:3377)
	at cljs.analyzer$analyze_seq.invoke(analyzer.cljc:3355)
	at cljs.analyzer$analyze_form.invokeStatic(analyzer.cljc:3545)
	at cljs.analyzer$analyze_form.invoke(analyzer.cljc:3541)
	at cljs.analyzer$analyze_STAR_.invokeStatic(analyzer.cljc:3595)
	at cljs.analyzer$analyze_STAR_.invoke(analyzer.cljc:3586)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3616)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze_seq.invokeStatic(analyzer.cljc:3378)
	at cljs.analyzer$analyze_seq.invoke(analyzer.cljc:3355)
	at cljs.analyzer$analyze_form.invokeStatic(analyzer.cljc:3545)
	at cljs.analyzer$analyze_form.invoke(analyzer.cljc:3541)
	at cljs.analyzer$analyze_STAR_.invokeStatic(analyzer.cljc:3595)
	at cljs.analyzer$analyze_STAR_.invoke(analyzer.cljc:3586)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3616)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3607)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3605)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$parse_invoke_STAR_$ana_expr__2332.invoke(analyzer.cljc:3154)
	at clojure.core$map$fn__5587.invoke(core.clj:2747)
	at clojure.lang.LazySeq.sval(LazySeq.java:40)
	at clojure.lang.LazySeq.seq(LazySeq.java:49)
	at clojure.lang.RT.seq(RT.java:528)
	at clojure.lang.LazilyPersistentVector.create(LazilyPersistentVector.java:44)
	at clojure.core$vec.invokeStatic(core.clj:377)
	at clojure.core$vec.invoke(core.clj:367)
	at cljs.analyzer$parse_invoke_STAR_.invokeStatic(analyzer.cljc:3156)
	at cljs.analyzer$parse_invoke_STAR_.invoke(analyzer.cljc:3103)
	at cljs.analyzer$parse_invoke.invokeStatic(analyzer.cljc:3161)
	at cljs.analyzer$parse_invoke.invoke(analyzer.cljc:3159)
	at cljs.analyzer$analyze_seq_STAR_.invokeStatic(analyzer.cljc:3349)
	at cljs.analyzer$analyze_seq_STAR_.invoke(analyzer.cljc:3346)
	at cljs.analyzer$analyze_seq_STAR__wrap.invokeStatic(analyzer.cljc:3353)
	at cljs.analyzer$analyze_seq_STAR__wrap.invoke(analyzer.cljc:3351)
	at cljs.analyzer$analyze_seq.invokeStatic(analyzer.cljc:3377)
	at cljs.analyzer$analyze_seq.invoke(analyzer.cljc:3355)
	at cljs.analyzer$analyze_form.invokeStatic(analyzer.cljc:3545)
	at cljs.analyzer$analyze_form.invoke(analyzer.cljc:3541)
	at cljs.analyzer$analyze_STAR_.invokeStatic(analyzer.cljc:3595)
	at cljs.analyzer$analyze_STAR_.invoke(analyzer.cljc:3586)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3616)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3607)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3605)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$fn__1821.invokeStatic(analyzer.cljc:1849)
	at cljs.analyzer$fn__1821.invoke(analyzer.cljc:1845)
	at clojure.lang.MultiFn.invoke(MultiFn.java:251)
	at cljs.analyzer$analyze_seq_STAR_.invokeStatic(analyzer.cljc:3348)
	at cljs.analyzer$analyze_seq_STAR_.invoke(analyzer.cljc:3346)
	at cljs.analyzer$analyze_seq_STAR__wrap.invokeStatic(analyzer.cljc:3353)
	at cljs.analyzer$analyze_seq_STAR__wrap.invoke(analyzer.cljc:3351)
	at cljs.analyzer$analyze_seq.invokeStatic(analyzer.cljc:3377)
	at cljs.analyzer$analyze_seq.invoke(analyzer.cljc:3355)
	at cljs.analyzer$analyze_form.invokeStatic(analyzer.cljc:3545)
	at cljs.analyzer$analyze_form.invoke(analyzer.cljc:3541)
	at cljs.analyzer$analyze_STAR_.invokeStatic(analyzer.cljc:3595)
	at cljs.analyzer$analyze_STAR_.invoke(analyzer.cljc:3586)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3616)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3607)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3605)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.analyzer$fn__1692$fn__1716.invoke(analyzer.cljc:1448)
	at cljs.analyzer$fn__1692.invokeStatic(analyzer.cljc:1448)
	at cljs.analyzer$fn__1692.invoke(analyzer.cljc:1396)
	at clojure.lang.MultiFn.invoke(MultiFn.java:251)
	at cljs.analyzer$analyze_seq_STAR_.invokeStatic(analyzer.cljc:3348)
	at cljs.analyzer$analyze_seq_STAR_.invoke(analyzer.cljc:3346)
	at cljs.analyzer$analyze_seq_STAR__wrap.invokeStatic(analyzer.cljc:3353)
	at cljs.analyzer$analyze_seq_STAR__wrap.invoke(analyzer.cljc:3351)
	at cljs.analyzer$analyze_seq.invokeStatic(analyzer.cljc:3377)
	at cljs.analyzer$analyze_seq.invoke(analyzer.cljc:3355)
	at cljs.analyzer$analyze_form.invokeStatic(analyzer.cljc:3545)
	at cljs.analyzer$analyze_form.invoke(analyzer.cljc:3541)
	at cljs.analyzer$analyze_STAR_.invokeStatic(analyzer.cljc:3595)
	at cljs.analyzer$analyze_STAR_.invoke(analyzer.cljc:3586)
	at cljs.analyzer$analyze.invokeStatic(analyzer.cljc:3616)
	at cljs.analyzer$analyze.invoke(analyzer.cljc:3598)
	at cljs.repl$evaluate_form$__GT_ast__6355.invoke(repl.cljc:502)
	at cljs.repl$evaluate_form.invokeStatic(repl.cljc:504)
	at cljs.repl$evaluate_form.invoke(repl.cljc:484)
	at cider.piggieback$eval_cljs.invokeStatic(piggieback.clj:147)
	at cider.piggieback$eval_cljs.invoke(piggieback.clj:146)
	at cider.piggieback$do_eval.invokeStatic(piggieback.clj:172)
	at cider.piggieback$do_eval.invoke(piggieback.clj:155)
	at cider.piggieback$evaluate.invokeStatic(piggieback.clj:195)
	at cider.piggieback$evaluate.invoke(piggieback.clj:193)
	at clojure.lang.Var.invoke(Var.java:381)
	at cider.piggieback$wrap_cljs_repl$fn__21728$fn__21730$fn__21731.invoke(piggieback.clj:224)
	at cider.piggieback$enqueue$fn__21708.invoke(piggieback.clj:129)
	at clojure.tools.nrepl.middleware.interruptible_eval$run_next$fn__18135.invoke(interruptible_eval.clj:190)
	at clojure.lang.AFn.run(AFn.java:22)
	at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
	at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
	at java.lang.Thread.run(Thread.java:748)
Caused by: java.lang.NullPointerException
	at clojure.core$deref_future.invokeStatic(core.clj:2292)
	at clojure.core$deref.invokeStatic(core.clj:2312)
	at clojure.core$deref.invoke(core.clj:2298)
	at cider.nrepl.middleware.out$print_stream$fn__27410.invoke(out.clj:85)
	at cider.nrepl.middleware.out.proxy$java.io.OutputStream$ff19274a.write(Unknown Source)
	at java.io.PrintStream.write(PrintStream.java:480)
	at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
	at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:291)
	at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:104)
	at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:185)
	at java.io.PrintStream.write(PrintStream.java:527)
	at java.io.PrintStream.print(PrintStream.java:669)
	at java.io.PrintStream.println(PrintStream.java:806)
	at sc.api.logging$portable_println.invokeStatic(logging.cljc:17)
	at sc.api.logging$portable_println.invoke(logging.cljc:15)
	at sc.api.logging$log_cs.invokeStatic(logging.cljc:22)
	at sc.api.logging$log_cs.invoke(logging.cljc:20)
	at sc.api.logging$eval27016$fn__27017.invoke(logging.cljc:31)
	at sc.api.logging$register_cs_logger$fn__27010.invoke(logging.cljc:8)
	at clojure.lang.MultiFn.invoke(MultiFn.java:233)
	at sc.impl$spy_emit.invokeStatic(impl.cljc:219)
	at sc.impl$spy_emit.invoke(impl.cljc:205)
	at sc.api$spy_emit.invokeStatic(api.cljc:11)
	at sc.api$spy_emit.invoke(api.cljc:7)
	at sc.api$spy.invokeStatic(api.cljc:75)
	at sc.api$spy.invoke(api.cljc:13)
	at clojure.lang.AFn.applyToHelper(AFn.java:156)
	at clojure.lang.AFn.applyTo(AFn.java:144)
	at clojure.core$apply.invokeStatic(core.clj:661)
	at clojure.core$apply.invoke(core.clj:652)
	at cljs.analyzer$macroexpand_1_STAR_$fn__2369.invoke(analyzer.cljc:3295)
	at cljs.analyzer$macroexpand_1_STAR_.invokeStatic(analyzer.cljc:3294)
	at cljs.analyzer$macroexpand_1_STAR_.invoke(analyzer.cljc:3281)
	... 219 more

@mrrodriguez
Copy link
Author

mrrodriguez commented Aug 3, 2018

@vvvvalvalval @nickstares I was able to recreate it in a similar way and agree that the problem only seems to be with the figwheel-sidecare + piggieback + cider setup.

I'm thinking cider doesn't matter, it's the other 2 involved. So will see about being able to narrow it down more.

EDIT:

I looked a bit more at this and now I'm actually suspicious of cider nrepl middleware. It is in the stacktrace posted above, but I'll show the relevant lines

Caused by: java.lang.NullPointerException
	at clojure.core$deref_future.invokeStatic(core.clj:2292)
	at clojure.core$deref.invokeStatic(core.clj:2312)
	at clojure.core$deref.invoke(core.clj:2298)
	at cider.nrepl.middleware.out$print_stream$fn__27410.invoke(out.clj:85)
	at cider.nrepl.middleware.out.proxy$java.io.OutputStream$ff19274a.write(Unknown Source)
	at java.io.PrintStream.write(PrintStream.java:480)
	at sun.nio.cs.StreamEncoder.writeBytes(StreamEncoder.java:221)
	at sun.nio.cs.StreamEncoder.implFlushBuffer(StreamEncoder.java:291)
	at sun.nio.cs.StreamEncoder.flushBuffer(StreamEncoder.java:104)
	at java.io.OutputStreamWriter.flushBuffer(OutputStreamWriter.java:185)
	at java.io.PrintStream.write(PrintStream.java:527)
	at java.io.PrintStream.print(PrintStream.java:669)
	at java.io.PrintStream.println(PrintStream.java:806)
	at sc.api.logging$portable_println.invokeStatic(logging.cljc:17)
	at sc.api.logging$portable_println.invoke(logging.cljc:15)

sc.api.logging/portable-println is being called on the :clj side. It looks like there may be interference with the cider.nrepl.middleware.out/print-stream middleware.

Looking at the relevant Cider code:

(defn print-stream
  "Returns a PrintStream suitable for binding as java.lang.System/out
  or java.lang.System/err. All operations are forwarded to all output
  bindings in the sessions of messages.
  type is either :out or :err."
  [type]
  (let [printer (case type
                  :out '*out*
                  :err '*err*)]
    (PrintStream. (proxy [OutputStream] []
                    (close [] (.flush ^OutputStream this))
                    (write
                      ([int-or-bytes]
                       (.write @(resolve printer)
                               (if (instance? Integer int-or-bytes)
                                 int-or-bytes
                                 (String. int-or-bytes))))
                      ([bytes ^Integer off ^Integer len]
                       (let [byte-range (byte-array
                                         (take len (drop off bytes)))]
                        (.write @(resolve printer) (String. byte-range))))) <--- ERROR HAPPENS HERE
                    (flush []
                      (.flush @(resolve printer))))
                  true)))

It looks like the call to (resolve printer) returns nil. I believe that this is (resolve *out*).
I believe the reason it returns nil is probably because the ns bound is cljs.user and resolution of things may be a bit different.

EDIT (2):

I played around with this and I'm now convinced the cider-nrepl middleware above is the problem. In general, I think it is a tricky/error-prone situation in CLJS to have macros that try to resolve vars at macroexpansion time, at least with figwheel reloading I believe.

So the function sc.api.logging/portable-println was introduced in f7a5859 to try deal with where the macroexpansion time code sites were logged to.
This works in basic cases because the reference is (.println System/out ^String s). However, with cider-nrepl with-out middleware enabled, System/out is apparently masked behind a proxy. That proxy does a (resolve *out*), which can end up happening during CLJS analysis macroexpansion time. This breaks with a NPE.

A workaround for this issue is to put something like this:

(sc.api.logging/register-cs-logger
 :sc.api.logging/log-spy-cs
 (fn [cs]
   nil))

NOTE: This is really the same workaround (in concept) that was around prior to sc.api.logging/portable-println being added I believe, see #1 . The way there also should work for the same reasons.

In your user.clj or somewhere you know will get loaded after sc.api and before the CLJS compilation.

With this, there is no initial code site details logged anywhere. However, when execution points are logged later, they are logged at runtime to the CLJS out stream you'd expect, so you can still find where the execution points are to effectively use scope-capture.

So now the question is, could/should scope-capture try to do the initial macroexpansion-time code site logging in a way that is more robust to something like this middleware?

@SevereOverfl0w
Copy link

The cljs compiler uses *out* for emitting strings. If you instead defaulted to *err*, then it wouldn't conflict.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

4 participants