Timbre crashing Cider workflow (?)

[gdulus]

Hey,

First of all, thank you for a great project. Second, this is more of a question than a bug submission at this moment.

I'm experiencing strange behavior when timbre is used as a dependency in my project. When working with Doom Emacs (Clojure + Cider), when timbre is required in a namespace, reloading all namespaces (cider-ns-reload-all) leads to the exception:

Exception updating the ns-cache #error {
 :cause No implementation of method: :send of protocol: #'nrepl.transport/Transport found for class: nrepl.middleware.caught$caught_transport$reify__12531
 :via
 [{:type java.lang.IllegalArgumentException
   :message No implementation of method: :send of protocol: #'nrepl.transport/Transport found for class: nrepl.middleware.caught$caught_transport$reify__12531
   :at [clojure.core$_cache_protocol_fn invokeStatic core_deftype.clj 584]}]
 :trace
 [[clojure.core$_cache_protocol_fn invokeStatic core_deftype.clj 584]
  [clojure.core$_cache_protocol_fn invoke core_deftype.clj 576]
  [nrepl.transport$eval31382$fn__31400$G__31373__31407 invoke transport.clj 23]
  [clojure.lang.Var invoke Var.java 388]
  [cider.nrepl.middleware.track_state$update_and_send_cache$fn__16921 invoke track_state.clj 213]
  [cider.nrepl.middleware.track_state$update_and_send_cache invokeStatic track_state.clj 209]
  [cider.nrepl.middleware.track_state$update_and_send_cache invoke track_state.clj 159]
  [cider.nrepl.middleware.track_state$update_and_send_cache invokeStatic track_state.clj 181]
  [cider.nrepl.middleware.track_state$update_and_send_cache invoke track_state.clj 159]
  [clojure.lang.AFn applyToHelper AFn.java 156]
  [clojure.lang.AFn applyTo AFn.java 144]
  [clojure.core$apply invokeStatic core.clj 669]
  [clojure.core$update_in$up__6922 invoke core.clj 6220]
  [clojure.core$update_in invokeStatic core.clj 6221]
  [clojure.core$update_in doInvoke core.clj 6207]
  [clojure.lang.RestFn applyTo RestFn.java 146]
  [clojure.core$apply invokeStatic core.clj 673]
  [clojure.core$binding_conveyor_fn$fn__5823 doInvoke core.clj 2058]
  [clojure.lang.RestFn applyTo RestFn.java 146]
  [clojure.lang.Agent$Action doRun Agent.java 114]
  [clojure.lang.Agent$Action run Agent.java 163]
  [java.util.concurrent.ThreadPoolExecutor runWorker ThreadPoolExecutor.java 1128]
  [java.util.concurrent.ThreadPoolExecutor$Worker run ThreadPoolExecutor.java 628]
  [java. lang.Thread run Thread.java 829]]}

code used to test it:

(ns beholder.handlers
  (:require
   [beholder.helpers :as helpers]
   [clj-http.client :as client]
   [clojure.string :refer [split]]
   [compojure.core :refer :all]
   [compojure.route :as route]
   [ring.middleware.defaults :refer [wrap-defaults]]
   [ring.util.http-response :refer :all]
   [taoensso.timbre :as log]))

I have tested this with all possible combinations of required namespaces and only timbre leads to these issues.

Cider repl:

;; Connected to nREPL server - nrepl://localhost:46149
;; CIDER 1.7.0-snapshot (package: 1.7.0-snapshot), nREPL 1.0.0
;; Clojure 1.11.1, Java 11.0.12
;;     Docs: (doc function-name)
;;           (find-doc part-of-name)
;;   Source: (source function-name)
;;  Javadoc: (javadoc java-object-or-class)
;;     Exit: <C-c C-q>
;;  Results: Stored in vars *1, *2, *3, an exception in *e;
;;  Startup: /home/gdulus/.sdkman/candidates/leiningen/current/bin/lein update-in :dependencies conj \[nrepl/nrepl\ \"1.0.0\"\] -- update-in :dependencies conj \[refactor-nrepl/refactor-nrepl\ \"3.6.0\"\] -- update-in :plugins conj \[refactor-nrepl/refactor-nrepl\ \"3.6.0\"\] -- update-in :plugins conj \[cider/cider-nrepl\ \"0.30.0\"\] -- repl :headless :host localhost

my project.clj

(defproject beholder "0.1.0"
  :description "Documentation search engine with K8S first approach."
  :license {:name "MIT License" :url "https://opensource.org/licenses/MIT"}
  :dependencies [;; -------------- base -----------------------------------
                 [org.clojure/clojure "1.11.1"]
                 [prismatic/schema "1.4.1"]
                 [jarohen/chime "0.3.3"]
                 ;; -------------- k8s -----------------------------------
                 [nubank/k8s-api "0.1.2"]
                 [io.fabric8/kubernetes-client "6.3.1"]
                 ;; -------------- persistence ---------------------------
                 [cc.qbits/spandex "0.7.10"]
                 ;; -------------- scheduling -----------------------------------
                 [jarohen/chime "0.3.3"]
                 ;; -------------- web -----------------------------------
                 [etaoin "1.0.39"]
                 [compojure "1.6.3"]
                 [ring/ring-defaults "0.3.4"]
                 [ring-json-response "0.2.0"]
                 [metosin/ring-http-response "0.9.3"]
                 [selmer "1.12.55"]
                 [environ "1.2.0"]
                 [clj-soup/clojure-soup "0.1.3"]
                 [clj-http "3.12.3"]
                 [org.clojure/data.json "2.4.0"]

                 ;; --------------- testing ------------------------------
                 [clj-test-containers "0.7.4"]
                 [ring/ring-mock "0.4.0"]

                 ;; --------------- logging ------------------------------
                 [com.taoensso/timbre "6.1.0"]]

  :plugins [[lein-environ "1.2.0"]                          ; make sure to change intellij repl run options to "run it with lein"
            [lein-ring "0.12.6"]
            [lein-eftest "0.6.0"]]
  :profiles {:kaocha {:dependencies [[lambdaisland/kaocha "1.75.1190"]]}}
  :aliases {"ktest" ["with-profile" "+kaocha" "run" "-m" "kaocha.runner" "--reporter" "kaocha.report.progress/report"]}
  :repl-options {:init-ns beholder.handlers}
  :ring {:handler beholder.handlers/app})

[ptaoussanis]

@gdulus Hi Paweł, thanks for the detailed info - that's helpful 👍

No obvious cause comes to mind from Timbre's end, but I can reproduce on my end with the deps I happened to have loaded:

[com.taoensso/timbre "6.1.0"]
[cider/cider-nrepl  "0.30.0"]
[nrepl "1.0.0"]

and the Cider 1.6.0 Emacs package.

Calling (cider-ns-reload-all) results in the same exception:

Exception updating the ns-cache #error {
 :cause No implementation of method: :send of protocol: #'nrepl.transport/Transport found for class: nrepl.middleware.print$printing_transport$reify__21736
[...]

Seems plausible that something in Timbre's implementation is tripping up CIDER or nrepl, etc. - but can't say off-hand.

I'm actually not familiar with cider-ns-reload-all, and there's nothing immediately obvious to me in the stacktrace - so will need to take a proper look.

Am just focused on some other tasks for today, but will try take a look at this in the next couple days and come back to you.

[gdulus]

@ptaoussanis Thank you and no worries about the timeline

[ptaoussanis]

@gdulus Hi Paweł,

Interesting- so I just came back to this to investigate, and now I've been unable to reproduce the problem. Not sure if I'm missing something obvious.

Would you please check the test repo that I've uploaded and see if you can reproduce the error on your side?

Steps I've been trying:

1. Run lein repl :headless with [nrepl "1.0.0"] dep in my .lein/profiles.clj and the the Cider 1.6.0 Emacs package.
2. Run cider-connect from Emacs to connect to the above REPL.
3. Open beholder.handlers namespace and run (cider-ns-reload-all) from Emacs.

Currently, that's triggering a successful ns reload for me.

I see from your example that you're running a snapshot release of Cider?
Assuming the above steps actually trigger the exception for you (?), could you please try with a stable Cider release and let me know what happens there?

Thanks

[gdulus]

Hey @ptaoussanis
I have checked your example repo with the current version of my Doom Emacs (v3.0.0-pre) and it crashed with the same exception.

In the next couple of days, I will do the same for the version with Cider 1.6.0 as this means I need to downgrade Doom Emacs to the version shipped with the stable version of Cider)

[bclark-videra]

I'm able to reproduce this error using the test repo without Cider. Hopefully the following steps make it easier to track down.

Since Cider (and other editors that jack in) is adding cider-nrepl middleware, I made this change to project.clj to include that middleware:

diff --git a/project.clj b/project.clj
index 8915e04..f93a547 100644
--- a/project.clj
+++ b/project.clj
@@ -26,4 +26,5 @@
   :plugins
   [[lein-environ "1.2.0"]
    [lein-ring "0.12.6"]
-   [lein-eftest "0.6.0"]])
+   [lein-eftest "0.6.0"]
+   [cider/cider-nrepl "0.30.0"]])

Then I ran lein repl.

In the repl:

nREPL server started on port 52812 on host 127.0.0.1 - nrepl://127.0.0.1:52812
REPL-y 0.5.1, nREPL 1.0.0
Clojure 1.11.1
OpenJDK 64-Bit Server VM 20.0.1
    Docs: (doc function-name-here)
          (find-doc "part-of-name-here")
  Source: (source function-name-here)
 Javadoc: (javadoc java-object-or-class-here)
    Exit: Control+D or (exit) or (quit)
 Results: Stored in vars *1, *2, *3, an exception in *e

user=> (require '[beholder.handlers] :reload-all)
Loading initial Timbre config from: :default
nil
user=> Exception updating the ns-cache #error {
 :cause No implementation of method: :send of protocol: #'nrepl.transport/Transport found for class: nrepl.middleware.caught$caught_transport$reify__1208
 :via
 [{:type java.lang.IllegalArgumentException
   :message No implementation of method: :send of protocol: #'nrepl.transport/Transport found for class: nrepl.middleware.caught$caught_transport$reify__1208
   :at [clojure.core$_cache_protocol_fn invokeStatic core_deftype.clj 584]}]
 :trace
 [[clojure.core$_cache_protocol_fn invokeStatic core_deftype.clj 584]
  [clojure.core$_cache_protocol_fn invoke core_deftype.clj 576]
  [nrepl.transport$eval18178$fn__18196$G__18169__18203 invoke transport.clj 23]
  [clojure.lang.Var invoke Var.java 388]
  [cider.nrepl.middleware.track_state$update_and_send_cache$fn__6971 invoke track_state.clj 213]
  [cider.nrepl.middleware.track_state$update_and_send_cache invokeStatic track_state.clj 209]
  [cider.nrepl.middleware.track_state$update_and_send_cache invoke track_state.clj 159]
  [cider.nrepl.middleware.track_state$update_and_send_cache invokeStatic track_state.clj 181]
  [cider.nrepl.middleware.track_state$update_and_send_cache invoke track_state.clj 159]
  [clojure.lang.AFn applyToHelper AFn.java 156]
  [clojure.lang.AFn applyTo AFn.java 144]
  [clojure.core$apply invokeStatic core.clj 669]
  [clojure.core$update_in$up__6922 invoke core.clj 6220]
  [clojure.core$update_in invokeStatic core.clj 6221]
  [clojure.core$update_in doInvoke core.clj 6207]
  [clojure.lang.RestFn applyTo RestFn.java 146]
  [clojure.core$apply invokeStatic core.clj 673]
  [clojure.core$binding_conveyor_fn$fn__5823 doInvoke core.clj 2058]
  [clojure.lang.RestFn applyTo RestFn.java 146]
  [clojure.lang.Agent$Action doRun Agent.java 114]
  [clojure.lang.Agent$Action run Agent.java 163]
  [java.util.concurrent.ThreadPoolExecutor runWorker ThreadPoolExecutor.java 1144]
  [java.util.concurrent.ThreadPoolExecutor$Worker run ThreadPoolExecutor.java 642]
  [java.lang.Thread run Thread.java 1623]]}

I also tried changing versions of timbre in the test project:

• 5.2.1: no error
• 6.0.0: error
• 6.1.0: error

[ptaoussanis]

@bclark-videra Hi Byron, thanks for the assistance on this!

I can confirm that adding [cider/cider-nrepl "0.30.0"] to the test repo's project.clj :plugins seems to do the trick, I can now reproduce on my side 👍

Will try investigate further.

[ptaoussanis]

@gdulus @bclark-videra So it looks like the cause of the trouble was an update to one of Timbre's dependencies.

Until the upstream issue can be fixed, you can temporarily work around the problem by adding the following dependency to your project.clj before Timbre: [io.aviso/pretty "1.1.1"].

This will force the old dependency to be used, the same one that was included with Timbre v5.x.

Apologies for the trouble, and thanks again for the report and assistance with debugging!

[bclark-videra]

Thanks for tracking down the underlying cause, @ptaoussanis, even though it wasn't in timbre.

[ptaoussanis]

Will be addressed in a new Timbre release that I'll be pushing shortly, marking as done.