[fix] Timbre->Telemere appender: don't duplicate output formatting

BEFORE this commit:

  The Timbre->Telemere appender produced duplicate preamble output
  (timestamp, namespace, etc.). Both Timbre AND Telemere were adding
  preamble info.

AFTER this commit:

  Now ONLY Telemere adds preamble info.
  Timbre's `:output-fn` is ignored.

CHANGELOG.md

@@ -1,6 +1,7 @@
 This project uses [**Break Versioning**](https://www.taoensso.com/break-versioning).
 
 ---
+
 # `v1.1.0` (2025-08-22)
 
 ## 📦 Dependencies
@@ -12,6 +13,8 @@ Available on Clojars:
 
 This project uses [Break Versioning](https://www.taoensso.com/break-versioning).
 
+## Release notes
+
 This is a **maintenance release** that fixes a few minor issues, improves docs, and adds some extra API flexibility. It should be a safe upgrade for all users of v1.x.
 
 Please **report any unexpected problems** on [GitHub](https://github.com/taoensso/telemere/issues) or the [Slack channel](https://www.taoensso.com/telemere/slack) 🙏 - [Peter Taoussanis](https://www.taoensso.com)

README.md

@@ -1,5 +1,5 @@
 <a href="https://www.taoensso.com/clojure" title="More stuff by @ptaoussanis at www.taoensso.com"><img src="https://www.taoensso.com/open-source.png" alt="Taoensso open source" width="340"/></a>  
-[**API**][cljdoc] | [**Wiki**][GitHub wiki] | [Slack channel][] | Latest release: [v1.1.0](../../releases/tag/v1.1.0) (2025-08-22)
+[**API**][cljdoc] | [**Wiki**][GitHub wiki] | [Slack][] | Latest release: [v1.1.0](../../releases/tag/v1.1.0) (2025-08-22)
 
 [![Clj tests][Clj tests SVG]][Clj tests URL]
 [![Cljs tests][Cljs tests SVG]][Cljs tests URL]
@@ -314,7 +314,7 @@ See [here](../../wiki/8-Community) for community resources.
 - [Wiki][GitHub wiki] (getting started, usage, etc.)
 - API reference via [cljdoc][cljdoc]
 - Extensive [internal help](#internal-help) (no need to leave your IDE)
-- Support via [Slack channel][] or [GitHub issues][]
+- Support via [Slack][] or [GitHub issues][]
 - [General observability tips](../../wiki/7-Tips) (advice on building and maintaining observable Clojure/Script systems, and getting the most out of Telemere)
 
 ## Funding
@@ -331,7 +331,7 @@ Licensed under [EPL 1.0](LICENSE.txt) (same as Clojure).
 [GitHub releases]: ../../releases
 [GitHub issues]:   ../../issues
 [GitHub wiki]:     ../../wiki
-[Slack channel]:   https://www.taoensso.com/telemere/slack
+[Slack]:   https://www.taoensso.com/telemere/slack
 
 [Peter Taoussanis]: https://www.taoensso.com
 [sponsor]:          https://www.taoensso.com/sponsor

main/resources/docs/signal-options.txt

@@ -9,12 +9,12 @@ All options are available for all signal creator calls:
                  Defaults to `:auto` for tracing signals, and nil otherwise
 
 `:msg` --------- Arb app-level ?message to incl. in signal: str or vec of strs to join (with `\space`), may be a delay
-`:data` -------- Arb app-level ?data    to incl. in signal: usu. a map
+`:data` -------- Arb app-level ?data    to incl. in signal: usu. a map, LAZY! [3]
 `:error` ------- Arb app-level ?error   to incl. in signal: platform error [2]
 
 `:run` --------- ?form     to execute UNCONDITIONALLY; will incl. `:run-val` in signal
-`:do` ---------- ?form     to execute   conditionally (iff signal allowed), before establishing `:let` ?binding
+`:do` ---------- ?form     to execute   conditionally (iff signal allowed) and LAZILY [3], before establishing `:let` ?binding
-`:let` --------- ?bindings to establish conditionally (iff signal allowed), BEFORE evaluating `:data` and `:msg` (useful!)
+`:let` --------- ?bindings to establish conditionally (iff signal allowed) and LAZILY [3], BEFORE evaluating `:data` and `:msg` (useful!)
 
 `:parent` ------ Custom ?{:keys [id uid]} to override auto (dynamic) parent signal tracing info
 `:root` -------- Custom ?{:keys [id uid]} to override auto (dynamic) root   signal tracing info
@@ -37,9 +37,13 @@ All options are available for all signal creator calls:
 
 <kvs> ---------- Other arb app-level ?kvs to incl. in signal. Typically NOT included in
                  handler output, so a great way to provide custom data/opts for use
-                 (only) by custom transforms/handlers.
+                 (only) by custom transforms/handlers. LAZY! [3]
 
 If anything is unclear, please ping me (@ptaoussanis) so that I can improve these docs!
 
 [1] `java.time.Instant`   or `js/Date`
 [2] `java.lang.Throwable` or `js/Error`
+[3] Most Telemere signal content is evaluated CONDITIONALLY (iff signal allowed),
+    LAZILY (when signal is created), and on the HANDLING THREAD (not logging thread).
+    This allows efficient filtering, better control+monitoring of back pressure,
+    conditional effects, etc. Ref. <https://www.taoensso.com/telemere/flow> for visual!

main/src/taoensso/telemere/impl.cljc

@@ -170,8 +170,8 @@
 (defn default-trace-msg
   [form value error nsecs]
   (if error
-    (str form " !> " (truss/ex-type error))
+    (str (if (nil? form) "nil" form) " !> " (truss/ex-type error))
-    (str form " => " value)))
+    (str (if (nil? form) "nil" form) " => " (if (nil? value) "nil" value))))
 
 (comment
   (default-trace-msg "(+ 1 2)" 3   nil               12345)
@@ -524,14 +524,16 @@
             clj?  (not cljs?)
 
             opts (merge {:kind :generic, :level :info} base-opts opts)
-            {run-form :run} opts
+
+            run-form? (contains? opts :run)
+            run-form  (get       opts :run)
 
             ns-form* (get opts :ns :auto)
             ns-form  (auto-> ns-form* (str *ns*))
 
             show-run-val (get opts :run-val '_run-val)
             show-run-form
-            (when run-form
+            (when run-form?
               (get opts :run-form
                 (if (and
                       (enc/list-form? run-form)
@@ -564,7 +566,7 @@
                  id-form    :id
                  level-form :level} opts
 
-                trace? (get opts :trace? (boolean run-form))
+                trace? (get opts :trace? run-form?)
                 _
                 (when-not (contains? #{true false nil} trace?)
                   (truss/ex-info!
@@ -619,7 +621,7 @@
 
                       _ ; Compile-time validation
                       (do
-                        (when (and run-form error-form) ; Ambiguous source of error
+                        (when (and run-form? error-form) ; Ambiguous source of error
                           (truss/ex-info!
                             (str "Signal cannot have both `:run` and `:error` opts at "
                               (sigs/format-callsite ns-form coords))))
@@ -631,7 +633,7 @@
 
                       signal-form
                       (let [record-form
-                            (let   [clause [(if run-form :run :no-run) (if clj? :clj :cljs)]]
+                            (let   [clause [(if run-form? :run :no-run) (if clj? :clj :cljs)]]
                               (case clause
                                 [:run    :clj ]  `(Signal. 1 ~'__inst ~'__uid, ~'__ns ~coords ~host-form ~'__thread ~'__otel-context1, ~sample-form, ~'__kind ~'__id ~'__level, ~ctx-form ~parent-form ~'__root1, ~data-form ~kvs-form ~'_msg_,   ~'_run-err  '~show-run-form ~show-run-val ~'_end-inst ~'_run-nsecs)
                                 [:run    :cljs]  `(Signal. 1 ~'__inst ~'__uid, ~'__ns ~coords                                          ~sample-form, ~'__kind ~'__id ~'__level, ~ctx-form ~parent-form ~'__root1, ~data-form ~kvs-form ~'_msg_,   ~'_run-err  '~show-run-form ~show-run-val ~'_end-inst ~'_run-nsecs)
@@ -642,7 +644,7 @@
                                     (sigs/format-callsite ns-form coords)))))
 
                             record-form
-                            (if-not run-form
+                            (if-not run-form?
                               record-form
                               `(let [~(with-meta '_run-result {:tag `RunResult}) ~'__run-result
                                      ~'_run-nsecs (.-run-nsecs    ~'_run-result)
@@ -674,8 +676,8 @@
                          (do   signal#)))))
 
                 ;; Trade-off: avoid double `run-form` expansion
-                run-fn-form (when run-form `(fn [] ~run-form))
+                run-fn-form (when run-form? `(fn [] ~run-form))
-                run-form*   (when run-form `(~'__run-fn-form))
+                run-form*   (when run-form? `(~'__run-fn-form))
 
                 into-let-form
                 (enc/cond!
@@ -684,7 +686,7 @@
                     ~'__uid   ~(auto-> uid-form `(taoensso.telemere/*uid-fn* (if ~'__root0 false true)))
                     ~'__root1 ~'__root0 ; Retain, but don't establish
                     ~'__run-result
-                    ~(when run-form
+                    ~(when run-form?
                        `(let [t0# (enc/now-nano*)]
                           (truss/try*
                             (do            (RunResult. ~run-form* nil (- (enc/now-nano*) t0#)))
@@ -696,7 +698,7 @@
                     ~'__uid  ~(auto-> uid-form `(taoensso.telemere/*uid-fn* (if ~'__root0 false true)))
                     ~'__root1 (or ~'__root0 ~(when trace? `{:id ~'__id, :uid ~'__uid}))
                     ~'__run-result
-                    ~(when run-form
+                    ~(when run-form?
                        `(binding [*trace-root*   ~'__root1
                                   *trace-parent* {:id ~'__id, :uid ~'__uid}]
                           (let [t0# (enc/now-nano*)]
@@ -707,7 +709,7 @@
                   ;; Trace with OpenTelemetry
                   (and clj? enabled:otel-tracing?)
                   `[~'__otel-context0  ~(get opts :otel/context `(otel-context)) ; Context
-                    ~'__otel-context1  ~(if run-form `(otel-context+span ~'__id ~'__inst ~'__otel-context0 ~(get opts :otel/span-kind)) ~'__otel-context0)
+                    ~'__otel-context1  ~(if run-form? `(otel-context+span ~'__id ~'__inst ~'__otel-context0 ~(get opts :otel/span-kind)) ~'__otel-context0)
                     ~'__uid            ~(auto-> uid-form `(or (otel-span-id ~'__otel-context1) (com.taoensso.encore.Ids/genHexId16)))
                     ~'__root1
                     (or ~'__root0
@@ -715,7 +717,7 @@
                          `{:id ~'__id, :uid (or (otel-trace-id ~'__otel-context1) (com.taoensso.encore.Ids/genHexId32))}))
 
                     ~'__run-result
-                    ~(when run-form
+                    ~(when run-form?
                        `(binding [*otel-context* ~'__otel-context1
                                   *trace-root*   ~'__root1
                                   *trace-parent* {:id ~'__id, :uid ~'__uid}]

main/src/taoensso/telemere/open_telemetry.clj

@@ -219,15 +219,15 @@
 
       (if (or common-attrs trace-attrs)
         (let [ab (Attributes/builder)]
-          (when-let [ns   (get signal :ns)]    (.put ab "ns"   (str  ns)))
+          (when-let [ns   (get         signal :ns)]         (.put ab "ns"   (str  ns)))
-          (when-let [line (get signal :line)]  (.put ab "line" (long line)))
+          (when-let [line (enc/get-in* signal [:coords 0])] (.put ab "line" (long line)))
           (when-let [attrs common-attrs] (put-attrs! ab attrs))
           (when-let [attrs  trace-attrs] (put-attrs! ab attrs))
           (.build ab))
 
         ;; Common case
-        (when-let [ns   (get signal :ns)]
+        (when-let [ns   (get         signal :ns)]
-          (if-let [line (get signal :line)]
+          (if-let [line (enc/get-in* signal [:coords 0])]
             (Attributes/of ak-ns ns, ak-line (long line))
             (Attributes/of ak-ns ns)))))))
 

main/src/taoensso/telemere/timbre.cljc

@@ -35,21 +35,21 @@
                   (enc/format* pattern            vargs)
                   (enc/str-join " " (map arg-str) vargs)))]
 
-          [error msg {:vargs vargs}])
+          [error msg vargs])
 
         (let [md      (if (and (map? v0) (get (meta v0) :meta)) v0 nil)
-              error   (get md :err)
+              error   (get    md :err)
               md      (dissoc md :err)
-              vargs   (if md (enc/vrest vargs) vargs)
+              vargs   (if     md (enc/vrest vargs) vargs)
-              pattern (if format-msg? (let [[v0] vargs] v0) nil)
+              pattern (if format-msg? (let [[v0]   vargs] v0) nil)
-              vargs   (if format-msg? (enc/vrest vargs) vargs)
+              vargs   (if format-msg? (enc/vrest   vargs) vargs)
               msg
               (delay
                 (if format-msg?
                   (enc/format* pattern            vargs)
                   (enc/str-join " " (map arg-str) vargs)))]
 
-          [error msg (when-not (empty? vargs) {:vargs vargs})])))))
+          [error msg (when-not (empty? vargs) vargs)])))))
 
 (comment
   (parse-vargs true [                   "hello %s" "stu"])
@@ -63,13 +63,13 @@
      [level format-msg? vargs]
      (truss/keep-callsite
        `(when (impl/signal-allowed? {:kind :log, :level ~level, :id shim-id})
-          (let [[error# msg# data#] (parse-vargs ~format-msg? ~vargs)]
+          (let [[error# msg# vargs#] (parse-vargs ~format-msg? ~vargs)]
             (tel/log!
-              {:allow? true
+              {:allow?       true
-               :level  ~level
+               :level        ~level
-               :id     shim-id
+               :id           shim-id
-               :error  error#
+               :error        error#
-               :data   data#}
+               :timbre/vargs vargs#}
               msg#)
             nil)))))
 
@@ -190,8 +190,11 @@
    :min-level nil
    :fn
    (fn [data]
-     (let [{:keys [instant level context ?err output_
+     (let [{:keys [instant level context msg-type vargs
-                   ?ns-str ?file ?line ?column]} data]
+                   ?ns-str ?file ?line ?column]} data
+
+           format-msg? (enc/identical-kw? msg-type :f)
+           [error msg vargs] (parse-vargs format-msg? vargs)]
 
        (taoensso.telemere/signal!
          {:kind :timbre
@@ -200,9 +203,9 @@
           :ctx+  context
 
           :ns     ?ns-str
-          :file   ?file
+          :coords (when ?line [?line ?column])
-          :line   ?line
+          :file   ?file ; Non-standard, goes to kvs
-          :column ?column
 
-          :error  ?err
+          :error        error
-          :msg    (force output_)})))})
+          :msg          msg
+          :timbre/vargs vargs})))})

main/test/taoensso/telemere_tests.cljc

@@ -594,12 +594,13 @@
       (let [{rv :value, [sv] :signals} (with-sigs (tel/log!? {:allow? false}      "msg")) ] [(is (= rv nil))  (is (nil? sv))])])
 
    (testing "trace!" ; ?id + run => unconditional run result (value or throw)
-     [(let [{rv :value, [sv] :signals} (with-sigs (tel/trace!                 (+ 1 2))) ] [(is (= rv 3))  (is (sm?  sv {:kind :trace, :coords coords?, :level :info, :id  nil, :msg_ "(+ 1 2) => 3"}))])
+     [(let [{rv :value, [sv] :signals} (with-sigs (tel/trace!                     nil)) ] [(is (= rv nil)) (is (sm?  sv {:kind :trace, :coords coords?, :level :info, :id  nil, :msg_ "nil => nil"}))])
-      (let [{rv :value, [sv] :signals} (with-sigs (tel/trace! {:msg nil}      (+ 1 2))) ] [(is (= rv 3))  (is (sm?  sv {:kind :trace, :coords coords?, :level :info, :id  nil, :msg_ nil}))])
+      (let [{rv :value, [sv] :signals} (with-sigs (tel/trace!                 (+ 1 2))) ] [(is (= rv 3))   (is (sm?  sv {:kind :trace, :coords coords?, :level :info, :id  nil, :msg_ "(+ 1 2) => 3"}))])
-      (let [{rv :value, [sv] :signals} (with-sigs (tel/trace!      :id1       (+ 1 2))) ] [(is (= rv 3))  (is (sm?  sv {:kind :trace, :coords coords?, :level :info, :id :id1}))])
+      (let [{rv :value, [sv] :signals} (with-sigs (tel/trace! {:msg nil}      (+ 1 2))) ] [(is (= rv 3))   (is (sm?  sv {:kind :trace, :coords coords?, :level :info, :id  nil, :msg_ nil}))])
-      (let [{rv :value, [sv] :signals} (with-sigs (tel/trace! {:id :id1}      (+ 1 2))) ] [(is (= rv 3))  (is (sm?  sv {:kind :trace, :coords coords?, :level :info, :id :id1}))])
+      (let [{rv :value, [sv] :signals} (with-sigs (tel/trace!      :id1       (+ 1 2))) ] [(is (= rv 3))   (is (sm?  sv {:kind :trace, :coords coords?, :level :info, :id :id1}))])
-      (let [{rv :value, [sv] :signals} (with-sigs (tel/trace! {:id :id1, :run (+ 1 2)}))] [(is (= rv 3))  (is (sm?  sv {:kind :trace, :coords coords?, :level :info, :id :id1}))])
+      (let [{rv :value, [sv] :signals} (with-sigs (tel/trace! {:id :id1}      (+ 1 2))) ] [(is (= rv 3))   (is (sm?  sv {:kind :trace, :coords coords?, :level :info, :id :id1}))])
-      (let [{re :error, [sv] :signals} (with-sigs (tel/trace!      :id1        (ex1!))) ] [(is (ex1? re)) (is (sm?  sv {:kind :trace, :coords coords?, :level :info, :id :id1, :error ex1,
+      (let [{rv :value, [sv] :signals} (with-sigs (tel/trace! {:id :id1, :run (+ 1 2)}))] [(is (= rv 3))   (is (sm?  sv {:kind :trace, :coords coords?, :level :info, :id :id1}))])
+      (let [{re :error, [sv] :signals} (with-sigs (tel/trace!      :id1        (ex1!))) ] [(is (ex1? re))  (is (sm?  sv {:kind :trace, :coords coords?, :level :info, :id :id1, :error ex1,
                                                                                                            :msg_ #?(:clj  "(ex1!) !> clojure.lang.ExceptionInfo"
                                                                                                                     :cljs "(ex1!) !> cljs.core/ExceptionInfo")}))])
       (let [{rv :value, [sv] :signals} (with-sigs (tel/trace! {:allow? false} (+ 1 2)))] [(is (= rv 3)) (is (nil? sv))])
@@ -753,15 +754,15 @@
 ;;;; Timbre shim
 
 (deftest _timbre-shim
-  [(is (sm? (with-sig (timbre/log :warn              "x1" nil "x2")) {:kind :log, :level :warn,  :id timbre/shim-id, :msg_ "x1 nil x2", :data {:vargs ["x1" nil "x2"]}, :ns string?}))
+  [(is (sm? (with-sig (timbre/log :warn              "x1" nil "x2")) {:kind :log, :level :warn,  :id timbre/shim-id, :msg_ "x1 nil x2", :timbre/vargs ["x1" nil "x2"], :ns string?}))
-   (is (sm? (with-sig (timbre/info                   "x1" nil "x2")) {:kind :log, :level :info,  :id timbre/shim-id, :msg_ "x1 nil x2", :data {:vargs ["x1" nil "x2"]}, :ns string?}))
+   (is (sm? (with-sig (timbre/info                   "x1" nil "x2")) {:kind :log, :level :info,  :id timbre/shim-id, :msg_ "x1 nil x2", :timbre/vargs ["x1" nil "x2"], :ns string?}))
-   (is (sm? (with-sig (timbre/error                  "x1" nil "x2")) {:kind :log, :level :error, :id timbre/shim-id, :msg_ "x1 nil x2", :data {:vargs ["x1" nil "x2"]}, :ns string?}))
+   (is (sm? (with-sig (timbre/error                  "x1" nil "x2")) {:kind :log, :level :error, :id timbre/shim-id, :msg_ "x1 nil x2", :timbre/vargs ["x1" nil "x2"], :ns string?}))
 
-   (is (sm? (with-sig (timbre/logf :warn  "%s %s %s" "x1" nil "x2")) {:kind :log, :level :warn,  :id timbre/shim-id, :msg_ "x1 nil x2", :data {:vargs ["x1" nil "x2"]}, :ns string?}))
+   (is (sm? (with-sig (timbre/logf :warn  "%s %s %s" "x1" nil "x2")) {:kind :log, :level :warn,  :id timbre/shim-id, :msg_ "x1 nil x2", :timbre/vargs ["x1" nil "x2"], :ns string?}))
-   (is (sm? (with-sig (timbre/infof       "%s %s %s" "x1" nil "x2")) {:kind :log, :level :info,  :id timbre/shim-id, :msg_ "x1 nil x2", :data {:vargs ["x1" nil "x2"]}, :ns string?}))
+   (is (sm? (with-sig (timbre/infof       "%s %s %s" "x1" nil "x2")) {:kind :log, :level :info,  :id timbre/shim-id, :msg_ "x1 nil x2", :timbre/vargs ["x1" nil "x2"], :ns string?}))
-   (is (sm? (with-sig (timbre/errorf      "%s %s %s" "x1" nil "x2")) {:kind :log, :level :error, :id timbre/shim-id, :msg_ "x1 nil x2", :data {:vargs ["x1" nil "x2"]}, :ns string?}))
+   (is (sm? (with-sig (timbre/errorf      "%s %s %s" "x1" nil "x2")) {:kind :log, :level :error, :id timbre/shim-id, :msg_ "x1 nil x2", :timbre/vargs ["x1" nil "x2"], :ns string?}))
 
-   (is (sm? (with-sig (timbre/info ex1 "x1" "x2")) {:kind :log, :level :info, :error ex1, :msg_ "x1 x2", :data {:vargs ["x1" "x2"]}}) "First-arg error")
+   (is (sm? (with-sig (timbre/info ex1 "x1" "x2")) {:kind :log, :level :info, :error ex1, :msg_ "x1 x2", :timbre/vargs ["x1" "x2"]}) "First-arg error")
 
    (is (sm?                            (with-sig (timbre/spy :info "my-name" (+ 1 2))) {:kind :spy, :level :info,  :id timbre/shim-id, :msg_ "my-name => 3", :ns string?}))
    (is (sm? (tel/with-min-level :debug (with-sig (timbre/spy (+ 1 2))))                {:kind :spy, :level :debug, :id timbre/shim-id, :msg_ "(+ 1 2) => 3", :ns string?}))