diff --git a/README.md b/README.md index f8d0995..be07e1b 100644 --- a/README.md +++ b/README.md @@ -1,7 +1,7 @@ Current [semantic](http://semver.org/) version: ```clojure -[com.taoensso/timbre "1.0.0"] +[com.taoensso/timbre "1.1.0"] ``` # Timbre, a (sane) Clojure logging & profiling library @@ -27,7 +27,7 @@ Timbre is an attempt to make **simple logging simple** and more **complex loggin Depend on Timbre in your `project.clj`: ```clojure -[com.taoensso/timbre "1.0.0"] +[com.taoensso/timbre "1.1.0"] ``` and `use` the library: @@ -231,7 +231,7 @@ CDS (Clojure Documentation Site) is a contributor-friendly community project aim ## Contact & Contribution -Reach me (Peter Taoussanis) at *ptaoussanis at gmail.com* for questions/comments/suggestions/whatever. I'm very open to ideas if you have any! I'm also on Twitter: [@ptaoussanis](https://twitter.com/#!/ptaoussanis). +Reach me (Peter Taoussanis) at [taoensso.com](https://www.taoensso.com) for questions/comments/suggestions/whatever. I'm very open to ideas if you have any! I'm also on Twitter: [@ptaoussanis](https://twitter.com/#!/ptaoussanis). ## License diff --git a/project.clj b/project.clj index 8a66a7a..34ec8ef 100644 --- a/project.clj +++ b/project.clj @@ -1,4 +1,4 @@ -(defproject com.taoensso/timbre "1.0.0" +(defproject com.taoensso/timbre "1.1.0" :description "Clojure logging & profiling library" :url "https://github.com/ptaoussanis/timbre" :license {:name "Eclipse Public License"} diff --git a/src/taoensso/timbre/profiling.clj b/src/taoensso/timbre/profiling.clj index 24c21aa..af1d838 100644 --- a/src/taoensso/timbre/profiling.clj +++ b/src/taoensso/timbre/profiling.clj @@ -1,7 +1,8 @@ (ns taoensso.timbre.profiling "Simple all-Clojure profiling adapted from clojure.contrib.profile." {:author "Peter Taoussanis"} - (:require [taoensso.timbre :as timbre])) + (:require [taoensso.timbre :as timbre] + [taoensso.timbre.utils :as utils])) (def ^:dynamic *plog* "{::pname [time1 time2 ...] ...}" nil) @@ -30,8 +31,8 @@ [plog] (reduce (fn [m [pname times]] (let [count (count times) - total (reduce + times) - mean (long (/ total count)) + time (reduce + times) + mean (long (/ time count)) ;; Mean Absolute Deviation mad (long (/ (reduce + (map #(Math/abs (long (- % mean))) times)) @@ -41,7 +42,7 @@ :max (apply max times) :mean mean :mad mad - :total total}))) + :time time}))) {} plog)) (defn fqname @@ -51,17 +52,15 @@ (defn plog-table "Returns formatted table string for given plog stats." - ([stats] (plog-table stats :total)) + ([stats] (plog-table stats :time)) ([stats sort-field] (let [;; How long entire (profile) body took - total-time (-> stats :meta/total :total) - stats (dissoc stats :meta/total) - - ;; Sum of (p) times, <= total-time - accounted (reduce + (map :total (vals stats))) + clock-time (-> stats ::clock-time :time) + stats (dissoc stats ::clock-time) + accounted (reduce + (map :time (vals stats))) max-name-width (apply max (map (comp count str) - (conj (keys stats) "Unaccounted"))) + (conj (keys stats) "Accounted Time"))) pattern (str "%" max-name-width "s %6d %9s %10s %9s %9s %7d %1s%n") s-pattern (.replace pattern \d \s) @@ -69,25 +68,24 @@ ft (fn [nanosecs] (let [pow #(Math/pow 10 %) ok-pow? #(>= nanosecs (pow %)) - to-pow #(long (/ nanosecs (pow %)))] - (cond (ok-pow? 9) (str (to-pow 9) "s") - (ok-pow? 6) (str (to-pow 6) "ms") - (ok-pow? 3) (str (to-pow 3) "μs") - :else (str (long nanosecs) "ns"))))] + to-pow #(utils/round-to (/ nanosecs (pow %1)) %2)] + (cond (ok-pow? 9) (str (to-pow 9 1) "s") + (ok-pow? 6) (str (to-pow 6 0) "ms") + (ok-pow? 3) (str (to-pow 3 0) "μs") + :else (str nanosecs "ns"))))] (with-out-str - (printf s-pattern "Name" "Calls" "Min" "Max" "MAD" "Mean" "Total%" "Total") + (printf s-pattern "Name" "Calls" "Min" "Max" "MAD" "Mean" "Time%" "Time") (doseq [pname (->> (keys stats) (sort-by #(- (get-in stats [% sort-field]))))] - (let [{:keys [count min max mean mad total]} (stats pname)] + (let [{:keys [count min max mean mad time]} (stats pname)] (printf pattern (fqname pname) count (ft min) (ft max) (ft mad) - (ft mean) (perc total total-time) (ft total)))) + (ft mean) (perc time clock-time) (ft time)))) - (let [unacc (- total-time accounted) - unacc-perc (perc unacc total-time)] - (printf s-pattern "Unaccounted" "" "" "" "" "" unacc-perc (ft unacc)) - (printf s-pattern "Total" "" "" "" "" "" 100 (ft total-time))))))) + (printf s-pattern "[Clock] Time" "" "" "" "" "" 100 (ft clock-time)) + (printf s-pattern "Accounted Time" "" "" "" "" "" + (perc accounted clock-time) (ft accounted)))))) (defmacro profile* "Executes named body with profiling enabled. Body forms wrapped in (p) will be @@ -118,7 +116,7 @@ (str "Profiling " (fqname name#)) (str "\n" (plog-table stats#)))) ~name - (p :meta/total ~@body)) + (p ::clock-time ~@body)) (do ~@body))) (defmacro sampling-profile diff --git a/src/taoensso/timbre/utils.clj b/src/taoensso/timbre/utils.clj index abef478..61f97e0 100644 --- a/src/taoensso/timbre/utils.clj +++ b/src/taoensso/timbre/utils.clj @@ -34,4 +34,15 @@ (defn deep-merge "Partial of `deep-merge-with`." [& maps] - (apply deep-merge-with (fn [x y] y) maps)) \ No newline at end of file + (apply deep-merge-with (fn [x y] y) maps)) + +(defn round-to + "Rounds argument to given number of decimal places." + [x places] + (if (zero? places) + (Math/round (double x)) + (let [modifier (Math/pow 10.0 places)] + (/ (Math/round (* x modifier)) modifier)))) + +(comment (round-to 10 0) + (round-to 10.123 2)) \ No newline at end of file