Timing problem for jack-in?

[bonega]

I get the following stacktrace intermittently upon doing M-x: cider-jack-in
The frequency might be dependent on something in the project used, not sure yet.

I can't really tell if anything breaks when it happens.
PP exists in the repl directly after the stacktrace.
Thought it would be helpfull anyway, I saw some old reports posting similar stacktraces but without the timing aspect.

java.lang.IllegalAccessError: pp does not exist
 at clojure.core$refer.doInvoke (core.clj:3849)
    clojure.lang.RestFn.applyTo (RestFn.java:139)
    clojure.core$apply.invoke (core.clj:619)
    clojure.core$load_lib.doInvoke (core.clj:5394)
    clojure.lang.RestFn.applyTo (RestFn.java:142)
    clojure.core$apply.invoke (core.clj:619)
    clojure.core$load_libs.doInvoke (core.clj:5413)
    clojure.lang.RestFn.applyTo (RestFn.java:137)
    clojure.core$apply.invoke (core.clj:619)
    clojure.core$require.doInvoke (core.clj:5496)
    clojure.lang.RestFn.applyTo (RestFn.java:137)
    clojure.core$apply.invoke (core.clj:617)
    user$eval1073.invoke (NO_SOURCE_FILE:1)
    clojure.lang.Compiler.eval (Compiler.java:6619)
    clojure.lang.Compiler.eval (Compiler.java:6582)
    clojure.core$eval.invoke (core.clj:2852)
    clojure.main$repl$read_eval_print__6588$fn__6591.invoke (main.clj:259)
    clojure.main$repl$read_eval_print__6588.invoke (main.clj:259)
    clojure.main$repl$fn__6597.invoke (main.clj:277)
    clojure.main$repl.doInvoke (main.clj:277)
    clojure.lang.RestFn.invoke (RestFn.java:1096)
    clojure.tools.nrepl.middleware.interruptible_eval$evaluate$fn__589.invoke (interruptible_eval.clj:56)
    clojure.lang.AFn.applyToHelper (AFn.java:159)
    clojure.lang.AFn.applyTo (AFn.java:151)
    clojure.core$apply.invoke (core.clj:617)
    clojure.core$with_bindings_STAR_.doInvoke (core.clj:1788)
    clojure.lang.RestFn.invoke (RestFn.java:425)
    clojure.tools.nrepl.middleware.interruptible_eval$evaluate.invoke (interruptible_eval.clj:41)
    clojure.tools.nrepl.middleware.interruptible_eval$interruptible_eval$fn__630$fn__633.invoke (interruptible_eval.clj:171)
    clojure.core$comp$fn__4154.invoke (core.clj:2330)
    clojure.tools.nrepl.middleware.interruptible_eval$run_next$fn__623.invoke (interruptible_eval.clj:138)
    clojure.lang.AFn.run (AFn.java:24)
    java.util.concurrent.ThreadPoolExecutor.runWorker (ThreadPoolExecutor.java:1145)
    java.util.concurrent.ThreadPoolExecutor$Worker.run (ThreadPoolExecutor.java:615)
    java.lang.Thread.run (Thread.java:724)

[bbatsov]

Could you, please, post your cider-related config?

[bonega]

I have confirmed that the problem still exists with an empty cider-config.
My testing seems to indicate that the frequency of failure really seems to be related to the project used.

I haven't been able to reproduce it in a project that uses the following deps:

:dependencies [[org.clojure/clojure "1.5.1"]
                 [clj-webdriver "0.6.0"]
                 [org.clojure/core.incubator "0.1.2"]
                 [com.datomic/datomic-free "0.8.4020.24" :exclusions [org.apache.httpcomponents/httpclient]]
                 [fs "1.3.2"]]

My intermittently failing project does only use Midje. (Other projects still fail without midje)
Perhaps there is a slight delay with including some of the deps that masks the problem?
It might be pertinent that I have a SSD.

[bbatsov]

I asked about your config, because unless you've enabled REPL pretty-printing I can't think of why pp would be needed at all.

[bonega]

Hmm... strange.
I have done a M-x: grep for 'pretty' in ~/.emacs.d/ but there are no hits.

But I might have found something relevant in ~/.lein/profiles.clj:

{:user {:plugins [[lein-midje "3.1.3"] [lein-kibit "0.0.8"]]
        ;:dependencies [[io.aviso/pretty "0.1.8"]]
        }
 ;:repl-options {:nrepl-middleware [io.aviso.nrepl/pretty-middleware]}
 }

aviso/pretty seems a likely culprit, but it is disabled.
Looking at the stacktrace seems to indicate a middleware though.

$ lein --version
Leiningen 2.2.0 on Java 1.7.0_25 Java HotSpot(TM) 64-Bit Server VM

[bbatsov]

interruptible_eval is a built-in middleware, so I doubt it's causing the problem. @cemerick Might have a better idea how we can find the offender.

[cemerick]

Nothing in nREPL itself, which doesn't use pretty-printing at all anywhere. The "intermittent" thing is bizarre; perhaps it only seems intermittent because you're twiddling around with configurations? ;-)

[bonega]

I did some testing just now with cider-jack-in and cider-quit.
Seems entirely random and can reoccur in the same emacs session if I restart cider.

But as I said before, I haven't discovered any ill effects so far.
Just found it interesting.

[mpwillson]

I had this a lot on a Debian Wheezy machine, but also intermittent.

My "fix" was to add a short delay in cider-init-repl-buffer, just before the requires in nrepl-repl-requires-sexp are evaluated:

defun cider-init-repl-buffer (connection buffer &optional noprompt)
    "Initialize the REPL for CONNECTION in BUFFER.
  Insert a banner, unless NOPROMPT is non-nil."
    (with-current-buffer buffer
      (unless (eq major-mode (quote cider-repl-mode))
        (cider-repl-mode))
      ;; use the same requires by default as clojure.main does
      (sit-for 1) ; allow lein repl to come up fully?
      (cider-eval-sync nrepl-repl-requires-sexp)
      (cider-repl-reset-markers)
      (unless noprompt
        (cider-repl--insert-banner-and-prompt nrepl-buffer-ns))
      (cider-remember-clojure-buffer cider-current-clojure-buffer)
      (current-buffer)))

Maybe there is a race going on here between emacs and the repl clojure instantiation?

[bbatsov]

@mpwillson @bonega Can you insert the following code in place of the (sit-for 1) and sent me back its output, when you get the problem:

(message "nrepl status: %s" (process-status (get-process "nrepl")))
(message "nrepl-server status: %s" (process-status (get-process "nrepl-server")))

I have to know whether the server is causing the problem or the connection to it.

[mpwillson]

This is the output in Messages when the stack trace occurs (it's the same when it doesn't):

nREPL server started on 58088
Connecting to nREPL on localhost:58088...
nrepl status: open
nrepl-server status: run
Connected. 

Let me know if you need anything else.

-mark

[bonega]

I can't reproduce the problem anymore.
Not sure exactly what I have updated..

[bbatsov]

@mpwillson You get only a Java stack trace, right? An Emacs stack trace would help me narrow the issue further, but I doubt any is produced.

[mpwillson]

Yes, only the Java stack trace is produced; emacs is silent, I'm afraid.

-mark

[noisesmith]

Have you set the debug-on-error variable in emacs? I think this is needed to access the emacs debugger and get stack traces.

[AeroNotix]

I have the same bug occasionally, I can confirm that it happens non-uniformly.

My relevant .emacs configuration:

(add-hook 'clojure-mode-hook 'flymake-mode-on)
(require 'ac-nrepl)
(add-hook 'cider-repl-mode-hook 'ac-nrepl-setup)
(add-hook 'cider-mode-hook 'ac-nrepl-setup)
(eval-after-load "auto-complete"
'(add-to-list 'ac-modes 'cider-repl-mode))

[mpwillson]

@noisesmith , thanks for the suggestion. However, with debug-on-error set to t, there is still no evidence of an emacs error.

-mark

[bonega]

@mpwillson could you try to require and use pp after the error message?
I seem to rember that there was an additional error message for that.

[mpwillson]

@bonega I can use pp fine in the cider repl - no errors at all.

One other data point. If I change nrepl-repl-requires-sexp to this (i.e. using :refer :all for clojure/pprint):

(defvar nrepl-repl-requires-sexp "(clojure.core/apply clojure.core/require 
     '[[clojure.repl :refer (  source apropos dir pst doc find-doc)] 
       [clojure.pprint :refer :all] [clojure.java.javadoc :refer (javadoc)]])"
     "Things to require in the tooling session and the REPL buffer.")

the IllegalAccessError does not occur.

-mark