14 KiB

Raw Blame History

[com.taoensso/timbre "3.1.1"] ; 3.x is a non-breaking upgrade - see CHANGELOG for details

Appender authors: please see here about migrating Timbre 2.x appenders to 3.x's recommended style.

Timbre, a (sane) Clojure logging & profiling library

Logging with Java can be maddeningly, unnecessarily hard. Particularly if all you want is something simple that works out-the-box. Timbre brings functional, Clojure-y goodness to all your logging needs. No XML!

What's in the box™?

Logs as Clojure values (v3+).
Small, uncomplicated all-Clojure library.
Super-simple map-based config: no arcane XML or properties files!
Low overhead with dynamic logging level.
No overhead with compile-time logging level. (v2.6+)
Flexible fn-centric appender model with middleware.
Sensible built-in appenders including simple email appender.
Tunable rate limit and asynchronous logging support.
Robust namespace filtering.
tools.logging support (optional, useful when integrating with legacy logging systems).
Dead-simple, logging-level-aware logging profiler.

Getting started

Dependencies

Add the necessary dependency to your Leiningen project.clj and use the supplied ns-import helper:

[com.taoensso/timbre "3.1.1"] ; project.clj

(ns my-app (:require [taoensso.timbre :as timbre])) ; Your ns
(timbre/refer-timbre) ; Provides useful Timbre aliases in this ns

The refer-timbre call is a convenience fn that executes:

(require '[taoensso.timbre :as timbre
           :refer (log  trace  debug  info  warn  error  fatal  report
                   logf tracef debugf infof warnf errorf fatalf reportf
                   spy logged-future with-log-level sometimes)])
(require '[taoensso.timbre.profiling :as profiling :refer (pspy pspy* profile defnp)])

Logging

By default, Timbre gives you basic print output to *out*/*err* at a debug logging level:

(info "This will print") => nil
%> 2012-May-28 17:26:11:444 +0700 localhost INFO [my-app] - This will print

(spy :info (* 5 4 3 2 1)) => 120
%> 2012-May-28 17:26:14:138 +0700 localhost INFO [my-app] - (* 5 4 3 2 1) 120

(trace "This won't print due to insufficient logging level") => nil

First-argument exceptions generate a nicely cleaned-up stack trace using io.aviso.exception:

(info (Exception. "Oh noes") "arg1" "arg2")
%> 2012-May-28 17:35:16:132 +0700 localhost INFO [my-app] - arg1 arg2
java.lang.Exception: Oh noes
            NO_SOURCE_FILE:1 my-app/eval6409
          Compiler.java:6511 clojure.lang.Compiler.eval
          <...>

Configuration

This is the biggest win over Java logging utilities IMO. Here's timbre/example-config (also Timbre's default config):

(def example-config
  "APPENDERS
     An appender is a map with keys:
      :doc             ; (Optional) string.
      :min-level       ; (Optional) keyword, or nil (no minimum level).
      :enabled?        ; (Optional).
      :async?          ; (Optional) dispatch using agent (good for slow appenders).
      :rate-limit      ; (Optional) [ncalls-limit window-ms].
      :fmt-output-opts ; (Optional) extra opts passed to `fmt-output-fn`.
      :fn              ; (fn [appender-args-map]), with keys described below.

     An appender's fn takes a single map with keys:
      :level         ; Keyword.
      :error?        ; Is level an 'error' level?.
      :throwable     ; java.lang.Throwable.
      :args          ; Raw logging macro args (as given to `info`, etc.).
      :message       ; Stringified logging macro args, or nil.
      :output        ; Output of `fmt-output-fn`, used by built-in appenders
                     ; as final, formatted appender output. Appenders may (but
                     ; are not obligated to) use this as their output.
      :ap-config     ; Contents of config's :shared-appender-config key.
      :profile-stats ; From `profile` macro.
      :instant       ; java.util.Date.
      :timestamp     ; String generated from :timestamp-pattern, :timestamp-locale.
      :hostname      ; String.
      :ns            ; String.
      ;; Waiting on http://dev.clojure.org/jira/browse/CLJ-865:
      :file          ; String.
      :line          ; Integer.

   MIDDLEWARE
     Middleware are fns (applied right-to-left) that transform the map
     dispatched to appender fns. If any middleware returns nil, no dispatching
     will occur (i.e. the event will be filtered).

  The `example-config` code contains further settings and details.
  See also `set-config!`, `merge-config!`, `set-level!`."

  {;;; Control log filtering by namespace patterns (e.g. ["my-app.*"]).
   ;;; Useful for turning off logging in noisy libraries, etc.
   :ns-whitelist []
   :ns-blacklist []

   ;; Fns (applied right-to-left) to transform/filter appender fn args.
   ;; Useful for obfuscating credentials, pattern filtering, etc.
   :middleware []

   ;;; Control :timestamp format
   :timestamp-pattern "yyyy-MMM-dd HH:mm:ss ZZ" ; SimpleDateFormat pattern
   :timestamp-locale  nil ; A Locale object, or nil

   ;; Output formatter used by built-in appenders. Custom appenders may (but are
   ;; not required to use) its output (:output). Extra per-appender opts can be
   ;; supplied as an optional second (map) arg.
   :fmt-output-fn
   (fn [{:keys [level throwable message timestamp hostname ns]}
       ;; Any extra appender-specific opts:
       & [{:keys [nofonts?] :as appender-fmt-output-opts}]]
     ;; <timestamp> <hostname> <LEVEL> [<ns>] - <message> <throwable>
     (format "%s %s %s [%s] - %s%s"
       timestamp hostname (-> level name str/upper-case) ns (or message "")
       (or (stacktrace throwable "\n" (when nofonts? {})) "")))

   :shared-appender-config {} ; Provided to all appenders via :ap-config key
   :appenders
   {:standard-out
    {:doc "Prints to *out*/*err*. Enabled by default."
     :min-level nil :enabled? true :async? false :rate-limit nil
     :fn (fn [{:keys [error? output]}] ; Use any appender args
           (binding [*out* (if error? *err* *out*)]
             (str-println output)))}

    :spit
    {:doc "Spits to `(:spit-filename :shared-appender-config)` file."
     :min-level nil :enabled? false :async? false :rate-limit nil
     :fn (fn [{:keys [ap-config output]}] ; Use any appender args
           (when-let [filename (:spit-filename ap-config)]ar
             (try (spit filename output :append true)
                  (catch java.io.IOException _))))}}})

A few things to note:

Appenders are trivial to write & configure - they're just fns. It's Timbre's job to dispatch useful args to appenders when appropriate, it's their job to do something interesting with them.
Being 'just fns', appenders have basically limitless potential: write to your database, send a message over the network, check some other state (e.g. environment config) before making a choice, etc.

The logging level may be set:

At compile-time: (TIMBRE_LOG_LEVEL environment variable).
Via an atom: (timbre/set-level! <level>). (Usual method).
Via dynamic thread-level binding: (timbre/with-log-level <level> ...).

A compile-time level offers zero-overhead performance since it'll cause insufficient logging calls to disappear completely at compile-time. Usually you won't need/want to bother: Timbre offers very decent performance with runtime level checks (~15msecs/10k checks on my Macbook Air).

For common-case ease-of-use, all logging utils use a global atom for their config. This is configurable with timbre/set-config!, timbre/merge-config!. The lower-level log and logf macros also take an optional first-arg config map for greater flexibility (e.g. during testing).

Built-in appenders

Redis (Carmine) appender (v3+)

;; [com.taoensso/carmine "2.4.0"] ; Add to project.clj deps
;; (:require [taoensso.timbre.appenders (:carmine :as car-appender)]) ; Add to ns

(timbre/set-config! [:appenders :carmine] (postal-appenders/make-carmine-appender))

This gives us a high-performance Redis appender:

All raw logging args are preserved in serialized form (even Throwables!).
Only the most recent instance of each unique entry is kept (hash fn used to determine uniqueness is configurable).
Configurable number of entries to keep per logging level.
Log is just a value: a vector of Clojure maps: query+manipulate with standard seq fns: group-by hostname, sort/filter by ns & severity, explore exception stacktraces, filter by raw arguments, etc. Datomic and core.logic also offer interesting opportunities here.

A simple query utility is provided: car-appender/query-entries.

Email (Postal) appender

;; [com.draines/postal "1.9.2"] ; Add to project.clj deps
;; (:require [taoensso.timbre.appenders (postal :as postal-appender)]) ; Add to ns

(timbre/set-config! [:appenders :postal]
  (postal-appender/make-postal-appender
   {:enabled?   true
    :rate-limit [1 60000] ; 1 msg / 60,000 msecs (1 min)
    :async?     true ; Don't block waiting for email to send
   }
   {:postal-config
    ^{:host "mail.isp.net" :user "jsmith" :pass "sekrat!!1"}
    {:from "me@draines.com" :to "foo@example.com"}}))

File appender

(timbre/set-config! [:appenders :spit :enabled?] true)
(timbre/set-config! [:shared-appender-config :spit-filename] "/path/my-file.log")

Other included appenders

A number of 3rd-party appenders are included out-the-box for: Android, IRC, sockets, MongoDB, and rotating files. These are all located in the taoensso.timbre.appenders.x namespaces - please see the relevant docstrings for details.

Thanks to their respective authors! Just give me a shout if you've got an appender you'd like to have added.

Profiling

The usual recommendation for Clojure profiling is: use a good JVM profiler like YourKit, JProfiler, or VisualVM.

And these certainly do the job. But as with many Java tools, they can be a little hairy and often heavy-handed - especially when applied to Clojure. Timbre includes an alternative.

Wrap forms that you'd like to profile with the p macro and give them a name:

(defn my-fn
  []
  (let [nums (vec (range 1000))]
    (+ (p :fast-sleep (Thread/sleep 1) 10)
       (p :slow-sleep (Thread/sleep 2) 32)
       (p :add  (reduce + nums))
       (p :sub  (reduce - nums))
       (p :mult (reduce * nums))
       (p :div  (reduce / nums)))))

(my-fn) => 42

The profile macro can now be used to log times for any wrapped forms:

(profile :info :Arithmetic (dotimes [n 100] (my-fn))) => "Done!"
%> 2012-Jul-03 20:46:17 +0700 localhost INFO [my-app] - Profiling my-app/Arithmetic
              Name  Calls       Min        Max       MAD      Mean  Total% Total
 my-app/slow-sleep    100       2ms        2ms      31μs       2ms      57 231ms
 my-app/fast-sleep    100       1ms        1ms      27μs       1ms      29 118ms
        my-app/add    100      44μs        2ms      46μs     100μs       2 10ms
        my-app/sub    100      42μs      564μs      26μs      72μs       2 7ms
        my-app/div    100      54μs      191μs      17μs      71μs       2 7ms
       my-app/mult    100      31μs      165μs      11μs      44μs       1 4ms
       Unaccounted                                                       6 26ms
             Total                                                     100 405ms

You can also use the defnp macro to conveniently wrap whole fns.

It's important to note that Timbre profiling is fully logging-level aware: if the level is insufficient, you won't pay for profiling (there is a minimal dynamic-var deref cost). Likewise, normal namespace filtering applies. (Performance characteristics for both checks are inherited from Timbre itself).

And since p and profile always return their body's result regardless of whether profiling actually happens or not, it becomes feasible to use profiling more often as part of your normal workflow: just leave profiling code in production as you do for logging code.

A simple sampling profiler is also available: taoensso.timbre.profiling/sampling-profile.

This project supports the CDS and goals

CDS, the Clojure Documentation Site, is a contributer-friendly community project aimed at producing top-notch, beginner-friendly Clojure tutorials and documentation. Awesome resource.
ClojureWerkz is a growing collection of open-source, batteries-included Clojure libraries that emphasise modern targets, great documentation, and thorough testing. They've got a ton of great stuff, check 'em out!

Contact & contributing

lein start-dev to get a (headless) development repl that you can connect to with Cider (emacs) or your IDE.

Please use the project's GitHub issues page for project questions/comments/suggestions/whatever (pull requests welcome!). Am very open to ideas if you have any!

Otherwise reach me (Peter Taoussanis) at taoensso.com or on Twitter. Cheers!

14 KiB Raw Blame History