boost::timerを使ってブロック内を時間計測

d:id:hecomi:20100715にて「boost::timerを使って1行コードを挟むだけで経過時間計測」という記事を書きました．その続きのおはなしです．前回のエントリでは，

CTimer t;
... // 長い処理1
t("process 1"); // 1の処理にかかった時間を書き出す
... // 長い処理2
t("process 2"); // 2の処理にかかった時間を書き出す

という形でした．しかしながらt("hogehoge")なんて記述が突然コードの中に＼デデーン／と挟まれていたら何か気持ち悪いですよね．また前回の計測位置を勘違いして，「あれ，思ったより時間が掛かっている？」なんて事態も招きかねません．そこでより良い記述方法としては，d:id:iwiwi:20100221でも紹介されているような，

benchmark("process 1") {
	... // 長い処理1
}
benchmark("process 2") {
	... // 長い処理2
}

という形にする方法が挙げられると思います．これをboost::timerを使って書いてみます．

#include <iostream>
#include <string>
#include <boost/timer.hpp>
#include <boost/format.hpp>
#include <windows.h> // Sleep用

struct __bench__
{
	boost::timer Timer;
	const std::string Str;

	__bench__(const std::string& str)
		: Str(str)
	{}
	~__bench__() {
		std::cout << boost::format("%1%: %2% sec\n") % Str % Timer.elapsed();
	}
	operator bool() {
		return false;
	}
};

#define benchmark(str) if(__bench__ __b__ = __bench__(str));else

int main() {
	benchmark("TEST") { Sleep(1234); } // TEST: 1.234 sec
	return 0;
}

無事測れました．printfライクな記法の部分はboost::lexical_castすれば代用できると思い省いてしまいました．

int main() {
	for (int i=1; i<5; i++) {
		benchmark("Sleep " + boost::lexical_cast<std::string>(1000*i)) {
			Sleep(1000*i);
		}
	}
	return 0;
}

それにしても，d:id:iwiwi:20100221にてiwiwiさんが提案されていらっしゃったこの#defineの記法面白いですね．一応解説を付記しておきます．

条件式の代入を利用して__b__をインスタンス化します（__bench__ __b__(str)とは出来ません）．
if文によってtrue/falseが判定されるので，このときoperator bool()が呼び出されます．
ここでfalseが返されますのでelse内のブロック，すなわちbenchmarkの後ろにある{}ブロックに突入します．
最後にブロックを抜ける際にローカル変数である__b__が破棄されるのでデストラクタが呼び出されます．

といった感じになります．

- - - - -

（追記：2011/1/18）
難点を挙げるとすれば，当たり前ですがブロック内で宣言した変数が外で使用できないことです．例えばインスタンス化に時間がかかるクラスがあるとして，そのインスタンス化に要した時間を測定しようとした場合，上記の記法では計測することが出来ません．

int main() {
	benchmark("Sleep " + boost::lexical_cast<std::string>(1000*i)) {
		Hoge h; // コンストラクタで非常に重い処理をする．
	}
	h.run(); // ブロックの外で実行（エラー）
	return 0;
}

{}というブロック内に記述する限りにおいて，このエラーは避けられません．しかしプリプロセッサの力を借りて非常に胡散臭い手法を使えば，擬似的にブロック内（っぽい何か）で宣言した変数も外で使えるようになります．

#include <iostream>
#include <boost/timer.hpp>
#include <boost/format.hpp>
#include <boost/preprocessor/arithmetic/sub.hpp>
#include <boost/preprocessor/cat.hpp>
#include <windows.h>

struct Hoge {
	Hoge() {
		Sleep(1234);
	}
	void run() {
		std::cout << "I can run!" << std::endl;
	}
};

void outputMesurementTime(const char* str, const double time) {
	std::cout << boost::format("%1%\t: %2% sec\n") % str % time;
}

#define benchmark(str, code) \
	boost::timer BOOST_PP_CAT(timer, __COUNTER__);\
	code;\
	outputMesurementTime(\
		str,\
		BOOST_PP_CAT(timer, BOOST_PP_SUB(__COUNTER__, 1)).elapsed()\
	);


int main() {
	benchmark("TEST CODE",
		Hoge h;
	);
	h.run();

	/* 出力 >
		TEST CODE:	1.234 sec
		I can run!
	*/

	return 0;
}

__COUNTER__はMSVCでのみ（？）使用できる，一意な数字を出力してくれるカウンタです．これをBoost.PreprocessorのBOOST_PP_CATでtimerという文字と結合し，timer1やtimer2といった一意な変数名を作り出します．2回目の使用時（boost::timerのメンバ関数elapsed()を呼び出す時）ではカウンタが1個進みすぎているのでBOOST_PP_SUBで数字を1個戻してもらって，timerという文字と結合，elapsed()を実行します．この間にコードを実行すれば，めでたくスコープに縛られず更に時間計測も出来るわけです．なお，入れ子はエラーになります．
…なんだか気持ち悪いですが，Boost.Preprocessor凄いですね．

凹みTips

C++、JavaScript、Unity、ガジェット等の Tips について雑多に書いています。

boost::timerを使ってブロック内を時間計測