[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.

main/project.clj

@@ -1,4 +1,4 @@
-(defproject com.taoensso/telemere "1.2.0-SNAPSHOT"
+(defproject com.taoensso/telemere "1.1.0"
   :author "Peter Taoussanis <https://www.taoensso.com>"
   :description "Structured logs and telemetry for Clojure/Script"
   :url "https://www.taoensso.com/telemere"
@@ -50,7 +50,7 @@
      [org.clojure/test.check        "1.1.1"]
      [org.clojure/tools.logging     "1.3.0"]
      [org.slf4j/slf4j-api           "2.0.17"]
-     [com.taoensso/telemere-slf4j   "1.2.0-SNAPSHOT"]
+     [com.taoensso/telemere-slf4j   "1.1.0"]
      #_[org.slf4j/slf4j-simple      "2.0.16"]
      #_[org.slf4j/slf4j-nop         "2.0.16"]
      #_[io.github.paintparty/bling  "0.4.2"]

main/resources/docs/signal-options.txt

@@ -26,7 +26,7 @@ All options are available for all signal creator calls:
 
 `:elidable?` --- Should signal be subject to compile-time elision? (default true)
 `:allow?` ------ Custom override for usual runtime filtering (true => ALWAYS create signal)
-`:trace?` ------ Should tracing be enabled for this signal? (default true iff `:run` provided or OpenTelemetry tracing enabled)
+`:trace?` ------ Should tracing be enabled for `:run` form?
 
 `:sample` ------ Sample ?rate ∈ℝ[0,1] for random signal sampling (0.75 => allow 75% of signals, nil => allow all)
 `:when` -------- Arb ?form; when present, form must return truthy to allow signal

main/src/taoensso/telemere/impl.cljc

@@ -38,10 +38,7 @@
      (def enabled:otel-tracing?
        "Documented at `taoensso.telemere/otel-tracing?`."
        (enc/get-env {:as :bool, :default present:otel?}
-         :taoensso.telemere/otel-tracing<.platform>))
-
-     (def enabled:incl-host-info?   "Include `:host` info in signals by default?"   (enc/get-env {:as :bool, :default true} :taoensso.telemere/incl-host-info))
-     (def enabled:incl-thread-info? "Include `:thread` info in signals by default?" (enc/get-env {:as :bool, :default true} :taoensso.telemere/incl-thread-info))))
+         :taoensso.telemere/otel-tracing<.platform>))))
 
 (def uid-kind
   "Documented at `taoensso.telemere/*uid-fn*`."
@@ -569,19 +566,16 @@
                  id-form    :id
                  level-form :level} opts
 
-                otel?         (get opts :otel? (and clj? present:otel?)) ; Undocumented
-                otel-tracing? (and otel? enabled:otel-tracing?)
-
-                trace? (get opts :trace? (or run-form? otel-tracing?))
+                trace? (get opts :trace? run-form?)
                 _
                 (when-not (contains? #{true false nil} trace?)
                   (truss/ex-info!
                     (str "Signal needs compile-time `:trace?` value at "
                       (sigs/format-callsite ns-form coords))))
 
-                host-form   (auto-> (get opts :host   :auto) (when (and clj? enabled:incl-host-info?)   `(enc/host-info)))
-                thread-form (auto-> (get opts :thread :auto) (when (and clj? enabled:incl-thread-info?) `(enc/thread-info)))
-                inst-form   (auto-> (get opts :inst   :auto) `(enc/now-inst*))
+                host-form   (auto-> (get opts :host   :auto) (when clj? `(enc/host-info)))
+                thread-form (auto-> (get opts :thread :auto) (when clj? `(enc/thread-info)))
+                inst-form   (auto-> (get opts :inst   :auto)            `(enc/now-inst*))
 
                 parent-form (get opts :parent `*trace-parent*)
                 root-form0  (get opts :root   `*trace-root*)
@@ -615,9 +609,9 @@
                               (dissoc opts
                                 :elidable? :coords :inst :uid :xfn :xfn+ :kvs+,
                                 :sample :ns :kind :id :level :filter :when #_:limit #_:limit-by,
-                                :ctx :ctx+ :parent :trace?, :do :let :data :msg :error,
+                                :ctx :ctx+ :parent #_:trace?, :do :let :data :msg :error,
                                 :run :run-form :run-val, :elide? :allow? #_:callsite-id,
-                                :host :thread :otel? :otel/context))]
+                                :host :thread :otel/context))]
 
                         (if-let [kvs+ (get opts :kvs+)] ; Undocumented
                           (if base
@@ -699,7 +693,7 @@
                             (catch :all t# (RunResult. nil        t#  (- (enc/now-nano*) t0#))))))]
 
                   ;; Trace without OpenTelemetry
-                  (or cljs? (not otel-tracing?))
+                  (or cljs? (not enabled:otel-tracing?))
                   `[~'__otel-context1 nil
                     ~'__uid  ~(auto-> uid-form `(taoensso.telemere/*uid-fn* (if ~'__root0 false true)))
                     ~'__root1 (or ~'__root0 ~(when trace? `{:id ~'__id, :uid ~'__uid}))
@@ -713,9 +707,9 @@
                               (catch :all t# (RunResult. nil        t#  (- (enc/now-nano*) t0#)))))))]
 
                   ;; Trace with OpenTelemetry
-                  (and clj? otel-tracing?)
+                  (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

main/src/taoensso/telemere/timbre.cljc

@@ -206,7 +206,6 @@
           :coords (when ?line [?line ?column])
           :file   ?file ; Non-standard, goes to kvs
 
-          :error  error
-          :msg    (when msg-type msg)
-
+          :error        error
+          :msg          msg
           :timbre/vargs vargs})))})

main/test/taoensso/telemere_tests.cljc

@@ -447,10 +447,10 @@
         (let [sv (with-sig (sig! {:level :info, :parent {:uid :uid1, :foo :bar}}))] (is (sm? sv {:parent {:id :submap/nx :uid      :uid1, :foo :bar}}) "Manual `:parent/uid`"))
         (let [sv (with-sig (sig! {:level :info, :root   {:id   :id1, :foo :bar}}))] (is (sm? sv {:root   {:id :id1       :uid :submap/nx, :foo :bar}}) "Manual `:root/id`"))
         (let [sv (with-sig (sig! {:level :info, :root   {:uid :uid1, :foo :bar}}))] (is (sm? sv {:root   {:id :submap/nx :uid      :uid1, :foo :bar}}) "Manual `:root/uid`"))
-        (let [sv (with-sig (sig! {:level :info, :otel? false}))                   ] (is (sm? sv {:uid nil})))
+        (let [sv (with-sig (sig! {:level :info}))                                 ] (is (sm? sv {:uid nil})))
         (let [sv (with-sig (sig! {:level :info, :uid :auto}))                     ] (is (sm? sv {:uid string?})))
         (let [sv (binding [tel/*uid-fn* (fn [_] "my-uid")]
-                   (with-sig (sig! {:level :info, :uid :auto, :otel? false})))    ] (is (sm? sv {:uid "my-uid"})))])
+                   (with-sig (sig! {:level :info, :uid :auto})))                  ] (is (sm? sv {:uid "my-uid"})))])
 
      (testing "Auto parent/root"
        [(testing "Tracing disabled"
@@ -727,7 +727,7 @@
                (is (sm? (with-sig (-> (.atWarn sl) (.log "Hello"))) {:level :warn, :ns "my.class", :kind :slf4j, :msg_ "Hello", :inst enc/inst?}) "Fluent API: warn basics")])
 
             (testing "Message formatting"
-             (let [msgp "x={},y={}", expected {:msg_ "x=1,y=2", :slf4j/args (fn [objs] (= (vec objs) ["1" "2"]))}]
+             (let [msgp "x={},y={}", expected {:msg_ "x=1,y=2", :data {:slf4j/args ["1" "2"]}}]
                [(is (sm? (with-sig (.info sl msgp "1" "2"))                                                           expected) "Legacy API: formatted message, raw args")
                 (is (sm? (with-sig (-> (.atInfo sl) (.setMessage msgp) (.addArgument "1") (.addArgument "2") (.log))) expected) "Fluent API: formatted message, raw args")]))
 
@@ -738,8 +738,8 @@
                     m2 (#'slf4j/est-marker! "M2")
                     cm (#'slf4j/est-marker! "Compound" "M1" "M2")]
 
-                [(is (sm? (with-sig (.info sl cm "Hello"))                                    {:slf4j/markers #{"Compound" "M1" "M2"}}) "Legacy API: markers")
-                 (is (sm? (with-sig (-> (.atInfo sl) (.addMarker m1) (.addMarker cm) (.log))) {:slf4j/markers #{"Compound" "M1" "M2"}}) "Fluent API: markers")]))
+                [(is (sm? (with-sig (.info sl cm "Hello"))                                    {:data {:slf4j/marker-names #{"Compound" "M1" "M2"}}}) "Legacy API: markers")
+                 (is (sm? (with-sig (-> (.atInfo sl) (.addMarker m1) (.addMarker cm) (.log))) {:data {:slf4j/marker-names #{"Compound" "M1" "M2"}}}) "Fluent API: markers")]))
 
             (testing "Errors"
               [(is (sm? (with-sig (.warn sl "An error" ^Throwable ex1))     {:level :warn, :error ex1}) "Legacy API: errors")
@@ -882,7 +882,7 @@
              (is (= ((tel/pr-signal-fn {:pr-fn (fn [_] "str")}) sig) (str "str" utils/newline))))]))
 
       (testing "format-signal-fn"
-        (let [sig (with-sig :raw :trap (tel/event! ::ev-id {:inst t1, :msg ["a" "b"], :otel? false}))]
+        (let [sig (with-sig :raw :trap (tel/event! ::ev-id {:inst t1, :msg ["a" "b"]}))]
           [(is (enc/str-starts-with? ((tel/format-signal-fn)         sig       ) "2024-01-01T01:01:01.110Z INFO EVENT"))
            (is (enc/str-ends-with?   ((tel/format-signal-fn) (dissoc sig :host)) "::ev-id a b\n"))]))])])
 

slf4j/project.clj

@@ -1,4 +1,4 @@
-(defproject com.taoensso/telemere-slf4j "1.2.0-SNAPSHOT"
+(defproject com.taoensso/telemere-slf4j "1.1.0"
   :author "Peter Taoussanis <https://www.taoensso.com>"
   :description "Telemere backend/provider for SLF4J API v2"
   :url "https://www.taoensso.com/telemere"
@@ -18,7 +18,7 @@
    {:dependencies
     [[org.clojure/clojure   "1.12.1"]
      [org.slf4j/slf4j-api   "2.0.17"]
-     [com.taoensso/telemere "1.2.0-SNAPSHOT"]]}
+     [com.taoensso/telemere "1.1.0"]]}
 
    :dev
    {:plugins

slf4j/src/taoensso/telemere/slf4j.clj

@@ -63,13 +63,13 @@
 
 (comment [(est-marker! "a1" "a2") (get-marker  "a1") (= (get-marker "a1") (get-marker "a1"))])
 
-(def ^:private get-marker-names
+(def ^:private marker-names
   "Returns #{<MarkerName>}. Cached => assumes markers NOT modified after creation."
   ;; We use `BasicMarkerFactory` so:
   ;;   1. Our markers are just labels (no other content besides their name).
   ;;   2. Markers with the same name are identical (enabling caching).
   (enc/fmemoize
-    (fn get-marker-names             [marker-or-markers]
+    (fn marker-names [marker-or-markers]
       (if (instance? org.slf4j.Marker marker-or-markers)
 
         ;; Single marker
@@ -79,15 +79,15 @@
           (if-not (.hasReferences m)
             acc
             (enc/reduce-iterator!
-              (fn [acc      ^org.slf4j.Marker in]
-                (if-not   (.hasReferences     in)
-                  (conj acc (.getName         in))
-                  (into acc (get-marker-names in))))
+              (fn [acc  ^org.slf4j.Marker in]
+                (if-not   (.hasReferences in)
+                  (conj acc (.getName     in))
+                  (into acc (marker-names in))))
               acc (.iterator m))))
 
         ;; Vector of markers
         (reduce
-          (fn [acc in] (into acc (get-marker-names in)))
+          (fn [acc in] (into acc (marker-names in)))
           #{} (truss/have vector? marker-or-markers))))))
 
 (comment
@@ -97,9 +97,9 @@
         ms [m1 m2]]
 
     (enc/qb 1e6 ; [45.52 47.48 44.85]
-      (get-marker-names m1)
-      (get-marker-names cm)
-      (get-marker-names ms))))
+      (marker-names m1)
+      (marker-names cm)
+      (marker-names ms))))
 
 ;;;; Interop fns (called by `TelemereLogger`)
 
@@ -132,10 +132,11 @@
        (org.slf4j.helpers.MessageFormatter/basicArrayFormat
          msg-pattern args))
 
-     :slf4j/args    args ; Object[]
-     :slf4j/markers marker-names ; Usu. used for routing, filtering, xfns, etc.
-     :data (when kvs {:slf4j/kvs kvs})})
-
+     :data
+     (enc/assoc-some nil
+       :slf4j/marker-names marker-names
+       :slf4j/args (when args (vec args))
+       :slf4j/kvs  kvs)})
   nil)
 
 (defn- log!
@@ -143,24 +144,24 @@
 
   ;; Modern "fluent" API calls
   ([logger-name ^org.slf4j.event.LoggingEvent event]
-   (let [inst         (or (when-let [ts (.getTimeStamp event)] (java.time.Instant/ofEpochMilli ts)) (enc/now-inst*))
-         level        (.getLevel     event)
-         error        (.getThrowable event)
-         msg-pattern  (.getMessage   event)
-         args         (when-let [args    (.getArgumentArray event)] args)
-         marker-names (when-let [markers (.getMarkers       event)] (get-marker-names (vec markers)))
-         kvs          (when-let [kvps    (.getKeyValuePairs event)]
-                        (reduce
-                          (fn [acc ^org.slf4j.event.KeyValuePair kvp]
-                            (assoc acc (.-key kvp) (.-value kvp)))
-                          nil kvps))]
+   (let [inst        (or (when-let [ts (.getTimeStamp event)] (java.time.Instant/ofEpochMilli ts)) (enc/now-inst*))
+         level       (.getLevel     event)
+         error       (.getThrowable event)
+         msg-pattern (.getMessage   event)
+         args        (when-let [args    (.getArgumentArray event)] args)
+         markers     (when-let [markers (.getMarkers       event)] (marker-names (vec markers)))
+         kvs         (when-let [kvps    (.getKeyValuePairs event)]
+                       (reduce
+                         (fn [acc ^org.slf4j.event.KeyValuePair kvp]
+                           (assoc acc (.-key kvp) (.-value kvp)))
+                         nil kvps))]
 
      (when-debug (println [:slf4j/fluent-log-call (sig-level level) logger-name]))
-     (normalized-log! logger-name level inst error msg-pattern args marker-names kvs)))
+     (normalized-log! logger-name level inst error msg-pattern args markers kvs)))
 
   ;; Legacy API calls
   ([logger-name ^org.slf4j.event.Level level error msg-pattern args marker]
-   (let [marker-names (when marker (get-marker-names marker))]
+   (let [marker-names (when marker (marker-names marker))]
      (when-debug (println [:slf4j/legacy-log-call (sig-level level) logger-name]))
      (normalized-log! logger-name level (enc/now-inst*) error msg-pattern args marker-names nil))))