Rlogでズボラロギング

c++

デバッグとかでログコードを埋め込みまくろうとして全ソースがカオスになったりとかありませんか？　特に画像や波形データなど、デバッガでは追いにくいような数値バグのデバッグにて納期に追われていたりすると、、、ぅがが
原因絞込みのために複数レベルのログ出力をこさえて、しかしそれでも原因が判明しないために更にアドホックにログ出力を追加。挙句の果てに「いー！もーめんどい！とにかく全部吐く」とやってしまって後からフィルタしたりだとか。ハードウェアのサイクルベースシミュレーションとかで画像なんかを扱っていると、データが多いのであんまりそれやると本当にカオスになりますし、そもそも遅いです。遅いなーしまったなー、とマクロで無効にしようと思ったらあらら、、、デバッグレベルごとにアドホックにつけていた#ifdefの山にゴミが大量に付着していてもうほどくにほどけないよー　orz　　・・・なんてこと*1.
こんなときにこそ先人の智恵と遺産を活用しましょう。という、後悔にまみれた覚書など。

RLogとは

RLogはmessage loggingを効率的に行うC++用のクラス・マクロライブラリです。で、glogとかQtのログライブラリと比べて何が美味しいかというと

  1. 階層的にログレベルを指定できる　→　こと細かなログレベル管理ができる
  2. 各レベルはdormant(休眠)状態に最適化されている　→　使わないときのパフォーマンスへの影響が少ない　→　プロダクトコードに入れっぱなしにしても大丈夫

といったあたり。つまりは計画能力０の僕でも「とりあえず書き倒して後で忘れる」ことができそうなよかーん。

使い方

使い方がC++ライブラリのくせにC++ishではなくC-ish。glogやQtのq...のようなstreamな書き方はサポートせずprintf()な感じになっています。この当たりは効率優先かな。
まあ普通にこんな風に

#include <rlog/rlog.h>
#include <rlog/rloglocation.h>
#include <rlog/StdioNode.h>
#include <rlog/RLogChannel.h>

using namespace rlog;

main(int argc, char** argv)
{
    RLogInit(argc, argv);

    const char *errorLevel = argc == 1? "": argv[1];

    StdioNode stdLog(STDERR_FILENO);                 // エラー出力ノードを作って
    stdLog.subscribeTo(RLOG_CHANNEL(errorLevel));    // 指定したエラーレベルでの購読要求

    rDebug("it's a debug message");
    rInfo("it's an information");
    rWarning("there's something dangerous around here");
    rError("something wrong. we have some problems now");
    rAssert("is life beautiful?" == "yes");
}

と書くだけでも

tkuro@sawshark> gcc mini.cpp -o mini -lrlog -DRLOG_COMPONENT=logtest
tkuro@sawshark> ./mini
12:20:33 (mini.cpp:17) it's an information
12:20:33 (mini.cpp:18) it's a debug message
12:20:33 (mini.cpp:19) it's a warning
12:20:33 (mini.cpp:20) emergency! bail-out!! it's fatal
12:20:33 (mini.cpp:22) Assert failed: "is life beautiful?" == "yes"
terminate called after throwing an instance of 'rlog::Error'
what(): Assert failure at mini.cpp:22 -- "is life beautiful?" == "yes"
zsh: abort ./mini

てな感じにファンシーに出ます。しかし。しかしです。本当にすごいのはここから。

階層的ロギング

チャネルはオレオレチャネルが作れます。その際に名前がつけれるのですが、これがディレクトリ構造と同じような階層構造を取れます。
ところで僕は関西ではFM-COCOROが大好きです。Over 45のためのラジオ局ってことで実に趣味に走った音楽の数々。45は超えてないんだけど実にジャストミートです。。。いや関係ないですね。

static RLogChannel *afternoonChannel  = DEF_CHANNEL("debug/fm-cocoro/afternoon",Log_Debug);
static RLogChannel *amusicChannel     = DEF_CHANNEL("debug/fm-cocoro/amusicmooning",Log_Debug);
static RLogChannel *trafficChannel    = DEF_CHANNEL("info/traffic", Log_Info);
static RLogChannel *otherChannel      = DEF_CHANNEL("error/other",  Log_Error);
　　:
    :

subscribeTo()で登録するときに上位階層のみを指定するとマッチするチャネル全てが聞けます。ラジオでそうなったらカオスですが。
てなわけでこれを使うとある程度分類さえしておけば後から柔軟に出力するチャネルを選ぶことが出来ます。なかなかに便利。

本当に速いの？

さて、一番肝心なところですね。

#include <rlog/rlog.h>
#include <rlog/rloglocation.h>
#include <rlog/StdioNode.h>
#include <rlog/RLogChannel.h>
#include <rlog/rlog-c99.h>
#include <iostream>
#include <cmath>

using namespace rlog;
using namespace std;

double foo()
{
    double sum = 0;

    for (int i = 0 ; i< 0x7ffffff; ++i) {
#ifdef LOG
        rDebug("it's a debug message");
        rInfo("it's an information");
        rWarning("there's something dangerous around here");
#endif
        sum += sin(i);
    }

    return sum;
}

main(int argc, char** argv)
{
    RLogInit(argc, argv);

    const char *errorLevel = argc == 1? "error": argv[1];

    StdioNode stdLog(STDERR_FILENO);
    stdLog.subscribeTo(RLOG_CHANNEL(errorLevel));

    cout << foo() << endl;
}

こんなのこさえてみました。これでLOGを定義した_with_logと定義しない_without_logについて

./bench_without_log  9.11s user 0.00s system 99% cpu 9.116 total
./bench_with_log  9.18s user 0.00s system 99% cpu 9.184 total

・・・・んん！　　馬路ですか。

結論

これは使えそう

*1:無計画な僕だけかも・・・