API docs | CHANGELOG | other Clojure libs | Twitter | contact/contrib | current Break Version:

[com.taoensso/timbre "3.4.0"]       ; Stable
[com.taoensso/timbre "4.0.0-beta1"] ; BREAKING, please see CHANGELOG for details

Timbre, a (sane) Clojure/Script logging & profiling library

Java logging is a tragic comedy full of crazy, unnecessary complexity that buys you nothing. It can be maddeningly, unnecessarily hard to get even the simplest logging working. We can do so much better with Clojure/Script.

Timbre brings functional, Clojure-y goodness to all your logging needs. It's fast, deeply flexible, and easy to configure. No XML!

What's in the box™?

• Full Clojure + ClojureScript support (v4+).
• No XML or properties files. One config map, and you're set.
• Deeply flexible fn appender model with middleware.
• Fantastic performance at any scale.
• Filter logging by levels and namespace whitelist/blacklist patterns.
• Zero overhead with complete Clj+Cljs elision for compile-time level/ns filters.
• Useful built-in appenders for out-the-box Clj+Cljs logging.
• Powerful, easy-to-configure per-appender rate limits and async logging.
• Logs as Clojure values (v3+).
• tools.logging support (optional, useful when integrating with legacy logging systems).
• Logging-level-aware logging profiler.
• Tiny, simple, cross-platform codebase.

3rd-party tools, appenders, etc.

• log-config by Hugo Duncan - library to help manage Timbre logging config.
• Other suggestions welcome!

Getting started

Dependencies

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

[com.taoensso/timbre "4.0.0-beta1"] ; Add to your project.clj :dependencies

(ns my-app ; Your ns
  (:require [taoensso.timbre :as timbre
             :refer (log  trace  debug  info  warn  error  fatal  report
                     logf tracef debugf infof warnf errorf fatalf reportf
                     spy)]

            ;; Clj only:
            [taoensso.timbre.profiling :as profiling
             :refer (pspy pspy* profile defnp p p*)]))

You can also use timbre/refer-timbre to setup these ns refers automatically (Clj only).

Logging

By default, Timbre gives you basic print stream or js/console (v4+) output 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 (Clj only):

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

Timbre slowing down your Clojure app shutdown?

This is due to an outstanding issue in Clojure. As a workaround, add the following to your application's startup routine:

(.addShutdownHook (Runtime/getRuntime) (Thread. (fn [] (shutdown-agents))))

Configuration

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

The example here shows config for Timbre v4. See here for an example of Timbre v3 config.

(def example-config
  "Example (+default) Timbre v4 config map.

  APPENDERS

    *** Please see the `taoensso.timbre.appenders.example-appender` ns if you
        plan to write your own Timbre appender ***

    An appender is a map with keys:
      :doc             ; Optional docstring
      :min-level       ; Level keyword, or nil (=> no minimum level)
      :enabled?        ;
      :async?          ; Dispatch using agent? Useful for slow appenders
      :rate-limit      ; [[ncalls-limit window-ms] <...>], or nil
      :data-hash-fn    ; Used by rate-limiter, etc.
      :opts            ; Any appender-specific opts
      :fn              ; (fn [data-map]), with keys described below

    An appender's fn takes a single data map with keys:
      :config          ; Entire config map (this map, etc.)
      :appender-id     ; Id of appender currently being dispatched to
      :appender        ; Entire appender map currently being dispatched to
      :appender-opts   ; Duplicates (:opts <appender-map>), for convenience

      :instant         ; Platform date (java.util.Date or js/Date)
      :level           ; Keyword
      :error-level?    ; Is level :error or :fatal?
      :?ns-str         ; String, or nil
      :?file           ; String, or nil  ; Waiting on CLJ-865
      :?line           ; Integer, or nil ; Waiting on CLJ-865

      :?err_           ; Delay - first-argument platform error, or nil
      :vargs_          ; Delay - raw args vector
      :hostname_       ; Delay - string (clj only)
      :msg_            ; Delay - args string
      :timestamp_      ; Delay - string
      :output-fn       ; (fn [data & [opts]]) -> formatted output string

      :profile-stats   ; From `profile` macro

      <Also, any *context* keys, which get merged into data map>

  MIDDLEWARE
    Middleware are simple (fn [data]) -> ?data fns (applied left->right) that
    transform the data map dispatched to appender fns. If any middleware returns
    nil, NO dispatching will occur (i.e. the event will be filtered).

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

  (merge
    {:level :debug  ; e/o #{:trace :debug :info :warn :error :fatal :report}

     ;; Control log filtering by namespaces/patterns. Useful for turning off
     ;; logging in noisy libraries, etc.:
     :whitelist  [] #_["my-app.foo-ns"]
     :blacklist  [] #_["taoensso.*"]

     :middleware [] ; (fns [data]) -> ?data, applied left->right

     #+clj :timestamp-opts
     #+clj default-timestamp-opts ; {:pattern _ :locale _ :timezone _}

     :output-fn default-output-fn ; (fn [data]) -> string

     :appenders
     #+clj
     {:println ; Appender id
      ;; Appender <map>:
      {:doc "Prints to (:stream <appender-opts>) IO stream. Enabled by default."
       :min-level nil :enabled? true :async? false :rate-limit nil

       ;; Any custom appender opts:
       :opts {:stream :auto ; e/o #{:std-err :std-out :auto <stream>}
              }

       :fn
       (fn [data]
         (let [{:keys [output-fn error? appender-opts]} data
               {:keys [stream]} appender-opts
               stream (case stream
                        (nil :auto) (if error? default-err *out*)
                        :std-err    default-err
                        :std-out    default-out
                        stream)]
           (binding [*out* stream] (println (output-fn data)))))}

      :spit
      {:doc "Spits to (:spit-filename <appender-opts>) file."
       :min-level nil :enabled? false :async? false :rate-limit nil
       :opts {:spit-filename "timbre-spit.log"}
       :fn
       (fn [data]
         (let [{:keys [output-fn appender-opts]} data
               {:keys [spit-filename]} appender-opts]
           (when-let [fname (enc/as-?nblank spit-filename)]
             (try (ensure-spit-dir-exists! fname)
                  (spit fname (str (output-fn data) "\n") :append true)
                  (catch java.io.IOException _)))))}}

     #+cljs
     {:console
      {:doc "Logs to js/console when it exists. Enabled by default."
       :min-level nil :enabled? true :async? false :rate-limit nil
       :opts {}
       :fn
       (let [have-logger?       (and (exists? js/console) (.-log   js/console))
             have-warn-logger?  (and have-logger?         (.-warn  js/console))
             have-error-logger? (and have-logger?         (.-error js/console))
             adjust-level {:fatal (if have-error-logger? :error :info)
                           :error (if have-error-logger? :error :info)
                           :warn  (if have-warn-logger?  :warn  :info)}]
         (if-not have-logger?
           (fn [data] nil)
           (fn [data]
             (let [{:keys [level appender-opts output-fn]} data
                   {:keys []} appender-opts
                   output (output-fn data)]

               (case (adjust-level level)
                 :error (.error js/console output)
                 :warn  (.warn  js/console output)
                        (.log   js/console output))))))}}}))

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_LEVEL environment variable).
• With timbre/set-level!/timbre/merge-level!.
• With timbre/with-level.

Built-in appenders

Redis (Carmine) appender (v3+)

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

(timbre/merge-config! {:appenders {:carmine (car-appender/make-appender)}})

This gives us a high-performance Redis appender:

• All raw logging args are preserved in serialized form (even errors!).
• 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, stick into or query with Datomic, etc.

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

Email (Postal) appender

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

(timbre/merge-config!
 {:appenders {:postal
   (postal-appender/make-appender {}
   {:postal-config
    ^{:host "mail.isp.net" :user "jsmith" :pass "sekrat!!1"}
    {:from "me@draines.com" :to "foo@example.com"}})}})

File appender

(timbre/merge-config!
  {:appenders {:spit {:enabled? true :opts {:spit-finame "/path/my-file.log"}}}})

Other included appenders

A number of 3rd-party appenders are included out-the-box here. Please see the relevant docstring for details.

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

Profiling (currently Clj only)

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!

License

Copyright © 2012-2015 Peter Taoussanis. Distributed under the Eclipse Public License, the same as Clojure.