nrepl

https://github.com/nrepl/nrepl || https://nrepl.org
unwarysage 2018-04-20T19:44:47.000519Z

Heyo. I have a question. it seems that the view of messages in nREPL varies depending on whether I looking at them from a middleware, or from a client

unwarysage 2018-04-20T19:45:30.000271Z

I'm trying to write a function that takes a piece of code as a string and evaulates it, returning all nREPL messages related to it's evauluation

unwarysage 2018-04-20T19:45:49.000284Z

And for standard responses, it's fine

unwarysage 2018-04-20T19:46:17.000591Z

But anything sent to err or out doesn't seem to arrive on the client side

unwarysage 2018-04-20T19:46:56.000412Z

Which is unfortunate, because I am trying to write code for modifying error messages, and those don't show up

2018-04-20T20:03:31.000525Z

*err* and *out* are thread local bindings, so writing to them will depend on what thread the writing to is occuring on

2018-04-20T20:04:39.000036Z

if in your server process you are spinning up some thread that somehow doesn't copy the repls values of *err* and *out* it will get the default values and nrepl won't be able to capture the output

unwarysage 2018-04-20T20:06:17.000128Z

So this is what I have.

(defn trap-response [inp-code]
(with-open [conn (repl/connect :port server-port)]
     (-> (repl/client conn 1000)
       (repl/message {:op :eval :code inp-code})
       doall)))

unwarysage 2018-04-20T20:06:32.000528Z

With some code to start an nREPL server preceding it

unwarysage 2018-04-20T20:07:06.000518Z

In the middleware I am trying to test, I know that

:err
exists

unwarysage 2018-04-20T20:09:19.000093Z

how can I copy the repl values of

*err*
?

2018-04-20T20:13:25.000391Z

it will depend on what you are running and what inp-code is doing

2018-04-20T20:14:07.000461Z

e.g. a new thread launched with say future does automatically inherit the initiating threads values of err and out (also any other dynamic vars bound)

2018-04-20T20:15:06.000012Z

if you are manually creating and starting a Thread object you will have do it yourself, the easiest way is likely to use bound-fn

unwarysage 2018-04-20T20:15:31.000586Z

hmm

unwarysage 2018-04-20T20:15:41.000076Z

for the present I am not doing anyhting threaded

2018-04-20T20:15:47.000089Z

oh, are you saying your middleware is seeing the messages with :err in them?

unwarysage 2018-04-20T20:15:58.000617Z

Yeah

unwarysage 2018-04-20T20:16:11.000298Z

My middleware is attempting to improve java error messages

2018-04-20T20:16:15.000182Z

just somewhere between your middleware and the client the message is getting dropped

2018-04-20T20:16:44.000536Z

is your middleware forwarding on the message correctly? is it throwing an error causing the error message to be swallowed?

unwarysage 2018-04-20T20:16:51.000248Z

Yeah, and the error message comes through, but as a print, and not in right place

2018-04-20T20:17:10.000330Z

what do you mean "as a print" and "not in the right place" ?

unwarysage 2018-04-20T20:18:40.000586Z

one moment

unwarysage 2018-04-20T20:20:42.000291Z

Okay, so I run trap response and I get a list of nrepl messages back

unwarysage 2018-04-20T20:20:59.000422Z

But it also prints the modified error message

unwarysage 2018-04-20T20:21:04.000573Z

so I get something like

unwarysage 2018-04-20T20:21:12.000195Z

teardown.core=> (trap-response "(banana)")
Name banana is undefined.
({:ex "class clojure.lang.Compiler$CompilerException", :id "a71b6465-6515-4b66-801c-91daa498cdf8", :root-ex "class clojure.lang.Compiler$CompilerException", :session "50e928a8-2fed-44c9-adae-8404972586f1", :status ["eval-error"]} {:id "a71b6465-6515-4b66-801c-91daa498cdf8", :session "50e928a8-2fed-44c9-adae-8404972586f1", :status ["done"]})
teardown.core=> 

2018-04-20T20:21:43.000157Z

oh, that isn't :err

unwarysage 2018-04-20T20:21:52.000467Z

okay

2018-04-20T20:21:59.000014Z

that is :ex , the exception value

2018-04-20T20:22:21.000503Z

status :eval-error

unwarysage 2018-04-20T20:22:31.000212Z

yeah.

2018-04-20T20:22:58.000156Z

that isn't output to *out* or *err*, that is the error result of the eval

unwarysage 2018-04-20T20:23:00.000207Z

I would like to see an entry in my list of responses with that key

2018-04-20T20:23:20.000080Z

are you just printing the message in your middleware?

unwarysage 2018-04-20T20:23:25.000307Z

no

2018-04-20T20:23:43.000503Z

what does trap-response do?

unwarysage 2018-04-20T20:24:13.000442Z

https://clojurians.slack.com/archives/C17JYSA3H/p1524254777000128 this is the definition of trap response

2018-04-20T20:25:12.000145Z

and what does your middleware do? are you running the repl server in the same jvm as you are running trap-response?

unwarysage 2018-04-20T20:25:50.000427Z

my middleware takes the value of :err and changes it. Eventually I hope to gain access to the exception object, but for the moment I am parsing string to string

2018-04-20T20:26:35.000233Z

are you sure you aren't just printing out the string in the middleware? it looks a lot like you are

2018-04-20T20:27:13.000503Z

I am not sure that an error like that results in anything coming back with :errr set

2018-04-20T20:27:26.000584Z

I think you just get the :ex

unwarysage 2018-04-20T20:27:28.000138Z

no, there are no prints in my middleware

unwarysage 2018-04-20T20:28:15.000325Z

middleware wraps the transport function in incoming messages, so that post eval this code is run

unwarysage 2018-04-20T20:28:35.000506Z

(defn modify-errors "takes a nREPL response, and returns a message with the errors fixed"
  [inp-message]
  (if (contains? inp-message :err)
    (assoc inp-message :err (m-obj/get-all-text (:msg-info-obj (p-exc/process-spec-errors (inp-message :err)))))
    inp-message))

2018-04-20T20:29:35.000386Z

I am looking at the interruptible-eval middleware right now, and when an exception is thrown it doesn't set :err, you get back the :ex message

unwarysage 2018-04-20T20:30:16.000417Z

and yet my middleware works. I don't mean to be obtuse, but in developping the middleware I never got access to the

:ex
message

2018-04-20T20:30:50.000191Z

how recently have you restarted your repl?

unwarysage 2018-04-20T20:31:28.000406Z

fresh for these commands

unwarysage 2018-04-20T20:31:43.000104Z

Fresh everytime I touched the middleware

2018-04-20T20:32:28.000333Z

I would put in some printlns in each branch of that if to see which branch is actually getting taken

unwarysage 2018-04-20T20:33:10.000192Z

This is the code

unwarysage 2018-04-20T20:33:30.000211Z

and I know which branch is being taken, because I can see the transformed error messages

2018-04-20T20:34:55.000228Z

no, you are seeing some printlns

unwarysage 2018-04-20T20:35:18.000024Z

okay. I am confused but attentive

2018-04-20T20:36:44.000032Z

you are seeing some output that sort of looks like it matches what in some circumstances might match what you would get if your middelware is running

2018-04-20T20:37:39.000487Z

but that doesn't actually prove that it is, so you need to prove that it is, and prove that is running the way you expect

2018-04-20T20:37:58.000430Z

you may also have an easier time debugging this kind of thing if you run the client and the server in different jvms

unwarysage 2018-04-20T20:38:17.000337Z

I can do that.

unwarysage 2018-04-20T20:39:46.000307Z

Well, I can connect to the babel jvm

2018-04-20T20:40:28.000307Z

what do you mean by that?

unwarysage 2018-04-20T20:41:17.000248Z

I am unsure of how to connect to a nREPL server using the middleware

2018-04-20T20:41:25.000291Z

I mean, you have two jvms, on running an nrepl server with your middleware, a second running an nrepl server without your middleware, you nrepl into the second and run trap-response

2018-04-20T20:41:33.000052Z

(connecting to the first)

unwarysage 2018-04-20T20:41:43.000494Z

will try

2018-04-20T20:42:09.000488Z

where you see the message printed out will tell you if it is being printed in the client side or the server side

2018-04-20T20:42:24.000021Z

it is almost certainly on the server side

unwarysage 2018-04-20T20:42:47.000259Z

IIRC it is, that was what I meant when I said "in the wrong place"

2018-04-20T20:43:34.000407Z

if you are satisfied that you have proved to yourself that it is printing on the server side, then you can start looking at the code being run on the server side

2018-04-20T20:43:40.000103Z

are you aot compiling?

unwarysage 2018-04-20T20:44:12.000218Z

No.

2018-04-20T20:44:56.000307Z

what I am getting at there is, is the code you think you are running what is actually running, aot compilation can be a culprit there, but I've seen people have multiple copies of the src directory and edit the wrong one, or forget to save the file, or whatever

unwarysage 2018-04-20T20:45:25.000168Z

Okay, so launching one repl with middleware, connecting a second one to it, defining and running trap response in the second one gets me a modified error message and the return list of messages, both in the second repl

2018-04-20T20:45:46.000033Z

interesting

unwarysage 2018-04-20T20:45:56.000404Z

waitaminute.

unwarysage 2018-04-20T20:46:36.000157Z

trap-response launches a third repl server and sends things to it for eval

unwarysage 2018-04-20T20:46:56.000502Z

How but the error messages are still being modified

unwarysage 2018-04-20T20:48:39.000363Z

so...

unwarysage 2018-04-20T20:48:42.000211Z

I think I see

2018-04-20T20:49:05.000587Z

my kind of vague hand wavy guess is you have state issues in your middleware stack, global state is being used, which could be a problem if you have more than one nrepl session running

unwarysage 2018-04-20T20:49:21.000493Z

somehow between the repl trap response runs and the one it is in, my middleware steps in

unwarysage 2018-04-20T20:49:29.000140Z

I don't think there is any state

2018-04-20T20:49:53.000306Z

I dunno, I see a bunch of def'ed atoms, and I made a hand wavy guess

unwarysage 2018-04-20T20:49:58.000450Z

in core?

2018-04-20T20:50:18.000525Z

yes

unwarysage 2018-04-20T20:50:27.000275Z

sorry core has been deprecated. Those were for testing purposes, and no code runs in core now.

unwarysage 2018-04-20T20:50:32.000118Z

really sorry about that

2018-04-20T20:50:57.000084Z

no worries, just took a glance around

unwarysage 2018-04-20T20:52:02.000289Z

So, just trying out a plain old division by zero error in the repl that runs trap-response, I see it's error messages are being modified

unwarysage 2018-04-20T20:52:45.000309Z

https://clojurians.slack.com/archives/C17JYSA3H/p1524256604000032 though I am still concerned by any problems you saw when you said this

2018-04-20T20:55:14.000368Z

I didn't see any problems, it is more like like I try to eliminate assumptions when debugging, and that seemed like one

unwarysage 2018-04-20T20:55:31.000210Z

fair enough

unwarysage 2018-04-20T20:55:54.000385Z

AFK ~2 minutes max

unwarysage 2018-04-20T21:00:46.000543Z

back

unwarysage 2018-04-20T21:05:45.000140Z

okay

unwarysage 2018-04-20T21:06:52.000300Z

it seems if trap-response's own server is set to point at the modified server, then I do get

:err

unwarysage 2018-04-20T21:09:43.000043Z

This seems to be working, and I am very grateful

unwarysage 2018-04-20T21:09:53.000076Z

thank you for your time and expertise