Fix #1679: issue with wrapping taoensso.timbre/log! (#1683)

CHANGELOG.md

@@ -7,6 +7,10 @@ A preview of the next release can be installed from
 
 [Babashka](https://github.com/babashka/babashka): Native, fast starting Clojure interpreter for scripting
 
+## Unreleased
+
+- Fix #1679: fix wrapping `timbre/log!`
+
 ## 1.3.189 (2024-02-22)
 
 - [#1660](https://github.com/babashka/babashka/issues/1660): add `:deps-root` as part of hash to avoid caching issue with `deps.clj`

deps.edn

@@ -45,7 +45,7 @@
         hiccup/hiccup {:mvn/version "2.0.0-RC1"}
         rewrite-clj/rewrite-clj {:mvn/version "1.1.47"}
         selmer/selmer {:mvn/version "1.12.59"}
-        com.taoensso/timbre {:mvn/version "6.0.1"}
+        com.taoensso/timbre {:mvn/version "6.5.0"}
         org.clojure/tools.logging {:mvn/version "1.1.0"}
         org.clojure/data.priority-map {:mvn/version "1.1.0"}
         insn/insn {:mvn/version "0.5.2"}

feature-logging/babashka/impl/logging.clj

@@ -13,56 +13,78 @@
 
 (defn- fline [and-form] (:line (meta and-form)))
 
+(defonce callsite-counter
+  (enc/counter))
+
 (defmacro log! ; Public wrapper around `-log!`
-  "Core low-level log macro. Useful for tooling, etc.
+  "Core low-level log macro. Useful for tooling/library authors, etc.
-    * `level`    - must eval to a valid logging level
-    * `msg-type` - must eval to e/o #{:p :f nil}
-    * `opts`     - ks e/o #{:config :?err :?ns-str :?file :?line :?base-data :spying?}
-  Supports compile-time elision when compile-time const vals
-  provided for `level` and/or `?ns-str`."
-  [level msg-type args & [opts]]
-  (have [:or nil? sequential?] args) ; To allow -> (delay [~@args])
-  (let [{:keys [?ns-str] :or {?ns-str (str @sci/ns)}} opts]
-    ;; level, ns may/not be compile-time consts:
-    (when-not (timbre/-elide? level ?ns-str)
-      (let [{:keys [config ?err ?file ?line ?base-data spying?]
-             :or   {config 'taoensso.timbre/*config*
-                    ?err   :auto ; => Extract as err-type v0
-                    ?file  @sci/file
-                    ;; NB waiting on CLJ-865:
-                    ?line (fline &form)}} opts
 
-            ?file (when (not= ?file "NO_SOURCE_PATH") ?file)
+       * `level`    - must eval to a valid logging level
+       * `msg-type` - must eval to e/o #{:p :f nil}
+       * `args`     - arguments seq (ideally vec) for logging call
+       * `opts`     - ks e/o #{:config ?err ?base-data spying?
+                               :?ns-str :?file :?line :?column}
 
-            ;; Identifies this particular macro expansion; note that this'll
+     Supports compile-time elision when compile-time const vals
-            ;; be fixed for any fns wrapping `log!` (notably `tools.logging`,
+     provided for `level` and/or `?ns-str`.
-            ;; `slf4j-timbre`, etc.):
-            callsite-id
-            (hash [level msg-type args ; Unevaluated args (arg forms)
-                   ?ns-str ?file ?line (rand)])]
 
-        `(taoensso.timbre/-log! ~config ~level ~?ns-str ~?file ~?line ~msg-type ~?err
+     Logging wrapper examples:
-                                (delay [~@args]) ~?base-data ~callsite-id ~spying?)))))
+
+       (defn     log-wrapper-fn    [& args]                        (timbre/log! :info :p  args))
+       (defmacro log-wrapper-macro [& args] (timbre/keep-callsite `(timbre/log! :info :p ~args)))"
+
+  ([{:as   opts
+     :keys [loc level msg-type args vargs
+            config ?err ?base-data spying?]
+     :or
+     {config 'taoensso.timbre/*config*
+      ?err   :auto}}]
+
+   (have [:or nil? sequential? symbol?] args)
+   (let [callsite-id (callsite-counter)
+         {:keys [line column]} (merge (meta &form) loc)
+         {:keys [ns file line column]} {:ns @sci/ns :file @sci/file :line line :column column}
+         ns     (or (get opts :?ns-str) ns)
+         file   (or (get opts :?file)   file)
+         line   (or (get opts :?line)   line)
+         column (or (get opts :?column) column)
+
+         elide? (and #_(enc/const-forms? level ns) (timbre/-elide? level ns))]
+
+     (when-not elide?
+       (let [vargs-form
+             (or vargs
+                 (if (symbol? args)
+                   `(taoensso.timbre/-ensure-vec ~args)
+                   `[              ~@args]))]
+
+         ;; Note pre-resolved expansion
+         `(taoensso.timbre/-log! ~config ~level ~ns ~file ~line ~column ~msg-type ~?err
+                                 (delay ~vargs-form) ~?base-data ~callsite-id ~spying?)))))
+
+  ([level msg-type args & [opts]]
+   (let [{:keys [line column]} (merge (meta &form))
+         {:keys [ns file line column]} {:ns @sci/ns :file @sci/file :line line :column column}
+         loc  {:ns ns :file file :line line :column column}
+         opts (assoc (conj {:loc loc} opts)
+                     :level level, :msg-type msg-type, :args args)]
+     `(taoensso.timbre/log! ~opts))))
 
 (defn make-ns [ns sci-ns ks]
   (reduce (fn [ns-map [var-name var]]
             (let [m (meta var)
-                  no-doc (:no-doc m)
                   doc (:doc m)
                   arglists (:arglists m)]
-              (if no-doc ns-map
+              (assoc ns-map var-name
-                  (assoc ns-map var-name
+                     (sci/new-var (symbol var-name) @var
-                         (sci/new-var (symbol var-name) @var
+                                  (cond-> {:ns sci-ns
-                                      (cond-> {:ns sci-ns
+                                           :name (:name m)}
-                                               :name (:name m)}
+                                    (:macro m) (assoc :macro true)
-                                        (:macro m) (assoc :macro true)
+                                    doc (assoc :doc doc)
-                                        doc (assoc :doc doc)
+                                    arglists (assoc :arglists arglists))))))
-                                        arglists (assoc :arglists arglists)))))))
           {}
           (select-keys (ns-publics ns) ks)))
 
-(def atomic-println @#'appenders/atomic-println)
-
 (defn println-appender
   "Returns a simple `println` appender for Clojure/Script.
   Use with ClojureScript requires that `cljs.core/*print-fn*` be set.
@@ -92,7 +114,7 @@
                :*err* @sci/err
                stream)]
          (binding [*out* stream]
-           (atomic-println (force output_)))))}))
+           (enc/println-atomic (force output_)))))}))
 
 (def default-config (assoc-in timbre/*config* [:appenders :println]
                               (println-appender {:stream :auto})))
@@ -127,7 +149,8 @@
          'merge-config! (sci/copy-var merge-config! tns)
          'set-level! (sci/copy-var set-level! tns)
          'println-appender (sci/copy-var println-appender tns)
-         '-log-and-rethrow-errors (sci/copy-var -log-and-rethrow-errors tns)))
+         '-log-and-rethrow-errors (sci/copy-var -log-and-rethrow-errors tns)
+         '-ensure-vec (sci/copy-var enc/ensure-vec tns)))
 
 (def timbre-appenders-namespace
   (let [tan (sci/create-ns 'taoensso.timbre.appenders.core nil)]

project.clj

@@ -74,7 +74,7 @@
              :feature/selmer {:source-paths ["feature-selmer"]
                               :dependencies [[selmer/selmer "1.12.59"]]}
              :feature/logging {:source-paths ["feature-logging"]
-                               :dependencies [[com.taoensso/timbre "6.0.4"]
+                               :dependencies [[com.taoensso/timbre "6.5.0"]
                                               [org.clojure/tools.logging "1.1.0"]]}
              :feature/priority-map {:source-paths ["feature-priority-map"]
                                     :dependencies [[org.clojure/data.priority-map "1.1.0"]]}

resources/META-INF/babashka/deps.edn

@@ -45,7 +45,7 @@
         hiccup/hiccup {:mvn/version "2.0.0-RC1"}
         rewrite-clj/rewrite-clj {:mvn/version "1.1.47"}
         selmer/selmer {:mvn/version "1.12.59"}
-        com.taoensso/timbre {:mvn/version "6.0.1"}
+        com.taoensso/timbre {:mvn/version "6.5.0"}
         org.clojure/tools.logging {:mvn/version "1.1.0"}
         org.clojure/data.priority-map {:mvn/version "1.1.0"}
         insn/insn {:mvn/version "0.5.2"}

test/babashka/logging_test.clj

@@ -44,7 +44,7 @@
 
 (deftest logging-test
   (let [res (tu/bb nil (pr-str program))]
-    (is (= 17 (count (re-seq #"\[dude:.\]" res))))
+    (is (= 8 (count (re-seq #"\[dude:.\]" res))))
     (is (= 6 (count (re-seq #"DEBUG" res))))
     (is (= 11 (count (re-seq #"INFO" res)))))
   (testing "println appender works with with-out-str"
@@ -110,3 +110,11 @@
       (is (= 3 (count (re-seq #"\"test warn\"" res)))))
     (testing "lists are printed readably"
       (is (= 2 (count (re-seq #"\(\\a \\b\)" res)))))))
+
+(deftest timbre-log!-test
+  (is (str/includes? (tu/bb nil
+                            (pr-str '(do (require '[taoensso.timbre :as timbre])
+                                         (defn log-wrapper [& args]
+                                           (timbre/log! :info :p args))
+                                         (log-wrapper "hallo"))))
+                     "hallo")))