rtiさんのマイページ

史上最速のデバッグログを考える。

2010/03/04 05:49



超高速なサーバを作ったとする。
一秒一マイクロ秒、一クロックを争うぐらいの超高速なサーバ。
超高速なサーバを作ったとしてもデバッグログはほしいものだ。
デバッグログってのはアクセスログとかとは別にアプリケーション内部の情報を書き出すヤツ。俗に言うアプリケーションログ。

LogObjectSingleton()-getInstance()-WriteFormat(%s:%d 何かよくないことがおきますた,__FILE__,__LINE__);


これを状態に応じて ON / OFFしたい。
debug モードで起動されたら、ログを出し、そうでないならログを出さないようにしたい。
だけど、なるべく超高速なサーバのパフォーマンスを落としたくない。
さて、この問題を解決するには、どのようなアプローチがあるんだろうか。
その1 グローバル変数で分岐する

if (g_isDebug)
{
LogObjectSingleton()-getInstance()-WriteFormat(%s:%d 何かよくないことがおきますた,__FILE__,__LINE__);
}


g_isDebug変数は邪悪なグローバル変数。
状況に応じて、ログを有効、有効にできるので保守が非常にしやすいが、毎回if文が実行されるので、分岐予測ペナルティをくらいやすい。
メリット
状態に応じて切り替えられる
デメリット
毎回if分岐が発生し分岐予測ペナルティを食らう。


その2 #defineマクロ

#ifdef _DEBUGLOG
LogObjectSingleton()-getInstance()-WriteFormat(%s:%d 何かよくないことがおきますた,__FILE__,__LINE__);
#endif


DEBUGLOGを有効にしたビルドのときのみ有効になる。
リリースではこのコードは無視されるので問題ない。
ただし、リリースしたソフトウェアがバグってしまってログをはかせたい場合に困る。
リリースしたものには、ログをはくルーチンが入っていないからデバッグログをはかせられない。
ログを有効にしたものをユーザに送って利用してもらわないといけない。
また、coreが送られてきたときのことを考えると、#defineを有効にしたものと無視したものの2つのバージョンを保存しておかないといけない。


メリット
超高速
デメリット
ユーザがログはきとログはかないをきり替えないといけない(ツールでアシストはできそうだが。。。)
coreをデバッグするためにログはきとログはかないの2種類を保持しておかないといけない。
その3 LoadLibrary
writelog() というログを出力する関数を作って、dllに入れる。
そして、ログを出力するdllとログを出力しないdllの2つ用意する。
これをアプリケーション起動時に読み込んで切り替える。
リリースするときは両方のdllをリリースする。

//logD.dll ログをはく
void writelog(const char , ....)
{
//実際にログをはく処理
}



//logR.dll ログをはかない
void writelog(const char , ....)
{
//何もしない!
}


メリット
分岐がなくなる。
関数呼び出しのオーバーヘッドだけでいれる。
デメリット
関数呼び出しのオーバーヘッドは無視していいんか?
一応動的に切り替えることはほぼ不可能?(自前でdllを再マップするハックが必要)
その4 分岐先予測
考えを変えて、分岐予測キャッシュを導入する。
http://ja.wikipedia.org/wiki/%E5%88%86%E5%B2%90%E5%85%88%E4%BA%88%E6%B8%AC
http://d.hatena.ne.jp/yupo5656/20040727
詳しくないし、ベンチも取っていないのでよくわからない。
アプリケーションログはこれで早くなったらいいなぁ
メリット
単一バイナリでそこそこ早い。(多分)
デメリット
自分の知識が足りないのでもっと調べる必要がある。


その5 動的書き換えでログ出力部分をnopにする
これもベンチとってもいないし、そもそも実装もしないいないんですけど、、
ログを出力する関数があったとして、

WriteFormat(%s:%d 何かよくないことがおきますた,__FILE__,__LINE__);


んで、こんな風にログをはくコードが関数の後ろに配置されたとする。

mov ... //通常の命令
call logger: //ここでロガーをコールする
mov ... //通常の命令
ret; //この関数時代の終了

logger: //ロガー関数

push __LINE__ //ロガー関数を呼ぶところらへん
push __FILE__
call WriteFormat
ret //元に戻る


call logger: を nop でつぶせば分岐しないから早くねぇ?www って考え。



mov ... //通常の命令
nop //消した!
nop //同じバイト数調整する
nop
nop
nop
mov ... //通常の命令
ret; //この関数時代の終了

logger: //ロガー関数はもう呼ばれない.

push __LINE__ //ロガー関数を呼ぶところらへん
push __FILE__
call WriteFormat
ret //元に戻る






メリット
単一バイナリで nop のコストぐらいで高速な動作が手に入る。
デメリット
これ動くの?w
どうやって、ロガー関数を見分けるの?
課題は山ほど




他にどういう方法があるだろうか。
他のソフトはどうやっているんだろう。
mysqlとかはデバッグオプションつきでコンパイルした場合だけフルデバッグログがでたような気がした。
その2 #defineマクロ を利用するのが一般的なんだろうが、、、、、
オープンソースの場合は自分でコンパイルできるが、プロプライエタリなソフトの場合そうはいかないんだよな。。。
どうしたものか。


Binder: rtiのバインダー(日記数:296/全体に公開)
このエントリーをはてなブックマークに追加

このブログにコメントをつけるには、ログインする必要があります。
マイページをお持ちでないひとは「マイページを作成する」ボタンを押してマイページを作成してください。
不適切なブログを見つけたら、こちらからご報告ください!

Mail Address(GMO ID):

Password:

自動ログインパスワードを忘れた方

最近書いたブログ


https://www.freeml.com/feed.php?u_id=7771196&f_code=1



Copyright(C)2018 GMO Media, Inc. All Rights Reserved.