Delayed Evaluation Across Packages April 24th, 2011
Patrick Stein

For my networking layer library, I wanted to provide ubiquitous logging. At the same time, I did not want to tie the application to my choice of logging library. I wanted the user to be able to pass me a function where I could give them a logging category and something to log.

(in-package :unet)

(defvar *logger-function* nil)

(defmacro log-it (category thing-to-log)
  `(when *logger-function*
     (funcall *logger-function* ,category ,thing-to-log)))

This seems simple enough, right? Now, throughout my code, I can do things like:

(log-it :incoming-packet packet)
(log-it :list-of-unacked-packets (get-list-of-unacked-packets))
(etc)

The application can register a *logger-function* something like this:

(defun app-log-network-msgs (category thing-to-log)
  (cl-log:log-message category thing-to-log))

Here’s the problem though: most (all?) logging libraries are good about not evaluating any arguments beyond the category unless something is actually listening for messages of that category. This makes it reasonable to do stuff like this and only take the speed hit when it’s actually important to do so:

(log-it :excruciating-detail
        (mapcar #'get-excrutiating-detail (append everyone everything)))

With my macro above, I have no way of knowing whether something is listening on a particular category or not. Further, most logging libraries don’t offer a way to query that sort of information.

What to do?

What I wanted to do was to pass a macro from the application package into my networking library instead of passing a function. I spent way too long trying to find a way to make this work (especially considering I ran into the same trouble in October, 2009 trying to use some combination of (macroexpand ...) and (eval ...) to let the caller decide which forms to execute).

All it took was posting to comp.lang.lisp to answer my own question: Closures. I changed my macro to create a closure:

(defmacro log-it (category thing-to-log)
  `(when *logger-function*
     (funcall *logger-function* ,category #'(lambda () ,thing-to-log))))

Now, the application’s logger function changes slightly and my forms are only evaluated when the logging library evaluates them:

(defun app-log-network-msgs (category thing-to-log-generator)
  (cl-log:log-message category (funcall thing-to-log-generator))

Hopefully, I will remember next time I run into this.

Binary Logging with CL-Log April 6th, 2011
Patrick Stein

One of the things that my current work does better than anywhere I’ve worked before is logging. When something goes wrong, there is a log file that you can dig through to find all kinds of information about what you were doing and how things were going.

As I move forward programming a game with my UNet library, I want to make sure that I can easily log all the network traffic during testing runs at least.

In looking through the various Lisp logging packages out there, I decided on Nick Levine’s cl-log library.

I installed it in no time with quicklisp.

Then, I set to work trying to figure out how I could use it to log binary data.

Here’s what I ended up with. If you want to do something similar, this should give you a good starting point.

Serializing, unserializing, and categorizing

With my USerial library, I defined a serializer to keep track of the different categories of log messages. And, I made corresponding categories in cl-log.

(make-enum-serializer :log-category (:packet :error :warning :info))

(defcategory :packet)
(defcategory :error)
(defcategory :warning (or :error :warning))
(defcategory :info (or :warning :info))

Specializing the classes

There are two major classes that I specialized: base-message and base-messenger. For my toying around, I didn’t end up adding any functionality to the base-message class. I will show it here though so that you know you can do it.

(defclass serialized-message (base-message)
  ())

(defclass serialized-messenger (base-messenger)
  ((filename :initarg :filename :reader serialized-messenger-filename)))

Then, I overrode the messenger-send-message generic function to create a binary header with my USerial library and then write the header and the message out.

(defmethod messenger-send-message ((messenger serialized-messenger)
                                   (message serialized-message))
  (let ((header (make-buffer 16)))
    (serialize* (:uint64 (timestamp-universal-time
                              (message-timestamp message))
                 :log-category (message-category message)
                 :uint64 (buffer-length :buffer (message-description message)))
             :buffer header)
    (with-open-file (stream (serialized-messenger-filename messenger)
                            :direction :output
                            :if-does-not-exist :create
                            :if-exists :append
                            :element-type '(unsigned-byte 8))
      (write-sequence header stream)
      (write-sequence (message-description message) stream))))

Using it

To get things going, I then made a log manager that accepts my serialized-message type and started one of my serialized-messenger instances.

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

(start-messenger 'serialized-messenger :name "binary-logger"
                                       :filename "/tmp/binary-log.dat")

Once these were started, I made a little utility function to make it easy for me to make test messages and then invoked log-message a few times.

(defun make-info (string)
  (serialize :string string :buffer (make-buffer)))

(log-message :warning (make-info "Warning"))
(log-message :info (make-info "This is info"))

Conclusions

In all, it has taken me about four times as long to write blog post as it did to install cl-log with quicklisp, peek through the cl-log documentation and source code enough to figure out how to do this, and write all of the code.

To really use this, I will probably separate out the category of a message from the serialized type of the message. This will probably involve adding a field to the serialized-message class to track the message type, adding an initialize-instance :before method for that class to look through the arguments to pull out the type, and then adding the type as an extra argument to log-message.

Wayback Popularity March 28th, 2011
Patrick Stein

Wow. A post that I made in February of 2009 just hit Hacker News yesterday and this one from June of 2009 either hit as well or came along for the ride. Suddenly, I have 3655 hits on a two year old articles. Wacky.

Tutorial: Introduction to Conditions and Restarts March 18th, 2011
Patrick Stein

Today was the first time that I really kicked the tires on Common Lisp’s conditions and restarts. I thought that I’d share some of the experience as a sort of mini-tutorial. This tutorial assumes some minimal experience hitting the debugger from the REPL and some comfort with CLOS.

Lisp: Conditions and Restarts from Patrick Stein on Vimeo.

Screencast tutorial on basic conditions and restarts in Common Lisp.

Here is the source code generated during this tutorial.

Swim, Zach! Swim! February 26th, 2011
Patrick Stein

It looks like Google Maps is having some longitude problems along the eastern coast of the U.S. This is from the CL-USERS Google Map:

l