Log4CLを使ってみる

( Common Lisp Libraries Advent Calendar の10日目の記事です )

最近やっと実感を得ましたが、(デバッグ)ログは大事ですね。 遠隔地にいるライブラリ製作者とやりとりする回数を減らせます。

ということで、Common Lispでログ出力するライブラリ、Log4CL を眺めてみます。

Log4CL は、CLikiの Current recommended libraries で紹介されています。
JavaのロギングライブラリであるLog4jを参考にして作られているようなので、Java使いの人にとっては使いやすいのかもしれません。

インストールは Quicklisp で行えます。

> (ql:quickload :log4cl)

正確な情報はgithubにあるREADME.mdおよびソースコードを読んで調べて頂くとして、 ざっと概要を説明してみます。

Log4CL は次の3つの構成要素から成ります。

• ロガー : ログの出力先 (論理的)
• アペンダ : ログの出力先(出力方法) (コンソール出力・ファイル出力など)
• レイアウト : ログ出力の整形方法

論理的な出力先であるロガーに、実際の出力方法を定義したアペンダを対応づけ、 レイアウトで指定されたフォーマットでログを出力します。

ログレベルは、 fatal,error,warn,info,debug, user1 ～ user4, trace, user5 ～ user9 の15段階が指定できます。 ログレベルの名前に対応する出力関数(マクロ)が定義されています。

CL-USER> (log:fatal "fatal error")
[22:57:21] [fatal] <cl-user> - fatal error

CL-USER> (log:info "hello")
[22:57:51] [info] <cl-user> - hello

1文字の省略形も定義されています。

CL-USER> (log:i "helo")
[22:59:26] [info] <cl-user> - helo

CL-USER> (log:w "w")
[23:00:10] [warn] <cl-user> - w

「<cl-user>」 は現在のパッケージ名です。 ロガーを指定しない場合、デフォルトでカレントパッケージの名前がロガーとして利用されます。

ロガーの作成はmake-logger関数、あるいはmake関数で行えます。
ロガーは親子関係を持ちますが、キーワードシンボルを指定すると 親=カレントパッケージ名, 子=シンボル名 という 構造が作成されるようです。

ログ出力関数でロガーを指定する場合は、名前(シンボル)を直接指定するほうが短くて良さそうです。

CL-USER> (log:w (log:make-logger :child) "w")
[23:02:41] [warn] <cl-user:child> - w

CL-USER> (log:f (log:make-logger '(parent child)) "f")
[23:03:13] [fatal] <parent:child> - f

CL-USER> (log:e :child "e")
[23:04:17] [error] <cl-user:child> - e

ロガーが出力するログレベルを設定するには、 config 関数を使います。省略形は c です。
なお、親ロガーの設定を引き継ぐよう設定するには、:unsetを指定すれば良いようです。 デフォルトの設定は :unset です。

CL-USER> (log:debug "hoge")
; No value
CL-USER> (log:c :d)  ;; (log:config :debug) と同等
CL-USER> (log:debug "hoge")
[23:13:02] [debug] <cl-user> - hoge

ログレベルに対応する出力処理以外に、評価前の式と評価後の値を出力する expr 関数があります。 処理系が SBCL の場合は、どの関数の中でログが出力されたかまでロガー名に含めてくれるようです。

(defun foo (a)
           (flet ((bar (b)
                    (log:expr a b (+ a b))))
             (bar 10)))
(log:config :debug)

;; CCL
CL-USER> (foo 2)
[23:17:57] [debug] <cl-user> - A=2 B=10 (+ A B)=12 

;; SBCL
CL-USER> (foo 2)
[23:17:06] [debug] <cl-user:foo:bar> - A=2 B=10 (+ A B)=12 

その他、アペンダやレイアウトの対応づけや設定ファイルの読み込み等が可能ですが、 README.md 以上に有益なことを書ける気がしないので、ドキュメントにかかれていない アペンダの定義を行い、syslogにログを出力してみます。

(ql:quickload :cl-syslog)

;; アペンダを定義
(defclass syslog-appender (log4cl-impl:appender)
  ())

;; アペンダの出力方法を定義
(defmethod log4cl-impl:appender-do-append ((appender syslog-appender) logger level log-func)
  ;; 出力はcl-syslogに丸投げ。
  (cl-syslog:log "log4cl" :local7 :info
    (with-output-to-string (s)
      (log4cl-impl:layout-to-stream
       (slot-value appender 'log4cl-impl:layout) s logger level log-func))))

;; ロガーを作成
(defvar syslog-logger (log:make '(syslog)))

;; ロガーにアペンダを対応付ける
(log:add-appender syslog-logger (make-instance 'syslog-appender))

;; ログ出力
(log:i syslog-logger "from cl")

kurohuku@mypc:/var/log$ tail -1 syslog
Dec 10 23:49:36 mypc log4cl: INFO - from cl

Log4jと異なりデフォルトで定義されてるアペンダは少ないので、 コンソールやファイル以外に出力を行いたい場合は自分でアペンダを定義する必要がありますが、 expr関数(マクロ)などはデバッグに便利ですし、試しに使ってみると良いと思います。

なお、Quicklispで (ql:system-apropos "log") でライブラリを検索したところ、 他にもロギングライブラリっぽいものが見つかりました。

• cl-log
• hu.dwim.logger
• log5
• logv
• (cl-syslog)
• (irc-logger)

・・・見つかりましたが、数が多いので比較はしません。ごめんなさい。