Shadow-cljs: Watch process nREPL starts hanging all requests after namespaced-require

[tekacs]

I'm running 2.11.4.

I'm experiencing something similar to #750 quite frequently, where on the REPL side what I'm seeing to start this issue off is:

[2020-09-22 13:13:45.007 - WARNING] :shadow.cljs.devtools.server.util/handle-ex - {:msg {:op :cljs-compile, :input {:code "(require '[common.types :as ty])", :ns cljs.user, :repl true}, :include-init true, :call-id 0, :from 128}}
AssertionError Assert failed: (symbol? repl-ns)
        shadow.build.resolve/resolve-repl (resolve.clj:639)
        shadow.build.resolve/resolve-repl 

I'm using the :browser target and I'm not 100% sure that this is the same issue, but it manifests in a similar way (builds work fine, nREPL is dead, causing timeouts, creating a new connection by refreshing the browser doesn't help, irrecoverable, have to restart the watch process).

I'm using Cursive as a client to the nREPL socket created during watch.

The issue appears to be reproducible for me like this:

; clj -A:various:aliases watch app
; Load browser
; Connect to nREPL socket using Cursive

(shadow/repl :app)
; To quit, type: :cljs/quit
; => [:selected :app]

(require '[common.types :as ty])
; nil

; Make any change to common.types, causing a hot reload

; This next line isn't necessary, but demonstrates that the alias is no longer present.
(ty/def ::x 1)
; ------ WARNING - :undeclared-ns ------------------------------------------------
;  Resource: <eval>:1:2
;  No such namespace: ty, could not locate ty.cljs, ty.cljc, or JavaScript source providing "ty"
; --------------------------------------------------------------------------------
; 
; ------ WARNING - :undeclared-var -----------------------------------------------
;  Resource: <eval>:1:2
;  Use of undeclared Var ty/def
; --------------------------------------------------------------------------------

(require '[common.types :as ty])
; error above appears in `clj watch` console
; hangs until time out
; all future evaluations time out, even just `1` or `:cljs/quit`
; the connection never dies

Everything behaves just fine if I instead simply type out the full (common.types/some-fn) every time I want to use it, even across hot reloads.

[thheller]

Please confirm that you actually have thheller/shadow-cljs {:mvn/version "2.11.4"} in your deps.edn? Unfortunately way too many people report being on some version but only having that version in package.json but not updated accordingly in deps.edn or project.clj.

I cannot reproduce this but it is sort of expected that the hot-reload may interfere with the REPL.

When a watch recompile happens it clears the namespace that was changed and compiles it. As this is supposed to reflect the state of the file all "temporary" modifications that may have been done to the ns previously from the REPL (eg. added require alias) will be gone because the file does not reflect that state. Otherwise you may end up states where you restart the watch later at some point and the build doesn't work anymore because it was depending on some intermediate REPL modifications.

[tekacs]

Yes, I have it in both package.json /and/ deps.edn.

Clearing the namespace makes total sense and is what I expect, but the /hang/ specifically (after attempting to require a namespace that was previously aliased) is the question... and presumably not expected behaviour.

[hjrnunes]

Hi,

I have the same issue, also on 2.11.4

project.clj and package.json have that same version.

Not sure what I can add. I see exactly what @tekacs described. Let me know if there's anything specific you'd like to see.

[pavel-klavik]

Hi,

happens to me as well, the same issue still in 2.11.8. I get the following in Cursive nREPL:

(clojure.string/join ["ab" "cd"])
Timeout while waiting for result.

And Shadow-cljs outputs this into console:

[2020-12-16 16:07:58.625 - WARNING] :shadow.cljs.devtools.server.util/handle-ex - {:msg {:op :cljs-load-sources, :sources [[:shadow.build.classpath/resource "cljs/spec/gen/alpha.cljs"] [:shadow.build.classpath/resource "cljs/spec/alpha.cljs"] [:shadow.build.classpath/resource "cljs/repl.cljs"] [:shadow.cljs.repl/resource "cljs/user.cljs"]], :call-id 6, :from 71}}
ExceptionInfo no output for id: [:shadow.cljs.repl/resource "cljs/user.cljs"] {:resource-id [:shadow.cljs.repl/resource "cljs/user.cljs"]}
        shadow.build.data/get-output! (data.clj:197)
        shadow.build.data/get-output! (data.clj:193)
        shadow.cljs.devtools.server.worker.impl/fn--15184/fn--15187 (impl.clj:813)
        clojure.core/map/fn--5866 (core.clj:2753)
        clojure.lang.LazySeq.sval (LazySeq.java:42)
        clojure.lang.LazySeq.seq (LazySeq.java:51)
        clojure.lang.RT.seq (RT.java:535)
        clojure.core/seq--5402 (core.clj:137)
        clojure.core.protocols/seq-reduce (protocols.clj:24)
        clojure.core.protocols/fn--8146 (protocols.clj:75)
        clojure.core.protocols/fn--8146 (protocols.clj:75)
        clojure.core.protocols/fn--8088/G--8083--8101 (protocols.clj:13)

Also as mentioned above, all previous requires are lost. For instance, if I did the following above:

(require '[orgpad.client.db.get :as db-get])
=> nil

I can use functions from db-get perfectly fine. After this, I can't call them and I get this error in REPL:

------ WARNING - :undeclared-ns ------------------------------------------------
 Resource: <eval>:1:2
 No such namespace: db-get, could not locate db_get.cljs, db_get.cljc, or JavaScript source providing "db-get" (Please check that namespaces with dashes use underscores in the ClojureScript file name)
--------------------------------------------------------------------------------
------ WARNING - :undeclared-var -----------------------------------------------
 Resource: <eval>:1:2
 Use of undeclared Var db-get/latest-editor
--------------------------------------------------------------------------------

Requiring the namespace again will timeout before the result is returned.

Reloading a file in Cursive nREPL might be related to this, I sometimes do it by accident.

[thheller]

I cannot reproduce this. Please provide more information about what you do BEFORE this error happens. Also more information about your setup would be helpful. Builds configs, versions, etc.

[pavel-klavik]

Build config is the following:

 :nrepl        {:port 9000}
 :builds       {:client     {:target           :browser
                             :output-dir       "resources/public/js/compiled"
                             :asset-path       "/js/compiled"
                             :module-loader    true
                             :modules          {:shared {:entries []}
                                                :main   {:init-fn    orgpad.client.core/init
                                                         :depends-on #{:shared}}
                                                :admin  {:entries    [orgpad.client.views.administration.core]
                                                         :depends-on #{:main}}
                                                :layout {:entries    [orgpad.client.layout.webworker.core]
                                                         :depends-on #{:shared}
                                                         :web-worker true}}
                             :compiler-options {:infer-externs      :auto
                                                :output-feature-set :es6}
                             :devtools         {:after-load     orgpad.client.core/mount-root
                                                :before-load    orgpad.client.core/stop-web-workers
                                                :watch-dir      "resources/public"
                                                :browser-inject :main
                                                :loader-mode    :script}}

Not sure when it exactly happens. I am editing the code in Cursive, saving changing and at some point, REPL does not work anymore. I am not able to find a way how to reproduce it, but it happens several times per day, on different computers and even different OS (I am on Windows, happens to my colleague on Linux as well). Any tips for debugging?

[genovese]

As I mentioned on slack, the same thing has been happening to me the past few days: _any_ require after a recompile raises an error (where (:name new-ns-info) is not a symbol in shadow.cljs.repl/repl-require), and thereafter the repl times out and hangs. I start the server and repl, look at some data, make a trivial change to a string (say) in any source file, the watch recompiles the code. At that point, I can look at data and call functions fine. Unaliased namespaces that I have required still seem to work (though former aliases are gone). But once I require anything else, aliased or not, the error/timeout/hang occurs.

I have a clean (node modules not installed, no cache etc) and a dirty (all modules installed, previously run builds) tarball of the project that consistently reproduces the problem, which I am happy to share (by email, say). But I am trying to reduce it to the minimal case first to make things easier. I'll post back when I have, hopefully this evening. I'm also trying to get a quick view of new-ns-info while this is happening.

For reference, here's the --cli-info

=== Version
jar:            2.11.10
cli:            2.11.10
deps:           1.3.2
config-version: 2.11.10

=== Paths
cli:     /Users/genovese/Projects/Isle/rav/fulravdemo/node_modules/shadow-cljs/cli/dist.js
config:  /Users/genovese/Projects/Isle/rav/fulravdemo/shadow-cljs.edn
project: /Users/genovese/Projects/Isle/rav/fulravdemo
cache:   .shadow-cljs

=== Java
openjdk version "15.0.1" 2020-10-20
OpenJDK Runtime Environment (build 15.0.1+9-18)
OpenJDK 64-Bit Server VM (build 15.0.1+9-18, mixed mode, sharing)

=== Source Paths

My shadow-cljs.edn:

{:deps     {:aliases [:dev]}
 :dev-http {8000 "classpath:public"}
 :builds   {:main {:target     :browser
                   :output-dir "resources/public/js/main"
                   :asset-path "/js/main"
                   :modules    {:main {:init-fn app.client/init
                                       :entries [app.client]}}
                   :devtools   {:after-load app.client/refresh
                                :preloads   [com.fulcrologic.fulcro.inspect.preload
                                             com.fulcrologic.fulcro.inspect.dom-picker-preload]}}}
 :nrepl {:port 8777}

 :open-file-command ["emacsclient" "-n" ["+%s:%s" :line :column] :file]}

And deps.edn:

{:paths   ["src/main" "resources"]
 :deps    {org.clojure/clojure    {:mvn/version "1.10.1"}
           com.fulcrologic/fulcro {:mvn/version "3.4.10"}}

 :aliases {:dev {:extra-paths ["src/dev"]
                 :extra-deps  {org.clojure/clojurescript   {:mvn/version "1.10.764"}
                               thheller/shadow-cljs        {:mvn/version "2.11.10"}
                               binaryage/devtools          {:mvn/version "1.0.2"}
                               edn-query-language/eql      {:mvn/version "1.0.1"}}}}}

Thanks for your help!

[genovese]

I logged ns-info and new-ns-info for the require before the recompile and the one after that triggers the hang. The info is below. (I've excised the repl-state from the log output because it is long, but let me know if something there would be helpful to see.) Interestingly, I had a case where the failure did not occur until after the third recompile, which is the first time that happened.

The first require (before looking at some data and triggering the recompile):

{:ns-info {:rename-macros nil, :renames {}, :meta {}, :ns-aliases {cljs.loader shadow.loader, clojure.spec.alpha cljs.spec.alpha, clojure.pprint cljs.pprint, clojure.spec.gen.alpha cljs.spec.gen.alpha, clojure.core.async cljs.core.async}, :use-macros {doc cljs.repl, find-doc cljs.repl, source cljs.repl, apropos cljs.repl, pst cljs.repl, dir cljs.repl}, :excludes #{}, :name cljs.user, :imports nil, :reload-deps [], :requires {cljs.repl cljs.repl, cljs.core cljs.core, goog goog, com.kymetis.rav.app.client com.kymetis.rav.app.client}, :seen #{:require}, :uses {doc cljs.repl, find-doc cljs.repl, source cljs.repl, apropos cljs.repl, pst cljs.repl, dir cljs.repl}, :require-macros {cljs.core cljs.core, cljs.repl cljs.repl}, :flags {:require #{}}, :js-deps {}, :deps [goog cljs.core cljs.repl com.kymetis.rav.app.client]},
 :new-ns-info {:rename-macros nil, :renames {}, :meta {}, :ns-aliases {cljs.loader shadow.loader, clojure.spec.alpha cljs.spec.alpha, clojure.pprint cljs.pprint, clojure.spec.gen.alpha cljs.spec.gen.alpha, clojure.core.async cljs.core.async}, :use-macros {doc cljs.repl, find-doc cljs.repl, source cljs.repl, apropos cljs.repl, pst cljs.repl, dir cljs.repl}, :excludes #{}, :name cljs.user, :imports nil, :reload-deps [], :requires {cljs.repl cljs.repl, cljs.core cljs.core, goog goog, com.kymetis.rav.app.client com.kymetis.rav.app.client}, :seen #{:require}, :uses {doc cljs.repl, find-doc cljs.repl, source cljs.repl, apropos cljs.repl, pst cljs.repl, dir cljs.repl}, :require-macros {cljs.core cljs.core, cljs.repl cljs.repl}, :flags {:require #{}}, :js-deps {}, :deps [goog cljs.core cljs.repl com.kymetis.rav.app.client]},
 :bad-name cljs.user,
 :current-ns cljs.user,
 :require-form (require (quote com.kymetis.rav.app.client)),
 :read-result {:eof? false, :ns cljs.user, :form (require (quote com.kymetis.rav.app.client)), :source "(require 'com.kymetis.rav.app.client)"},
 :repl-state {...}}

And the require that triggered failure:

{:ns-info nil,
 :new-ns-info {:flags {:require #{}}, :reload-deps [], :deps [com.kymetis.rav.app.ui], :requires {com.kymetis.rav.app.ui com.kymetis.rav.app.ui}},
 :bad-name nil,
 :current-ns cljs.user,
 :require-form (require (quote com.kymetis.rav.app.ui)),
 :read-result {:eof? false, :ns cljs.user, :form (require (quote com.kymetis.rav.app.ui)), :source "(require 'com.kymetis.rav.app.ui)"},
 :repl-state {...}}

If there's anything else that would be useful to see, don't hesitate to let me know. I'll keep digging as well.

[genovese]

I've attached a small example that consistently reproduces the problem for me. It's not strictly speaking minimal, as it still uses react and fulcro, but barely. I've pared away anything but the basics. (It's in a zip file because that's what github accepts.)

Steps (also in the included README):

1. Unpack the zip file, creating a directory shadowhang containing the package
2. cd shadowhang
3. npm install
4. Start server in one terminal with npx shadow-cljs watch main
5. Once the build is complete, open localhost:8000 in a browser
6. In another terminal, run npx shadow-cljs cljs-repl main
7. In the repl, follow the few steps listed in src/dev/reproduce.cljs to reproduce the problem

Let me know if you'd like something else, you have any questions, or there's another way I can help. Thanks!

hangex.zip

[thheller]

I think this should be fixed in 2.11.11.

Thanks everyone for the information. Not sure why I wasn't able to reproduce this earlier.