Erlang: ログライブラリLager
前置き
サービスとか公開した後で継続的に機能追加、デバッグしていく事を考えるとログってかなり重要ですよね。。
外部の機器との通信内容とか、エラーが出た場合にそのときのデータの中身がどうなってたとか、ユーザーからのリクエストの内容がどうだったかとか、あとできればソースコードの何行目でどんな種類のエラー吐いたのか...とか。
あんまりログを吐かせるとパフォーマンスに影響しそうなので、その辺はバランスの問題ですが、パフォーマンスに問題が出ないレベルで、かつ見づらくならない程度であれば出来るだけログは吐かせたいです。
仕事で作ってるサービス(Ruby製)では、そんなに頻繁に通信要求が飛んで来るわけではないので外部機器とのやりとりは全てsyslogに吐き出させています。なので、なにか起こったらデータを解析してサーバ側で発生してる問題か、端末側で発生してる問題かの切り分けがすぐできます。さすがに秒間数百〜数千のリクエストがあるような所ではこれは現実的でないでしょうけど、うちぐらいならむしろログに出しておいて、その後の対応を速くする方が大事なので。
Lager
前置き長かったですが、ErlangのロガーのひとつであるLagerです。Erlangには標準でロガーがついてますが、正直わかりづらい...w ログわかりずらいって怖い...って思って調べたらわかりやすいのありましたw 表題のLagerです。
あのbashoによる開発のようです。
ちなみに既にV氏によるlager紹介記事がありますが、勉強を兼ねて自分でも書いてみます。読むのはあっちがいいと思いますw
標準ではコンソールへのアウトプットとlogディレクトリ以下へのファイル出力になるようですが、設定次第でSyslogへの送信もできるようです。AMQPにも対応してるとの事ですが、これは使った事無くてよくわかりません...
準備
ここではrebarを使っている事を前提にして書きます。
自分のプロジェクトで使うには、まずrebar.configを編集します。編集個所は２カ所。
- コンパイルオプションに {parse_transform, lager_transform} を追加する。
- depsにlagerを追加する。
の２つです。
1はrebar.config中のerl_optsに{parse_transform, lager_transform} を追加します。こんな感じ
{erl_opts, [warnings_as_errors, warn_export_all, warn_unused_import, warn_untyped_record, {parse_transform, lager_transform} ]}.
最後に追加してます。
2は他のアプリケーションを自分のプロジェクトに追加する時と同じです。
{deps, [ {lager, "1.*", {git, "git://github.com/basho/lager.git", {branch, "master"}}}, {meck, "0.7.*", {git, "git://github.com/eproxus/meck.git", {branch, "master"}}}, {edown, "0.3.*", {git, "git://github.com/esl/edown.git", {branch, "master"}}} ]}.
先頭にlager追加しました。
あとは
$ ./rebar get-deps compile xref
すればおkです。
参考までに、rebar.config全体としてはこんな感じになりました。
{erl_opts, [warnings_as_errors, warn_export_all, warn_unused_import, warn_untyped_record, {parse_transform, lager_transform} ]}. {xref_checks, [fail_on_warning, undefined_function_calls]}. {cover_enabled, true}. {sub_dirs, ["rel"]}. {edoc_opts, [{doclet, edown_doclet}, {dialyzer_specs, all}, {report_missing_type, true}, {report_type_mismatch, true}, {pretty_print, erl_pp}, {preprocess, true}]}. {validate_app_modules, true}. {deps, [ {lager, "1.*", {git, "git://github.com/basho/lager.git", {branch, "master"}}}, {meck, "0.7.*", {git, "git://github.com/eproxus/meck.git", {branch, "master"}}}, {edown, "0.3.*", {git, "git://github.com/esl/edown.git", {branch, "master"}}} ]}.
使い方
使い方はいたって直感的です。最初にLagerアプリケーションを起動しておいて
application:start(lager).
あとはログを吐き出させたい場所で
lager:error("helo world!").
のように。あと動的に値を埋込みたい時は、いつもの感じで
lager:notice("helo ~p", ["world!"]).
のようにすれば標準でコンソール出力と、アプリケーションディレクトリ直下のlogディレクトリ内にerror.logとconsole.logが作られて書き込まれます。
。
一応注意が必要なのは、コンソールで直接 lager:error("hoge") とかやってもundefined functionて怒られます。
コードの中に書いてないと動きませんのでご注意を。
ちなみにV氏のサンプルだと、いきなりapplication:start(lager)で動きましたが、僕の手元のプロジェクトでは、そのまえに
application:start(compiler). application:start(syntax_tools).
しないと怒られました。なにが違うんだろう...?
ログレベルには
- debug
- info
- notice
- warning
- error
- critical
- alert
- emergency
があるようです。lagerモジュールにこのログレベルを関数名として呼び出せばいいです。lager:notice/2とか。
ただ、lager.erlのソース見てみると、これらの関数は定義もexportもされてないんですよねー。-export_typeってのがなんかやってるようですが、まだわかってません...わからんことだらけ。
設定変更(出力先ファイルおよびログレベル等)
標準でログはファイル(アプリケーションのルートディレクトリのlogディレクトリ以下)へ書き出されますが、書き出しレベルを変更したい場合はapplication:start(lager)する前に、一旦application:load(lager)しておいて、環境設定を保存してからapplication:start(lager)します。
例えばこんな感じでアプリケーションの.app.srcファイルに書いておいて
{application, lager_sample, [ {description, ""}, {vsn, "0.1"}, {registered, []}, {applications, [ kernel, stdlib ]}, {mod, { lager_sample_app, []}}, {env, [ {lager, [ {handlers, [ {lager_console_backend, debug}, {lager_file_backend, [ {"log/error.log", error, 10485760, "$D05", 5}, {"log/console.log", debug, 10485760, "$D05", 5}, {"/var/log/lager_sample/error.log", error, 10485760, "$D05", 5}, {"/var/log/lager_sample/console.log", debug, 10485760, "$D05", 5} ]} ]} ]} ]} ]}.
起動時に
application:start(lager_sample), {ok, [{handlers, LConfig}]} = application:get_env(lager_sample, lager), application:load(lager), application:set_env(lager, handlers, LConfig), application:start(lager).
とすると上記の設定で起動出来ます。
なお、この設定では絶対パスを指定して/var/log/lager_sampleディレクトリ以下にもログを書き出しているので事前にディレクトリを作って適切なパーミッションにしておく必要があります。
また、この設定だとコンソールと log/console.logおよび/var/log/lager_sample/console.logにはdebugレベル以上(つまり全て)のログを書き出し、log/error.logおよび/var/log/lager_sample/error.logにはerrorレベル以上のログを書き出します。
また、
{"error.log", error, 10485760, "$D05", 5},の中で"$D05"と書いてますが、これは毎日朝5時にログのローテートを行うという意味です。
あと10485760はローテートするファイルサイズ、5は最大でで5つまでファイルを残しておくという意味です。
{ファイル名, ログレベル, ファイルサイズ, ローテートのスケジュール, 保持するファイル数},となります。
あとは通常通り、lager:debug("hoge") などとすれば設定に応じてログが吐き出されます。
サンプル
githubに、今回の学習であれこれ弄ったサンプルをgithubに置いておきます。
使い方はプロジェクトのREAMEに書いてあります。
追記: Syslogとの連携
最初のほうで書いたように、LagerはSyslogとの連携もサポートしています。厳密にはSyslogとの連携をする為の部分はlager_syslogという別のプロジェクトに切り分けてあるようですが、このlager_syslogを自分のアプリケーションに組み込んで、あとはちゃちゃっと設定するだけで、今まで通りlager:error("hogehoge") とかすると、syslogに日時情報やノード情報と共に"hogehoge"と出力されます。
ただ、lager_syslogが依存しているerlang_syslogがLinuxしかサポートしてないっぽいです。手元ののMacOSX環境では動作しませんでした。ですので試す場合はLinuxで試してみてください。
ファイルとコンソールに書き出していた場合と変更する部分は
- rebar.configのdepsにlager_syslogを追加
- lagerのenv設定にsyslogを使う設定を追加
の2つです。
以下がlager_syslogを組み込むようにしたrebar.config全体です。
{erl_opts, [warnings_as_errors, warn_export_all, warn_unused_import, warn_untyped_record, {parse_transform, lager_transform} ]}. {xref_checks, [fail_on_warning, undefined_function_calls]}. {cover_enabled, true}. {sub_dirs, ["rel"]}. {edoc_opts, [{doclet, edown_doclet}, {dialyzer_specs, all}, {report_missing_type, true}, {report_type_mismatch, true}, {pretty_print, erl_pp}, {preprocess, true}]}. {validate_app_modules, true}. {deps, [ {lager, "1.*", {git, "git://github.com/basho/lager.git", {branch, "master"}}}, {lager_syslog, "0.9.*", % {git, "git://github.com/basho/lager_syslog.git", {git, "git://github.com/hiroeorz/lager_syslog.git", {branch, "master"}}}, {meck, "0.7.*", {git, "git://github.com/eproxus/meck.git", {branch, "master"}}}, {edown, "0.3.*", {git, "git://github.com/esl/edown.git", {branch, "master"}}} ]}.
変わったのはdepsのlagerの下にlager_syslogを追加した事だけです。
bashoのオリジナルのlager_syslogはlagerのバージョン1.0.0を要求しているのに対してlagerは1.2.0に上がっており、かつタグもなかったのでlager_syslogをフォークしてバージョン番号だけ直したものを使いました。コメントアウトしてあるほうがオリジナルなのでバージョン番号が一致していたらそちらを使われた方がいいです。まあ今回はデモという事で。
それからlagerのenv設定の所で、以下の設定を追記します。
{lager_syslog_backend, ["lager_sample", local0, debug]}"lager_sample"は識別子、local0はsyslogの種別、debugはログレベルです。
ファイルへの出力やコンソール出力と併用するとこんな感じになりますね。
{lager, [ {handlers, [ {lager_console_backend, debug}, {lager_file_backend, [ {"log/error.log", error, 10485760, "$D05", 5}, {"log/console.log", debug, 10485760, "$D05", 5}, {"/var/log/lager_sample/error.log", error, 10485760, "$D05", 5}, {"/var/log/lager_sample/console.log", debug, 10485760, "$D05", 5} ]}, {lager_syslog_backend, ["lager_sample", local0, debug]} ]} ]}
最後にsyslogの設定を追加しています。
上でアプリの.app.srcに設定してlager起動前に設定を変更する方法を使うとこんな感じです。
アプリの.app.srcファイル
{application, lager_sample, [ {description, ""}, {vsn, "0.1"}, {registered, []}, {applications, [ kernel, stdlib ]}, {mod, { lager_sample_app, []}}, {env, [ {lager, [ {handlers, [ {lager_console_backend, debug}, {lager_file_backend, [ {"log/error.log", error, 10485760, "$D05", 5}, {"log/console.log", debug, 10485760, "$D05", 5}, {"/var/log/lager_sample/error.log", error, 10485760, "$D05", 5}, {"/var/log/lager_sample/console.log", debug, 10485760, "$D05", 5} ]}, {lager_syslog_backend, ["lager_sample", local0, debug]} ]} ]} ]} ]}.
起動時に以下のようにlagerの設定を入れ替える
application:start(lager_sample), {ok, [{handlers, LConfig}]} = application:get_env(lager_sample, lager), application:load(lager), application:set_env(lager, handlers, LConfig), application:start(lager).
これで後は通常通り、
lager:debug("this id debug mesage!").
のようにコード中に書いておけばsyslogに出力されます。
Syslogへログを吐き出すサンプルは上のサンプルの"syslogブランチ"にあります。
