CL-LOG.LISP - A general purpose
                    logging utility for Common Lisp

                              Nick Levine
                          Ravenbrook Limited
                          ndl@ravenbrook.com

                              2007-06-09

Contents:
  1.  Introduction
  2.  Examples
  3.  Obtaining and installing CL-LOG
  4.  The log-manager
  5.  Timestamps
  6.  Categories
  7.  Messages
  8.  Messengers

1.  INTRODUCTION

CL-LOG is a general purpose logging utility, loosely modelled in some
respects after Gary King's "Log5" <http://common-lisp.net/project/log5/>.

Its features include:
    * logging to several destinations at once, via "messengers",
    * each messenger is tailored to accept some log messages and
      reject others, and this tailoring can be changed on-the-fly,
    * very rapid processing of messages which are rejected by all
      messengers,
    * support for messengers which cl:format text to a stream,
    * support for messengers which do not invoke cl:format,
    * timestamps in theory accurate to internal-time-units-per-second.

Typically, logging utilities only support the one, simple paradigm of
formatting objects to a text-stream. Removing this restriction allows
you to:
    * log random objects instead of plain text,
    * generate internationalized log messages,
    * create specialised binary logs,
    * base the test-suite of complex applications around logging.

Logging is controlled by the following classes: log-manager,
base-messenger, base-message; any of these might be specialised by
your application. Whether or not a messenger will accept a given
message is controlled by the "categories" of both the messenger and
message; categories are logical combinations of atoms (typically
keywords).

The source code for CL-LOG is very nearly the same length as this
documentation. You might find it less work to read the code instead.

CL-LOG has an MIT-style license, a copy of which will be found at the
end of this document.


2.  EXAMPLES

2.1. Getting started -- simple logging to a text file

There is a two-step setup and then you're ready to go.

First, create your log-manager and configure it for formatted messages:

    (in-package cl-log)

    (setf (log-manager)
          (make-instance 'log-manager :message-class 'formatted-message))

Next, instantiate a messenger and point it at your output file:

    (start-messenger 'text-file-messenger
                     :filename "/tmp/log.txt")

We didn't give this messenger a category, and this means it'll accept
all messages.

OK, we're ready to go.

    (log-message :warning "Logging system poorly understood")
    (log-message :coffee  "Levels replenished")

The output file now contains something like:

    3390537223.453 WARNING Logging system poorly understood
    3390537225.218 COFFEE Levels replenished

That's all there is to it.

Where to go next? Consider using categories (start with sections 6.1
and 6.4) to allow control over how much gets logged, and consider
making the formatted output prettier by specialising the class
formatted-message and defining a method on format-message (see section
7.3).


2.2. Logging to a ring, using categories

Let's define some categories: in this example they're going to
annotate the severities of situations which we wish to log. They range
from "critical" at one end of the scale to "debug" at the other.

    (defcategory :critical)
    (defcategory :error   (or :error :critical))
    (defcategory :warning (or :warning :error))
    (defcategory :notice  (or :notice :warning))
    (defcategory :info    (or :info :notice))
    (defcategory :debug   (or :debug :info))

Note the recursive inclusion: a :debug messenger will accept either
:debug or :info messages, and so it'll accept either :debug, :info or
:notice, and so on. It's quite safe to define a category in terms of
itself.

Next we fire up the log-manager and tell it that it's going to
generate messages of class base-message (these, as we'll see later,
are messages which do not cl:format their contents).

    (setf (log-manager)
          (make-instance 'log-manager :message-class 'base-message))

If you'd already run the file-logging example above, note that
resetting (log-manager) will automatically stop the previous
log-manager's messenger(s).

The final step before we're ready to start logging is to create at
least one messenger. The ring-messenger class records messages as raw
objects, always retaining the most recent :length (in this case, 10)
of them.

    (start-messenger 'ring-messenger
                     :length 10
                     :category '(and :info (not :error)))

The :category initarg above specifies that this messenger will only
accept messages which are of category :info but not of category
:error. Using the defcategory forms above, we can think of this as
equivalent to (or :info :notice :warning). Calculating whether a
message satisfies a combination like this isn't "for free", but the
results are cached and so provided you don't keep redefining your
categories (thousands of times per second, say) you'll get excellent
performance no matter how complicated the combinations are.

OK, let's log some messages. The first argument, always evaluated, to
the log-message macro is the category of this message. The remaining
arguments are only evaluated if the message is accepted by at least
one messenger. In this toy example, we fire off half a dozen messages
using the category of each as its contents:

    (dolist (z '(:critical :error :warning :notice :info :debug))
      (log-message z z))

Now let's show that we logged everything which was at least :info
provided it wasn't also at least :error

    (loop for message in (ring-messenger-messages
                          (car (log-manager-messengers (log-manager))))
          when message collect (message-description message))

    =>

    (:WARNING :NOTICE :INFO)


3.  OBTAINING AND INSTALLING CL-LOG

3.1. Obtaining CL-LOG

CL-LOG can be downloaded from http://www.nicklevine.org/cl-log/


3.2. Installing CL-LOG

The source is in two lisp files: pkg.lisp and cl-log.lisp. Compile and
load them in that order.

There's also an asdf file (cl-log.asdf).


3.3. Packages

The package of any lisp symbol referenced in this document can be
determined by selecting the first of the following which is applicable
to that symbol:

    1. the symbol's package is explicitly qualified;

    2. the symbol belongs to the COMMON-LISP package;

    3. if neither of the above applies then the symbol belongs to and
       is exported from the COM.RAVENBROOK.COMMON-LISP-LOG package.

The COM.RAVENBROOK.COMMON-LISP-LOG package has nickname CL-LOG. Its
use-list is the system default.

The version of CL-LOG can be determined from the value of
*CL-LOG-RELEASE*. This is release 0.1.0.



4.  THE LOG-MANAGER

4.1. Global accessor log-manager

(log-manager) returns the current log manager; (setf log-manager) sets
it. The new value must be either null or of type log-manager; if the
old value of (log-manager) was non-null then its messengers will be
stopped, by calling stop-messenger on each of them.


4.2. Class log-manager

This is the class of log-managers. You might or might not want to
subclass it.

Accessors on log-manager:

(log-manager-messengers log-manager) [setfable] returns the messengers
of a log-manager. Typically you won't ever need to set this directly -
see start-messenger and stop-messenger.

(log-manager-message-class log-manager) [setfable] returns a
designator for the class of messages which the log manager will
create. The log-manager class has initarg :message-class which will
be sufficient for most uses.

(logging-disabled log-manager) [setfable] can be used to disable and
re-enable logging globally.


4.3. Disabling the log manager

In addition to the logging-disabled setter above, there's the
following macro:

(with-logging-disabled &body body)

Logging is disabled in the lexical scope of this form and returned to
its previous state on exit, irrespective of any intervening calls to
(setf logging-disabled). It's just like a variable binding.


4.4. Invalidating the log manager

The generic-function invalidate-log-manager is called after categories
are defined or undefined, and after log-manager-messengers is reset
(e.g. after calling start-messenger or stop-messenger).

You can depend on invalidate-log-manager being called before the next
log-message operation completes, but you cannot depend on exactly when
this will be or how many times it will be called. (So, for instance,
in this version of CL-LOG, several calls to defcategory with no
intervening log-message will only cause invalidate-log-manager to be
called once).

CL-LOG supplies the primary method
    (invalidate-log-manager (log-manager log-manager))

You might want to define :after methods on this (for example, to close
resources used by a subclass of log-manager).


4.5. Rebinding the log manager

Make a temporary switch of log-manager with this macro:

(rebinding-log-manager ((log-manager) &body body))


5.  TIMESTAMPS

Every message is automatically given a timestamp (provided it's been
accepted by at least one messenger). It's a structure of type
timestamp (which you can subclass using defstruct with :include,
should you see the need).

Use constructor (make-timestamp (log-manager)) if you ever want a
timestamp of your own to take home and play with.

The timestamp has two readers: timestamp-universal-time and
timestamp-fraction. The fraction is in internal-time-units-per-second.

Warning: there's no obvious way in Common Lisp to tell what the
current fractional value of the universal-time is. CL-LOG's timestamps
add the universal-time when the log-manager was instantiated to the
change in (get-internal-real-time) since then. This means that
timestamps will be self-consistent but not externally consistent: the
fraction will be zero when the timestamp-universal-time changes but
probably won't be zero when the system's univeral-time changes.


6.  CATEGORIES

6.1. Messages, messengers and category-satisfies

Every message has a category, specified by the first argument to
log-message.

Every messenger has a category, specified when the messenger is
instantiated, which defines the message categories which that
messenger will accept. The messenger's category cannot be changed, but
you can use defcategory / defcategory-fn (see below) to tailor
on-the-fly how message and messenger categories are related.

A messenger's category is either null (meaning: accept all messages),
or an atom (meaning: this category is required), or a list starting
with one of AND, OR and NOT (meaning: a logical combination of
required categories). It's suggested that the atoms should be
keywords; this version of CL-LOG doesn't enforce that but it leaves
space for future expansions in which (e.g.) funcallables might have
some meaning.

A message's category is either an atom or a list of atoms (meaning:
all these categories apply to this message).

The function category-satisfies is called to determine whether its
first argument (a message category) "satisfies" its second argument (a
messenger category):

    ;; needed either, got both, so satisfied
    (category-satisfies '(:this :that) '(or :this :that)) => T

    (category-satisfies :error (and :info (not :error))) => NIL


6.2. defcategory

The macro defcategory is used to define the expansions for messengers'
categories. For example, given:

    (defcategory :interesting (or :important :urgent))

we have not only

    (category-satisfies :interesting :interesting) => T

but also

    ;; this message is urgent -- will it be accepted by a messenger
    ;; which expects its messages to be interesting?
    (category-satisfies :urgent :interesting) => T

These expansions only affect the messengers' categories (and not the
categories of the messages):

    ;; this message is interesting -- will it be accepted by a
    ;; messenger which expects its messages to be urgent?
    (category-satisfies :interesting :urgent) => NIL


6.3. Advanced defcategory

For clarity, you can also define a category without an expansion, as
in the example at the start of this document:

    (defcategory :critical)

This has no semantic meaning (and although it will overwrite a
previous expansion for :critical, it's clearer for you to use
undefcategory). It might make your code more readable.

Note that you can define a category in terms of itself:

    (defcategory :warning (or :warning :error))

This is quite safe. It means the same as:

    (defcategory :warning :error)

- the messenger will accept either warnings or errors. This last use
came to me as I was writing this document. It's an interesting quirk
but I don't much care for it as it really doesn't read well.


6.4. defcategory-fn

The defcategory macro expands into calls to the function
defcategory-fn. This function may be useful if you wish to change the
logging category of one or more messengers on the fly.

For example, you might do this by setting the category of the
messenger(s) to be :log-level and defining

    (defun (setf log-level) (new-value)
      (defcategory-fn :log-level new-value))

All your application has to do is to (setf (log-level) :warning) or
whatever, and all :log-level messengers have been changed to respond
to warnings.


6.5. Undefining categories

The macro undefcategory removes the expansion of a category. Example:

    (undefcategory :debug)

The function (clear-categories) undefines all category expansions.


7.  MESSAGES

7.1. log-message

The macro log-message is used to send messages.

    (log-message category description &rest arguments)

The category, always evaluated, is compared using category-satisfies
with the category of every messenger to determine which if any
messenger(s) will accept the message. The results of this comparison
are cached, so next time you log a message with this category the
lookup will be fast.

Provided at least one messenger accepts the message, a message object
is instantiated and given a fresh timestamp and the category; the
description and arguments are evaluated and set into the message. The
class of this object is determined by (log-manager-message-class
(log-manager)).


7.2. Class base-message

This is the root class for messages. The following readers are
provided:

  message-timestamp
  message-category
  message-description
  message-arguments


7.3. Class formatted-message

This subclass of base-message is for messages which will be formatted
to a text stream. The following reader is provided:

  message-text

This value is generated (lazilly) by calling the generic function
format-message whose primary method is defined thus:

  (defmethod format-message ((self formatted-message))
    (format nil "~a ~a ~?~&"
            (message-timestamp self)
            (message-category self)
            (message-description self)
            (message-arguments self)))

You probably want to specialise this.


8.  MESSENGERS

8.1. Class base-messenger

This is the root class for messengers.

To instantiate and activate a messenger, call start-messenger.

   (start-messenger class &rest initargs &key name &allow-other-keys)

To deactivate a messenger, call stop-messenger. This generic function
will accept either a messenger (i.e. the object returned by
start-messenger) or the name of a messenger. There are two methods on
stop-messenger

   (defmethod stop-messenger ((self base-messenger)))
   (defmethod stop-messenger (name)

and you're free to add more.

Only one messenger with a given name (equalp) may be started at any
one time. Starting a new messenger with an existing name will
automatically stop the old one.

The function call (find-messenger name) returns the messenger (if any)
with the given name.

The following readers are provided for instances of base-messenger:

  messenger-name (initarg :name)
  messenger-category (initarg :category)


8.2. Generic function messenger-send-message

This generic function is called once for each messenger which has
accepted any given message. It defines what the messengers will
actually do with their messages.

  (defgeneric messenger-send-message (messenger message))

Three methods are provided. The first

  (defmethod messenger-send-message ((messenger base-messenger) message))

signals an error. The other two are specialised on ring-messenger
(section 8.3) and text-stream-messenger (section 8.4) respectively. If
your messenger doesn't inherit from one of these two classes, you'll
have to define a method on messenger-send-message.


8.3. Class ring-messenger

This subclass of base-messenger allows you to specify -- via the :length
initarg --  how many messages you wish to keep. It retains this number of
messages (as raw objects) and is thus desinged to give cheap access to
your application's recent actions. Retrieve the messages with the
accessor ring-messenger-messages.

The message class base-message is sufficient for ring-messengers.

This class is dead useful in error handlers.


8.4. Class text-stream-messenger

This subclass of base-messenger handles the output of log messages as
formatted text to a stream. Specify this stream with the :stream
initarg (associated reader text-stream-messenger-stream).

You'll need messages of class formatted-message (section 7.3) in order
to use text-stream-messengers. The method on messenger-send-message
specialised on these two classes looks a little bit like this.

  (defmethod messenger-send-message ((messenger text-stream-messenger)
                                     (message formatted-message))
    (let ((ostream (text-stream-messenger-stream messenger)))
      (write-string (message-text message) ostream)))

Calling stop-messenger on a text-stream-messenger will automatically
close the associated stream.


8.5. Class text-file-messenger

This subclass of text-stream-messenger supports output to a
text-file. Specify the file with the :filename initarg (associated
reader text-file-messenger-file).


COPYRIGHT

This file copyright (c) 2007 - 2009 Nick Levine (ndl@ravenbrook.com)
Log5 copyright (c) 2007 Gary Warren King (gwking@metabang.com)

Permission is hereby granted, free of charge, to any person obtaining
a copy of this software and associated documentation files (the
"Software"), to deal in the Software without restriction, including
without limitation the rights to use, copy, modify, merge, publish,
distribute, sublicense, and/or sell copies of the Software, and to
permit persons to whom the Software is furnished to do so, subject to
the following conditions:

The above copyright notice and this permission notice shall be
included in all copies or substantial portions of the Software.

THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND,
EXPRESS OR IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF
MERCHANTABILITY, FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT.
IN NO EVENT SHALL THE AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY
CLAIM, DAMAGES OR OTHER LIABILITY, WHETHER IN AN ACTION OF CONTRACT,
TORT OR OTHERWISE, ARISING FROM, OUT OF OR IN CONNECTION WITH THE
SOFTWARE OR THE USE OR OTHER DEALINGS IN THE SOFTWARE.


$Id: //info.ravenbrook.com/user/ndl/lisp/cl-log/doc/index.txt#6 $