Laying logging foundations

Gary W. King’s logging library log5 is a lispy way to do logging.

It’s simple to set up and should probably be the first dependency you add to any serious project.

Unfortunately, the User Guide‘s examples are a bit bland.

So here’s some salt (for simplicity let us also ignore log5′s default categories and outputs):

Preliminaries

For comfort.

(defpackage :our-package
  (:use :common-lisp :log5))
 
(in-package :our-package)

Categories

Define new categories every time you add a semantic part to your project:

(defcategory borg-attack)
(defcategory federation-cabal)
(defcategory ion-flux)
(defcategory all-categories (or borg-attack federation-cabal ion-flux))

…or want to differentiate on the seriousness level of logging messages:

(defcategory debug)
(defcategory error)
(defcategory info)
(defcategory all-levels (or debug info error))

Outputs

Outputs get added to every logging message automatically.
They are evaluated at the time the log messages gets sent.

Let’s add one for the time and one for a line break:

(defoutput newline (format nil "~%"))
 
(defoutput time-hms
  (multiple-value-bind (second minute hour day month year)
    (decode-universal-time (get-universal-time))
    (format nil "~D:~2,'0D:~2,'0D" hour minute second)))

And one for the load averages, so we can see whether an error might have occurred due to heavy load (maybe a race condition):

(defoutput load (format nil "[~A]" (load-averages)))

If your project is web-based, you might also want to add the username associated with the current session, like this:

(defoutput username (format nil "[~A]"
  (when (boundp hunchentoot:*session*)
    (session-value 'username))))

Finally, if you’re running SBCL and don’t mind a bit of a hack, you can also identify the function context:

(defmacro current-function-name-log5 ()
  `(caaddr (sb-debug::backtrace-as-list)))

(defoutput function-name (format nil “[~A]” (current-function-name-log5)))

Senders

Senders decide where logging messages from certain categories go, and what they look like.
Here’s one that will log messages from all of the above categories to the standard output, utilizing all of the outputs we defined:

(start-sender 'debug
  (stream-sender :location *standard-output*)
  :category-spec '(all-levels all-categories)
  :output-spec '(time-hms load username function-name message newline))

Usage

You would log a message like this:

(log-for (borg-attack ion-flux)
  "The ion flux of vessel ~A broke down due to a borg attack"
  (get-current-vessel))

That’s already incredibly useful!

No comments yet. Be the first.

Leave a reply