Fork me on GitHub
#cider
<
2019-01-17
>
Cam Saul08:01:18

Has anyone ever ran into issues with cider-nrepl hanging when evaluating forms? I have the exact same Emacs version and configuration/`~/.lein/profiles.clj`/project across 3 different computers (3 Macs, 1 running Linux, and 1 running Windows) and only one of them has this issue (one of the Macs). I cannot figure why it's happening. Basically when I evaluate a form in cider-nrepl it will sometimes hang for 10-20 seconds before printing the result. The hanging is happening in the external process because Emacs is still responsive (and debug-on-exit and the Emacs profiling tools don't really provide useful info). When I run lein repl however things work perfectly normally. But if I run lein repl :headless and M-x cider-connect to that REPL I run into the hanging again.

dominicm08:01:30

@camsaul how big are the results you are evaluating?

Cam Saul08:01:18

The form and the results don't matter -- it hangs equally often and long whether I'm evaluating something simple like (+ 1 2) or a bigger function that run a DB query and returns a few hundred rows

pjstadig10:01:58

@camsaul maybe check the heap sizes? the default heap size can vary from computer to computer and memory pressure could cause delays in processing

Cam Saul10:01:26

@pjstadig thanks, I thought it could be that. But (.maxMemory (Runtime/getRuntime)) gives my 8 GB, so I don't think that's the problem

Cam Saul10:01:07

even when creating a new project and running cider-nrepl I'm running into the lag. I've enabled nrepl logging (`(setq nrepl-log-messages t)`) to try to figure out what's going on. It's lagging between sending the form to be evaled to the nrepl and getting the response.

(-->
  id            "17"
  op            "eval"
  session       "af0c00af-7bb8-4382-a6bc-44248c420115"
  time-stamp    "2019-01-17 02:21:58.994293000"
  code          "(+ 2 3)"
  column        9
  content-type  "true"
  file          "*cider-repl ~/x:localhost:50767(clj)*"
  line          8
  ns            "x.core"
  print-options (dict ...)
  printer       "cider.nrepl.pprint/pprint"
)
(<--
  id         "17"
  session    "af0c00af-7bb8-4382-a6bc-44248c420115"
  time-stamp "2019-01-17 02:22:42.249252000"
  ns         "x.core"
  value      "5"
)
In the example above I typed (+ 2 3) in the REPL and it took almost a full minute to get a response (as recorded in the timestamps). Annoying to say the least! 😓

Cam Saul10:01:23

I thought it could have been some sort of network configuration issue so I tried 127.0.0.1 instead of localhost but that doesn't seem to make a difference

Cam Saul10:01:16

I think maybe my next step will be to look at the traffic a little more with Wireshark and see what's going on and maybe try to repo some of the queries it's sending manually and seeing if I run into the same lag outside of CIDER

pjstadig10:01:49

i wouldn't guess it is networking related. have you tried hooking up jvisualvm or something similar to the repl server to see what is happening when its evaluating?

Cam Saul10:01:35

that's a good idea. Let me give that a try

Cam Saul10:01:02

the reason I thought it might have been networking related is there's no lag when running the nrepl directly with lein repl

pjstadig10:01:09

yeah i was thinking the delay in the timestamps indicated a delay in processing as opposed to networking

pjstadig10:01:21

are there any firewalls or network filters possibly interfering?

Cam Saul10:01:19

Yeah, I turned of then firewall and antivirus to see if that was a problem and it didn't make a difference. I'm using the same stuff on the other too Macs however without issue. Another other stuff ran locally like databases in Docker containers or web servers aren't having any issues

Cam Saul12:01:17

so profiling didn't get me very far except for finding out that nrepl is basically spending most of its CPU cycles polling for and writing bytes. Nothing surprising. What is surprising however is comparing packet capture in Wireshark with the `*nrepl-messages* buffer. I evaled (System/nanoTime) in the REPL at 4:15:15, but didn't see a response for 10 seconds or so. Wireshark capture:

04:15:15.884979 TCP	324	52718 → 52359 [PSH, ACK] <eval request from cider>
04:15:15.884997 TCP	56	 52359 → 52718 [ACK] <ack from nrepl for eval request packet>
04:15:15.890072 TCP	150	52359 → 52718 [PSH, ACK] <nrepl response>
04:15:15.890091 TCP	56	 52718 → 52359 [ACK] <ack from cider for response>
*nrepl-messages*
(-->
  id            "69"
  op            "eval"
  session       "2c754a30-4bf0-42ba-aa57-b57977f7f2aa"
  time-stamp    "2019-01-17 04:15:15.884446000"
  code          "(System/nanoTime)"
  column        9
  content-type  "true"
  file          "*cider-repl ~/x:localhost:52359(clj)*"
  line          14
  ns            "x.core"
  print-options (dict ...)
  printer       "cider.nrepl.pprint/pprint"
)
(<--
  id         "69"
  session    "2c754a30-4bf0-42ba-aa57-b57977f7f2aa"
  time-stamp "2019-01-17 04:15:24.734444000"
  ns         "x.core"
  value      "55310219931646"
)
(<--
  id         "69"
  session    "2c754a30-4bf0-42ba-aa57-b57977f7f2aa"
  time-stamp "2019-01-17 04:15:24.735295000"
  status     ("done")
)

Cam Saul12:01:40

The really strange thing is that I can see the response being sent by nrepl about 5 milliseconds after the eval request is sent, but it doesn't pop up in *nrepl-messages* or the CIDER REPL until 9 seconds later

Cam Saul12:01:36

In case my Emacs networking was broken somehow I reinstalled it and tried both http://Emacs.app and installing with Homebrew but neither had an effect. FWIW other networking in Emacs seems to be working fine (such as fetching packages) So I'm guessing there's something weird going on in the CIDER networking code itself. I'm going to try to poke around a bit and see if I can find what's going on

pjstadig13:01:11

Not sure if this is a good idea, but I released this https://github.com/pjstadig/ring-cider-debug

Chase22:01:25

I use C-c M-; (eval-defun-to-comment) a lot so that I can refer back to the output while studying. But if I do something like this (def words (clojure.string/split example #" ")) and then want to check my output by just putting in words below it I get the expected behavior when pressing C-c C-e but do not get the expected behavior from C-c M-;. Is there a trick to eval-defun-to-comment if I am using it on only variable names without an s-expression? Not sure if this is too much of a corner case for my use only.

Chase22:01:47

the behavior I get in this case is it evals the next complete s-expression in my source code and inserts the relevant comment for that expression.

jmckitrick23:01:43

@dpsutton It looks like my .lein/profiles.clj needs an update.

jmckitrick23:01:59

I’ll start with tools.nrepl

jmckitrick23:01:25

Or do I want the new one?

jmckitrick23:01:34

The standalone nrepl?

dpsutton23:01:35

if you can get away with it, an empty one is preferable

jmckitrick23:01:52

Actually, most is commented out.

dpsutton23:01:53

you shouldn't need any deps in there. CIDER will inject all of its own depepdencies into a project when you are jacking in

jmckitrick23:01:06

I have a few lein plugins

dpsutton23:01:19

those are usually a problem when upgrading

jmckitrick23:01:24

So… I’ll comment out all cider entries.

jmckitrick23:01:30

Ah. I’ll comment them all out for now.

jmckitrick23:01:22

First complaint: need cider-nrepl

dpsutton23:01:40

how are you starting your app?

jmckitrick23:01:40

cider-jack-in

jmckitrick23:01:10

I added [cider/cider-nrepl "0.20.0"] under :user :plugins

dpsutton23:01:24

get rid of it

dpsutton23:01:41

CIDER will inject everything it needs when you do cider-jack-in

jmckitrick23:01:00

Yeah, that’s when I got the error

jmckitrick23:01:04

I’ll try again clean

dpsutton23:01:05

in the *Messages* buffer it will show the command it uses to start up your process. can you post that here?

dpsutton23:01:22

also, what version of CIDER are you using?

jmckitrick23:01:51

0.21.0-snapshot

dpsutton23:01:12

did you recently update?

jmckitrick23:01:13

Starting server via /Users/jmckitrick/bin/lein update-in :dependencies conj \[nrepl\ \"0.5.3\"\] -- update-in :plugins conj \[cider/cider-nrepl\ \"0.20.0\"\] -- repl :headless :host localhost...

dpsutton23:01:28

cool. yeah there you can see its injecting everything it needs

jmckitrick23:01:34

I update weekly

dpsutton23:01:43

ok. just making sure emacs had been restarted since

jmckitrick23:01:45

Yes, it looks like it should work.. however…

jmckitrick23:01:54

error in process filter: user-error: 'nil' requires the nREPL op "classpath" (provided by cider-nrepl)
error in process filter: 'nil' requires the nREPL op "classpath" (provided by cider-nrepl)

dpsutton23:01:56

can you run that command from a command line and see what happens?

jmckitrick23:01:49

Starting by that command ends with nREPL server started on nnnn

dpsutton23:01:30

ok. try m-x nrepl-toggle-message-logging

jmckitrick23:01:30

Ok, this time CIDER did not give me the same warning. However, in the repl in emacs I’m seeing CIDER requires nREPL 0.4.4 (or newer) to work properly

dpsutton23:01:55

ok. i think we are closer. maybe check lein deps :tree to see if anything is bringing in tools.nrepl

jmckitrick23:01:47

Ok, let me RTFM this CIDER troubleshooting page as well…

jmckitrick23:01:45

Just found this [org.clojure/tools.nrepl "0.2.12" :exclusions [[org.clojure/clojure]]]

jmckitrick23:01:44

When I ran lein deps :tree, that is

jmckitrick23:01:51

Since I’m running cider-jack-in inside a project, I shouldn’t need to force nREPL 0.4.4

dpsutton23:01:16

right, but we need to keep the old tools.nrepl out

dpsutton23:01:24

it is poisonous to current CIDER

jmckitrick23:01:10

I don’t see how it’s getting in…

jmckitrick23:01:53

It’s not in my project.clj, and it’s not in .lein/profiles.clj

dpsutton23:01:14

are you sure you're on lein 2.8.3?

dpsutton23:01:43

if you are doing lein deps tree it should show who requires it. if it is "top level" it is just required in your project.clj

jmckitrick23:01:32

Oh, I downgraded to 2.8.1 to get my repl to work

jmckitrick23:01:43

Let me try 2.8.3

dpsutton23:01:54

ah sorry. yeah 2.8.3 moves to new nrepl, 2.8.1 was old nrepl

jmckitrick23:01:56

Ok, I think I’m in business!

jmckitrick23:01:13

I have both my repl and CIDER working… let me try again fresh

dpsutton23:01:21

excellent. sorry its so weird. things just get crazy when core infrastructure like nrepl gets unfrozen

jmckitrick23:01:33

No problem. I’m really looking for a place to help now. The only catch is I’m not currently in Clojure full time anymore. But I want to contribute something of value…

jmckitrick23:01:45

Looks like CIDER is fully operational. Thanks for the help!

jmckitrick23:01:39

So for any other projects I want to use, the hard work has been done, right? Upgrade leiningen, clear out .lein/profiles.clj, and that should be it?

dpsutton23:01:59

pretty much. the only gotcha is that the two versions of nrepl can't coexist right now

dpsutton23:01:15

which means lein 2.8.3 and watch your deps for older versions