[new] OpenTelemetry handler: support spans created outside Telemere

BEFORE this commit:

  Telemere captured OpenTelemetry context only when generating
  tracing signals (`trace!`, `spy!`, etc.).

AFTER this commit:

  Telemere always captures OpenTelemetry context when present.

Motivation for the change:

  Telemere users may have spans automatically created by the
  OpenTelemetry Java Agent, or manually created by other libs
  like clj-otel.

  By always capturing the OpenTelemetry context when present,
  this lets even non-tracing Telemere signals (like `log!`)
  include the relevant trace and span IDs for external tooling.

Thanks to @devurandom for suggesting this, and for helping
debug/identify the necessary changes 🙏

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 `:run` form?
+`:trace?` ------ Should tracing be enabled for this signal? (default true iff `:run` provided or OpenTelemetry tracing enabled)
 
 `: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,7 +38,10 @@
      (def enabled:otel-tracing?
        "Documented at `taoensso.telemere/otel-tracing?`."
        (enc/get-env {:as :bool, :default present:otel?}
-         :taoensso.telemere/otel-tracing<.platform>))))
+         :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))))
 
 (def uid-kind
   "Documented at `taoensso.telemere/*uid-fn*`."
@@ -566,16 +569,19 @@
                  id-form    :id
                  level-form :level} opts
 
-                trace? (get opts :trace? run-form?)
+                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?))
                 _
                 (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 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*))
+                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*))
 
                 parent-form (get opts :parent `*trace-parent*)
                 root-form0  (get opts :root   `*trace-root*)
@@ -609,9 +615,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/context))]
+                                :host :thread :otel? :otel/context))]
 
                         (if-let [kvs+ (get opts :kvs+)] ; Undocumented
                           (if base
@@ -693,7 +699,7 @@
                             (catch :all t# (RunResult. nil        t#  (- (enc/now-nano*) t0#))))))]
 
                   ;; Trace without OpenTelemetry
-                  (or cljs? (not enabled:otel-tracing?))
+                  (or cljs? (not 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}))
@@ -707,9 +713,9 @@
                               (catch :all t# (RunResult. nil        t#  (- (enc/now-nano*) t0#)))))))]
 
                   ;; Trace with OpenTelemetry
-                  (and clj? enabled:otel-tracing?)
+                  (and clj? 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/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 [line (get signal :line)]  (.put ab "line" (long line)))
+          (when-let [ns   (get         signal :ns)]         (.put ab "ns"   (str  ns)))
+          (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)]
-          (if-let [line (get signal :line)]
+        (when-let [ns   (get         signal :ns)]
+          (if-let [line (enc/get-in* signal [:coords 0])]
             (Attributes/of ak-ns ns, ak-line (long line))
             (Attributes/of ak-ns ns)))))))
 

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}))                                 ] (is (sm? sv {:uid nil})))
+        (let [sv (with-sig (sig! {:level :info, :otel? false}))                   ] (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})))                  ] (is (sm? sv {:uid "my-uid"})))])
+                   (with-sig (sig! {:level :info, :uid :auto, :otel? false})))    ] (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", :data {:slf4j/args ["1" "2"]}}]
+             (let [msgp "x={},y={}", expected {:msg_ "x=1,y=2", :slf4j/args (fn [objs] (= (vec objs) ["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"))                                    {: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")]))
+                [(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")]))
 
             (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"]}))]
+        (let [sig (with-sig :raw :trap (tel/event! ::ev-id {:inst t1, :msg ["a" "b"], :otel? false}))]
           [(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/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 marker-names
+(def ^:private get-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 marker-names [marker-or-markers]
+    (fn get-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 (marker-names in))))
+              (fn [acc      ^org.slf4j.Marker in]
+                (if-not   (.hasReferences     in)
+                  (conj acc (.getName         in))
+                  (into acc (get-marker-names in))))
               acc (.iterator m))))
 
         ;; Vector of markers
         (reduce
-          (fn [acc in] (into acc (marker-names in)))
+          (fn [acc in] (into acc (get-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]
-      (marker-names m1)
-      (marker-names cm)
-      (marker-names ms))))
+      (get-marker-names m1)
+      (get-marker-names cm)
+      (get-marker-names ms))))
 
 ;;;; Interop fns (called by `TelemereLogger`)
 
@@ -132,11 +132,10 @@
        (org.slf4j.helpers.MessageFormatter/basicArrayFormat
          msg-pattern args))
 
-     :data
-     (enc/assoc-some nil
-       :slf4j/marker-names marker-names
-       :slf4j/args (when args (vec args))
-       :slf4j/kvs  kvs)})
+     :slf4j/args    args ; Object[]
+     :slf4j/markers marker-names ; Usu. used for routing, filtering, xfns, etc.
+     :data (when kvs {:slf4j/kvs kvs})})
+
   nil)
 
 (defn- log!
@@ -144,24 +143,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)
-         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))]
+   (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))]
 
      (when-debug (println [:slf4j/fluent-log-call (sig-level level) logger-name]))
-     (normalized-log! logger-name level inst error msg-pattern args markers kvs)))
+     (normalized-log! logger-name level inst error msg-pattern args marker-names kvs)))
 
   ;; Legacy API calls
   ([logger-name ^org.slf4j.event.Level level error msg-pattern args marker]
-   (let [marker-names (when marker (marker-names marker))]
+   (let [marker-names (when marker (get-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))))