Clojurians Log v2

https://github.com/ericdallo/metrepl/blob/15fe50505d4f0aa257ebe80f2cd3c483387dcb84/src/metrepl/metrics.clj#L22-L24 I measure the time the handle msg op takes, but it seems it's not correct (handle-op-fn) == (handle msg) in the middleware https://github.com/ericdallo/metrepl/blob/15fe50505d4f0aa257ebe80f2cd3c483387dcb84/src/metrepl/middleware/op_metrics.clj#L25

for a code like this:

(do
  (Thread/sleep 1000)
  (+ 1 2))

I suspect the eval is done async... if so, how to measure that?

Yes, evals happen in a different thread (a "session" thread)

https://github.com/nrepl/nrepl/blob/master/src/clojure/nrepl/middleware/interruptible_eval.clj#L143-L146 where exec is this: https://github.com/nrepl/nrepl/blob/master/src/clojure/nrepl/middleware/session.clj#L207

Do you see any way to workaround that?

• Remember start time in the middleware wrapper • Update transport to intercept responses, wait for a :done response, that's where you take the end time

Similar to how it's done here https://github.com/clojure-emacs/cider-nrepl/blob/master/src/cider/nrepl/middleware/track_state.clj#L326-L341

Ahh that makes sense, I do something similar in other middleware and didn't realize I could wait for done, awesome

Does that happens for other ops? Like load-file?

I mean, what others should I be aware of this async behavior

Can't tell you off the top of my head, you better check for yourself. load-file is a probable one

Will do, thank you!

that worked perfectly, thanks!