Refactor manual hashing control (fully back-compatible)

Hashing is still done on a data level as before (with arb data-hash-fn);
difference is that {:timbre/hash _} arg0 support is now baked in to core
logging impl. rather than just the default data hash fn.

Effect: a new `:?hash-arg` is now provided as part of core data and will
be available to any data-hash-fns.

New implementation is also cleaner + faster.
This commit is contained in:
Peter Taoussanis 2016-01-27 10:26:19 +07:00
parent a8505032cb
commit db8f8a8759
2 changed files with 91 additions and 71 deletions

View File

@ -12,7 +12,7 @@
:dependencies :dependencies
[[org.clojure/clojure "1.5.1"] [[org.clojure/clojure "1.5.1"]
[com.taoensso/encore "2.32.0"] [com.taoensso/encore "2.33.0"]
[io.aviso/pretty "0.1.21"]] [io.aviso/pretty "0.1.21"]]
:plugins :plugins

View File

@ -18,8 +18,8 @@
(:require-macros [taoensso.timbre :as timbre-macros :refer ()])) (:require-macros [taoensso.timbre :as timbre-macros :refer ()]))
(if (vector? taoensso.encore/encore-version) (if (vector? taoensso.encore/encore-version)
(enc/assert-min-encore-version [2 32 0]) (enc/assert-min-encore-version [2 33 0])
(enc/assert-min-encore-version 2.32)) (enc/assert-min-encore-version 2.33))
;;;; Config ;;;; Config
@ -223,6 +223,10 @@
;;;; Utils ;;;; Utils
(declare get-hostname)
(defn- ->delay [x] (if (delay? x) x (delay x)))
(enc/compile-if (do enc/str-join true) ; Encore v2.29.1+ with transducers (enc/compile-if (do enc/str-join true) ; Encore v2.29.1+ with transducers
(defn- str-join [xs] (defn- str-join [xs]
(enc/str-join " " (enc/str-join " "
@ -240,25 +244,14 @@
(defrecord MyRec [x]) (defrecord MyRec [x])
(str-join ["foo" (MyRec. "foo")])) (str-join ["foo" (MyRec. "foo")]))
(defn- ->delay [x] (if (delay? x) x (delay x)))
(defn- vsplit-err1 [[v1 :as v]] (if-not (enc/error? v1) [nil v] (enc/vsplit-first v)))
(comment
(vsplit-err1 [:a :b :c])
(vsplit-err1 [(Exception.) :a :b :c]))
(defn default-data-hash-fn (defn default-data-hash-fn
"Used for rate limiters, some appenders (e.g. Carmine), etc. "Used for rate limiters, some appenders (e.g. Carmine), etc.
Goal: (hash data-1) = (hash data-2) iff data-1 \"the same\" as data-2 for Goal: (hash data-1) = (hash data-2) iff data-1 \"the same\" as data-2 for
rate-limiting purposes, etc." rate-limiting purposes, etc."
[data] [data]
(let [{:keys [?ns-str ?line vargs_]} data (let [{:keys [?hash-arg ?ns-str ?line vargs_]} data]
vargs @vargs_] (str (or ?hash-arg ; An explicit hash given as a0
(str [?ns-str (or ?line @vargs_)]))))
(or (enc/rsome #(and (map? %) (:timbre/hash %)) vargs) ; Explicit hash given
#_[?ns-str ?line] ; TODO Waiting on http://goo.gl/cVVAYA
[?ns-str vargs]))))
(comment (default-data-hash-fn {}))
#+clj #+clj
(enc/defonce* ^:private get-agent (enc/defonce* ^:private get-agent
@ -271,12 +264,33 @@
(comment (def rf (get-rate-limiter :my-appender [[10 5000]]))) (comment (def rf (get-rate-limiter :my-appender [[10 5000]])))
(defn- inherit-over [k appender config default]
(or
(let [a (get appender k)] (when-not (enc/kw-identical? a :inherit) a))
(get config k)
default))
(defn- inherit-into [k appender config default]
(merge default
(get config k)
(let [a (get appender k)] (when-not (enc/kw-identical? a :inherit) a))))
(comment
(inherit-over :foo {:foo :inherit} {:foo :bar} nil)
(inherit-into :foo {:foo {:a :A :b :B :c :C}} {:foo {:a 1 :b 2 :c 3 :d 4}} nil))
;;;; Internal logging core ;;;; Internal logging core
(def ^:dynamic *context*
"General-purpose dynamic logging context. Context will be included in appender
data map at logging time." nil)
(defmacro with-context [context & body] `(binding [*context* ~context] ~@body))
(defn log? (defn log?
"Would Timbre currently (runtime) log at the given logging level? "Runtime check: would Timbre currently log at the given logging level?
* `?ns-str` arg required to support ns filtering * `?ns-str` arg required to support ns filtering
* `config` arg required to support non-global config" * `config` arg required to support non-global config"
([level ] (log? level nil nil)) ([level ] (log? level nil nil))
([level ?ns-str ] (log? level ?ns-str nil)) ([level ?ns-str ] (log? level ?ns-str nil))
([level ?ns-str config] ([level ?ns-str config]
@ -307,57 +321,60 @@
(qb 10000 (info "foo"))) ; ~218ms ; Time to output ready (qb 10000 (info "foo"))) ; ~218ms ; Time to output ready
) )
(def ^:dynamic *context* (defn- vargs->margs "Processes vargs to extract special a0s"
"General-purpose dynamic logging context. Context will be included in appender [vargs a0-err?]
data map at logging time." nil) (let [[v0 :as v] vargs
[?err v]
(if (and a0-err? (enc/error? v0))
[v0 (enc/vnext v)]
[nil v])
(defmacro with-context [context & body] `(binding [*context* ~context] ~@body)) [v0 :as v] v
[?hash-arg v]
(if (and (map? v0) (contains? v0 :timbre/hash))
[(:timbre/hash v0) (enc/vnext v)]
[nil v])]
(declare get-hostname) {:?err ?err :?hash-arg ?hash-arg :vargs v}))
(defn- inherit-over [k appender config default]
(or
(let [a (get appender k)] (when-not (enc/kw-identical? a :inherit) a))
(get config k)
default))
(defn- inherit-into [k appender config default]
(merge default
(get config k)
(let [a (get appender k)] (when-not (enc/kw-identical? a :inherit) a))))
(comment (comment
(inherit-over :foo {:foo :inherit} {:foo :bar} nil) (vargs->margs [:a :b :c] true)
(inherit-into :foo {:foo {:a :A :b :B :c :C}} {:foo {:a 1 :b 2 :c 3 :d 4}} nil)) (vargs->margs [(Exception. "ex") :b :c] true)
(defn -log! "Core low-level log fn. Implementation detail." (infof {:timbre/hash :bar} "Hi %s" "steve")
(infof "Hi %s" "steve"))
(defn -log! "Core low-level log fn. Implementation detail!"
[config level ?ns-str ?file ?line msg-type ?err vargs_ ?base-data] [config level ?ns-str ?file ?line msg-type ?err vargs_ ?base-data]
(when (log? level ?ns-str config) ; Runtime check (when (log? level ?ns-str config) ; Runtime check
(let [instant (enc/now-dt) (let [instant (enc/now-dt)
;; vargs_ (->delay vargs_) ;; vargs_ (->delay vargs_) ; Should be safe w/o
context *context*
;; Extract ?err as err-type a0 in vargs?: a0-err? (enc/kw-identical? ?err :auto)
a0-err? (enc/kw-identical? ?err :auto) margs_ (delay (vargs->margs @vargs_ a0-err?))
vargs*_ (if a0-err? (delay (vsplit-err1 @vargs_)) vargs_) ?err_ (delay (if a0-err? (:?err @margs_) ?err))
?err_ (if a0-err? (delay (get @vargs*_ 0)) (delay ?err)) ?hash-arg_ (delay (:?hash-arg @margs_))
vargs_ (if a0-err? (delay (get @vargs*_ 1)) vargs_) vargs_ (delay (:vargs @margs_))
data
(merge ?base-data
;; No, better nest than merge (appenders may want to pass
;; along arb context w/o knowing context keys, etc.):
(when (map? context) context) ; DEPRECATED, for back compat
{:config config ; Entire config!
:context context
:instant instant
:level level
:?ns-str ?ns-str
:?file ?file
:?line ?line
:?err_ ?err_
:?hash-arg_ ?hash-arg_
:vargs_ vargs_
#+clj :hostname_ #+clj (delay (get-hostname))
:error-level? (#{:error :fatal} level)})
context *context*
data (merge ?base-data
;; No, better nest than merge (appenders may want to pass
;; along arb context w/o knowing context keys, etc.):
(when (map? context) context) ; DEPRECATED, for back compat
{:config config ; Entire config!
:context context
:instant instant
:level level
:?ns-str ?ns-str
:?file ?file
:?line ?line
:?err_ ?err_
:vargs_ vargs_
#+clj :hostname_ #+clj (delay (get-hostname))
:error-level? (#{:error :fatal} level)})
msg-fn msg-fn
(fn [vargs_] ; For use *after* middleware, etc. (fn [vargs_] ; For use *after* middleware, etc.
(when-not (nil? msg-type) (when-not (nil? msg-type)
@ -366,6 +383,7 @@
:p (str-join vargs) :p (str-join vargs)
:f (let [[fmt args] (enc/vsplit-first vargs)] :f (let [[fmt args] (enc/vsplit-first vargs)]
(enc/format* fmt args)))))) (enc/format* fmt args))))))
?data ?data
(reduce ; Apply middleware: data->?data (reduce ; Apply middleware: data->?data
(fn [acc mf] (fn [acc mf]
@ -374,7 +392,17 @@
(reduced nil) (reduced nil)
result))) result)))
data data
(:middleware config))] (:middleware config))
;; As a convenience to appenders, make sure that middleware
;; hasn't replaced any delays with non-delays
?data
(when-let [data ?data] ; Not filtered by middleware
(merge data
{:?err_ (->delay (:?err_ data))
:?hash-arg_ (->delay (:?hash-arg_ data))
:vargs_ (->delay (:vargs_ data))
#+clj :hostname_ #+clj (->delay (:hostname_ data))}))]
(when-let [data ?data] ; Not filtered by middleware (when-let [data ?data] ; Not filtered by middleware
(reduce-kv (reduce-kv
@ -382,15 +410,7 @@
(when (and (:enabled? appender) (when (and (:enabled? appender)
(level>= level (or (:min-level appender) :trace))) (level>= level (or (:min-level appender) :trace)))
(let [;; As a convenience to appenders, make sure that middleware (let [rate-limit-specs (:rate-limit appender)
;; hasn't replaced any delays with non-delays
data
(merge data
{:?err_ (->delay (:?err_ data))
:vargs_ (->delay (:vargs_ data))
#+clj :hostname_ #+clj (->delay (:hostname_ data))})
rate-limit-specs (:rate-limit appender)
data-hash-fn (inherit-over :data-hash-fn appender config data-hash-fn (inherit-over :data-hash-fn appender config
default-data-hash-fn) default-data-hash-fn)
rate-limit-okay? rate-limit-okay?