rlm@10: ;;; logging.clj -- delegated logging for Clojure
rlm@10:  
rlm@10: ;; by Alex Taggart
rlm@10: ;; July 27, 2009
rlm@10:  
rlm@10: ;; Copyright (c) Alex Taggart, July 2009. All rights reserved.  The use
rlm@10: ;; and distribution terms for this software are covered by the Eclipse
rlm@10: ;; Public License 1.0 (http://opensource.org/licenses/eclipse-1.0.php)
rlm@10: ;; which can be found in the file epl-v10.html at the root of this
rlm@10: ;; distribution.  By using this software in any fashion, you are
rlm@10: ;; agreeing to be bound by the terms of this license.  You must not
rlm@10: ;; remove this notice, or any other, from this software.
rlm@10: (ns 
rlm@10:   ^{:author "Alex Taggart, Timothy Pratley",
rlm@10:      :doc
rlm@10:   "Logging macros which delegate to a specific logging implementation. At
rlm@10:   runtime a specific implementation is selected from, in order, Apache
rlm@10:   commons-logging, log4j, and finally java.util.logging.
rlm@10:   
rlm@10:   Logging levels are specified by clojure keywords corresponding to the
rlm@10:   values used in log4j and commons-logging:
rlm@10:     :trace, :debug, :info, :warn, :error, :fatal
rlm@10:   
rlm@10:   Logging occurs with the log macro, or the level-specific convenience macros,
rlm@10:   which write either directly or via an agent.  For performance reasons, direct
rlm@10:   logging is enabled by default, but setting the *allow-direct-logging* boolean
rlm@10:   atom to false will disable it. If logging is invoked within a transaction it
rlm@10:   will always use an agent.
rlm@10:   
rlm@10:   The log macros will not evaluate their 'message' unless the specific logging
rlm@10:   level is in effect. Alternately, you can use the spy macro when you have code
rlm@10:   that needs to be evaluated, and also want to output the code and its result to
rlm@10:   the debug log.
rlm@10:   
rlm@10:   Unless otherwise specified, the current namespace (as identified by *ns*) will
rlm@10:   be used as the log-ns (similar to how the java class name is usually used).
rlm@10:   Note: your log configuration should display the name that was passed to the
rlm@10:   logging implementation, and not perform stack-inspection, otherwise you'll see
rlm@10:   something like \"fn__72$impl_write_BANG__39__auto____81\" in your logs.
rlm@10:   
rlm@10:   Use the enabled? macro to write conditional code against the logging level
rlm@10:   (beyond simply whether or not to call log, which is handled automatically).
rlm@10:   
rlm@10:   You can redirect all java writes of System.out and System.err to the log
rlm@10:   system by calling log-capture!.  To rebind *out* and *err* to the log system
rlm@10:   invoke with-logs.  In both cases a log-ns (e.g., \"com.example.captured\")
rlm@10:   needs to be specified to namespace the output."}
rlm@10:   clojure.contrib.logging)
rlm@10: 
rlm@10: (declare *impl-name* impl-get-log impl-enabled? impl-write!)
rlm@10: 
rlm@10: ;; Macros used so that implementation-specific functions all have the same meta.
rlm@10: 
rlm@10: (defmacro def-impl-name
rlm@10:   {:private true} [& body]
rlm@10:   `(def
rlm@10:     ^{:doc "The name of the logging implementation used."}
rlm@10:     *impl-name*
rlm@10:     ~@body))
rlm@10: 
rlm@10: (defmacro def-impl-get-log
rlm@10:   {:private true} [& body]
rlm@10:   `(def
rlm@10:     ^{:doc
rlm@10:   "Returns an implementation-specific log by string namespace. End-users should
rlm@10:   not need to call this."
rlm@10:        :arglist '([~'log-ns])}
rlm@10:     impl-get-log
rlm@10:     (memoize ~@body)))
rlm@10: 
rlm@10: (defmacro def-impl-enabled?
rlm@10:   {:private true} [& body]
rlm@10:   `(def
rlm@10:     ^{:doc
rlm@10:   "Implementation-specific check if a particular level is enabled. End-users
rlm@10:   should not need to call this."
rlm@10:        :arglist '([~'log ~'level])}
rlm@10:     impl-enabled?
rlm@10:     ~@body))
rlm@10: 
rlm@10: (defmacro def-impl-write!
rlm@10:   {:private true} [& body]
rlm@10:   `(def
rlm@10:     ^{:doc
rlm@10:   "Implementation-specific write of a log message. End-users should not need to
rlm@10:   call this."
rlm@10:        :arglist '([~'log ~'level ~'message ~'throwable])}
rlm@10:     impl-write!
rlm@10:     ~@body))
rlm@10: 
rlm@10: (defn- commons-logging
rlm@10:   "Defines the commons-logging-based implementations of the core logging
rlm@10:   functions. End-users should never need to call this."
rlm@10:   []
rlm@10:   (try
rlm@10:     (import (org.apache.commons.logging LogFactory Log))
rlm@10:     (eval
rlm@10:       `(do
rlm@10:         (def-impl-name "org.apache.commons.logging")
rlm@10:         (def-impl-get-log
rlm@10:           (fn [log-ns#]
rlm@10:             (org.apache.commons.logging.LogFactory/getLog ^String log-ns#)))
rlm@10:         (def-impl-enabled?
rlm@10:           (fn [^org.apache.commons.logging.Log log# level#]
rlm@10:             (condp = level#
rlm@10:               :trace (.isTraceEnabled log#)
rlm@10:               :debug (.isDebugEnabled log#)
rlm@10:               :info  (.isInfoEnabled  log#)
rlm@10:               :warn  (.isWarnEnabled  log#)
rlm@10:               :error (.isErrorEnabled log#)
rlm@10:               :fatal (.isFatalEnabled log#))))
rlm@10:         (def-impl-write!
rlm@10:           (fn [^org.apache.commons.logging.Log log# level# msg# e#]
rlm@10:             (condp = level#
rlm@10:               :trace (.trace log# msg# e#)
rlm@10:               :debug (.debug log# msg# e#)
rlm@10:               :info  (.info  log# msg# e#)
rlm@10:               :warn  (.warn  log# msg# e#)
rlm@10:               :error (.error log# msg# e#)
rlm@10:               :fatal (.fatal log# msg# e#))))
rlm@10:         true))
rlm@10:     (catch Exception e nil)))
rlm@10: 
rlm@10: 
rlm@10: (defn- log4j-logging
rlm@10:   "Defines the log4j-based implementations of the core logging functions.
rlm@10:    End-users should never need to call this."
rlm@10:   []
rlm@10:   (try
rlm@10:     (import (org.apache.log4j Logger Level))
rlm@10:     (eval
rlm@10:       '(do
rlm@10:         (def-impl-name "org.apache.log4j")
rlm@10:         (def-impl-get-log
rlm@10:           (fn [log-ns#]
rlm@10:             (org.apache.log4j.Logger/getLogger ^String log-ns#)))
rlm@10:         (let [levels# {:trace org.apache.log4j.Level/TRACE
rlm@10:                        :debug org.apache.log4j.Level/DEBUG
rlm@10:                        :info  org.apache.log4j.Level/INFO
rlm@10:                        :warn  org.apache.log4j.Level/WARN
rlm@10:                        :error org.apache.log4j.Level/ERROR
rlm@10:                        :fatal org.apache.log4j.Level/FATAL}]
rlm@10:           (def-impl-enabled?
rlm@10:             (fn [^org.apache.log4j.Logger log# level#]
rlm@10:               (.isEnabledFor log# (levels# level#))))
rlm@10:           (def-impl-write!
rlm@10:             (fn [^org.apache.log4j.Logger log# level# msg# e#]
rlm@10:               (if-not e#
rlm@10:                 (.log log# (levels# level#) msg#)
rlm@10:                 (.log log# (levels# level#) msg# e#)))))
rlm@10:         true))
rlm@10:     (catch Exception e nil)))
rlm@10: 
rlm@10: 
rlm@10: (defn- java-logging
rlm@10:   "Defines the java-logging-based implementations of the core logging
rlm@10:   functions. End-users should never need to call this."
rlm@10:   []
rlm@10:   (try
rlm@10:     (import (java.util.logging Logger Level))
rlm@10:     (eval
rlm@10:       `(do
rlm@10:         (def-impl-name "java.util.logging")
rlm@10:         (def-impl-get-log
rlm@10:           (fn [log-ns#]
rlm@10:             (java.util.logging.Logger/getLogger log-ns#)))
rlm@10:         (let [levels# {:trace java.util.logging.Level/FINEST
rlm@10:                        :debug java.util.logging.Level/FINE
rlm@10:                        :info  java.util.logging.Level/INFO
rlm@10:                        :warn  java.util.logging.Level/WARNING
rlm@10:                        :error java.util.logging.Level/SEVERE
rlm@10:                        :fatal java.util.logging.Level/SEVERE}]
rlm@10:           (def-impl-enabled?
rlm@10:             (fn [^java.util.logging.Logger log# level#]
rlm@10:               (.isLoggable log# (levels# level#))))
rlm@10:           (def-impl-write!
rlm@10:             (fn [^java.util.logging.Logger log# level# msg# e#]
rlm@10:               (if-not e#
rlm@10:                 (.log log# ^java.util.logging.Level (levels# level#)
rlm@10:                            ^String (str msg#))
rlm@10:                 (.log log# ^java.util.logging.Level (levels# level#)
rlm@10:                            ^String (str msg#) ^Throwable e#)))))
rlm@10:         true))
rlm@10:     (catch Exception e nil)))
rlm@10: 
rlm@10: 
rlm@10: ;; Initialize implementation-specific functions
rlm@10: (or (commons-logging)
rlm@10:     (log4j-logging)
rlm@10:     (java-logging)
rlm@10:     (throw ; this should never happen in 1.5+
rlm@10:       (RuntimeException.
rlm@10:         "Valid logging implementation could not be found.")))
rlm@10: 
rlm@10: 
rlm@10: (def ^{:doc
rlm@10:   "The default agent used for performing logging durng a transaction or when
rlm@10:   direct logging is disabled."}
rlm@10:   *logging-agent* (agent nil))
rlm@10: 
rlm@10: 
rlm@10: (def ^{:doc
rlm@10:   "A boolean indicating whether direct logging (as opposed to via an agent) is
rlm@10:   allowed when not operating from within a transaction. Defaults to true."}
rlm@10:   *allow-direct-logging* (atom true))
rlm@10: 
rlm@10: 
rlm@10: (defmacro log
rlm@10:   "Logs a message, either directly or via an agent. Also see the level-specific
rlm@10:   convenience macros."
rlm@10:   ([level message]
rlm@10:     `(log ~level ~message nil))
rlm@10:   ([level message throwable]
rlm@10:     `(log ~level ~message ~throwable ~(str *ns*)))
rlm@10:   ([level message throwable log-ns]
rlm@10:     `(let [log# (impl-get-log ~log-ns)]
rlm@10:       (if (impl-enabled? log# ~level)
rlm@10:         (if (and @*allow-direct-logging*
rlm@10:                  (not (clojure.lang.LockingTransaction/isRunning)))
rlm@10:           (impl-write! log# ~level ~message ~throwable)
rlm@10:           (send-off *logging-agent*
rlm@10:             (fn [_# l# v# m# t#] (impl-write! l# v# m# t#))
rlm@10:             log# ~level ~message ~throwable))))))
rlm@10: 
rlm@10: 
rlm@10: (defmacro enabled?
rlm@10:   "Returns true if the specific logging level is enabled.  Use of this function
rlm@10:   should only be necessary if one needs to execute alternate code paths beyond
rlm@10:   whether the log should be written to."
rlm@10:   ([level]
rlm@10:     `(enabled? ~level ~(str *ns*)))
rlm@10:   ([level log-ns]
rlm@10:     `(impl-enabled? (impl-get-log ~log-ns) ~level)))
rlm@10: 
rlm@10: 
rlm@10: (defmacro spy
rlm@10:   "Evaluates expr and outputs the form and its result to the debug log; returns 
rlm@10:   the result of expr."
rlm@10:   [expr]
rlm@10:   `(let [a# ~expr] (log :debug (str '~expr " => " a#)) a#))
rlm@10: 
rlm@10: 
rlm@10: (defn log-stream
rlm@10:   "Creates a PrintStream that will output to the log. End-users should not need
rlm@10:   to invoke this."
rlm@10:   [level log-ns]
rlm@10:   (java.io.PrintStream.
rlm@10:     (proxy [java.io.ByteArrayOutputStream] []
rlm@10:       (flush []
rlm@10:         (proxy-super flush)
rlm@10:         (let [s (.trim (.toString ^java.io.ByteArrayOutputStream this))]
rlm@10:           (proxy-super reset)
rlm@10:           (if (> (.length s) 0)
rlm@10:             (log level s nil log-ns)))))
rlm@10:     true))
rlm@10: 
rlm@10: 
rlm@10: (def ^{:doc
rlm@10:   "A ref used by log-capture! to maintain a reference to the original System.out
rlm@10:   and System.err streams."
rlm@10:   :private true}
rlm@10:   *old-std-streams* (ref nil))
rlm@10: 
rlm@10: 
rlm@10: (defn log-capture!
rlm@10:   "Captures System.out and System.err, redirecting all writes of those streams
rlm@10:   to :info and :error logging, respectively. The specified log-ns value will
rlm@10:   be used to namespace all redirected logging. NOTE: this will not redirect
rlm@10:   output of *out* or *err*; for that, use with-logs."
rlm@10:   [log-ns]
rlm@10:   (dosync
rlm@10:     (let [new-out (log-stream :info log-ns)
rlm@10:           new-err (log-stream :error log-ns)]
rlm@10:       ; don't overwrite the original values
rlm@10:       (if (nil? @*old-std-streams*)
rlm@10:         (ref-set *old-std-streams* {:out System/out :err System/err})) 
rlm@10:       (System/setOut new-out)
rlm@10:       (System/setErr new-err))))
rlm@10: 
rlm@10: 
rlm@10: (defn log-uncapture!
rlm@10:   "Restores System.out and System.err to their original values."
rlm@10:   []
rlm@10:   (dosync
rlm@10:     (when-let [{old-out :out old-err :err} @*old-std-streams*]
rlm@10:       (ref-set *old-std-streams* nil)
rlm@10:       (System/setOut old-out)
rlm@10:       (System/setErr old-err))))
rlm@10: 
rlm@10: 
rlm@10: (defmacro with-logs
rlm@10:   "Evaluates exprs in a context in which *out* and *err* are bound to :info and
rlm@10:   :error logging, respectively. The specified log-ns value will be used to
rlm@10:   namespace all redirected logging."
rlm@10:   [log-ns & body]
rlm@10:   (if (and log-ns (seq body))
rlm@10:     `(binding [*out* (java.io.OutputStreamWriter.
rlm@10:                        (log-stream :info ~log-ns))
rlm@10:                *err* (java.io.OutputStreamWriter.
rlm@10:                        (log-stream :error ~log-ns))]
rlm@10:       ~@body)))
rlm@10: 
rlm@10: (defmacro trace
rlm@10:   "Logs a message at the trace level."
rlm@10:   ([message]
rlm@10:     `(log :trace ~message))
rlm@10:   ([message throwable]
rlm@10:     `(log :trace ~message ~throwable)))
rlm@10: 
rlm@10: (defmacro debug
rlm@10:   "Logs a message at the debug level."
rlm@10:   ([message]
rlm@10:     `(log :debug ~message))
rlm@10:   ([message throwable]
rlm@10:     `(log :debug ~message ~throwable)))
rlm@10: 
rlm@10: (defmacro info
rlm@10:   "Logs a message at the info level."
rlm@10:   ([message]
rlm@10:     `(log :info ~message))
rlm@10:   ([message throwable]
rlm@10:     `(log :info ~message ~throwable)))
rlm@10: 
rlm@10: (defmacro warn
rlm@10:   "Logs a message at the warn level."
rlm@10:   ([message]
rlm@10:     `(log :warn ~message))
rlm@10:   ([message throwable]
rlm@10:     `(log :warn ~message ~throwable)))
rlm@10: 
rlm@10: (defmacro error
rlm@10:   "Logs a message at the error level."
rlm@10:   ([message]
rlm@10:     `(log :error ~message))
rlm@10:   ([message throwable]
rlm@10:     `(log :error ~message ~throwable)))
rlm@10: 
rlm@10: (defmacro fatal
rlm@10:   "Logs a message at the fatal level."
rlm@10:   ([message]
rlm@10:     `(log :fatal ~message))
rlm@10:   ([message throwable]
rlm@10:     `(log :fatal ~message ~throwable)))