呼出をトレースして実行時間を取る

Boost.ChronoでTrace - Faith and Brave - C++で遊ぼう
chronoがライブラリにまだ入っていないので導入はちょっと・・・
ということで作った。
車輪の再発明臭いけど気にしない。

elapsed_time.hpp

#pragma once

#include <algorithm>
#include <boost/current_function.hpp>
#include <boost/format.hpp>
#include <boost/function.hpp>
#include <boost/timer.hpp>
#include <pstade/napkin.hpp>

//definition
//ELAPSED_TIME_OUTPUT_TO_DEBUGGER
//ELAPSED_TIME_OUTPUT_TO_STDOUT	//as default

#if defined ELAPSED_TIME_OUTPUT_TO_DEBUGGER
#include <pstade/napkin/dout.hpp>
#else
#include <iostream>
#endif

namespace hwm
{
namespace elapsed_time_detail
{
	struct elapsed_time
	{
		typedef
			elapsed_time
		this_type;

		typedef 
			boost::function<
				void(this_type const&)
			>
		reporter_t;

		elapsed_time	(const char* file, const size_t line, const char* func, reporter_t r) 
			:	sum_	(0)
			,	min_	(0)
			,	max_	(0)
			,	count_	(0)
			,	file_	(file)
			,	line_	(line)
			,	func_	(func)
			,	r_		(r)
		{}

		~elapsed_time	() { try { r_(*this); } catch(...){} }

		void add(double elapse) {
			max_ = (std::max)(elapse, max_);
			min_ = (count_) ? (std::min)(elapse, min_) : elapse;
			sum_ += elapse;
			++count_;
		}

		const char*
				get_func	() const { return func_; }
		const char*
				get_file	() const { return file_; }
		size_t	get_line	() const { return line_; }
		double	get_min		() const { return min_; }
		double	get_max		() const { return max_; }
		double	get_total	() const { return sum_; }
		double	get_average	() const { return (count_) ? sum_ / count_ : 0; }
		size_t	get_count	() const { return count_; }
		void	set_reporter(reporter_t& r) { r_ = r; }

		void	clear		()
		{
			sum_ = min_ = max_ = count_ = 0;
		}

		double				sum_;
		double				min_;
		double				max_;
		size_t				count_;
		const char*			file_;
		const int			line_;
		const char*			func_;
		reporter_t			r_;
	};

	template<typename T>
	struct ScopedAdd
	{
		T&				t_;
		boost::timer	timer_;
		ScopedAdd		(T& t) : t_(t) {}
		~ScopedAdd		() { t_.add(timer_.elapsed()); }
	};

	struct default_reporter
	{
		template<typename T>
		void operator()(T const &t) const
		{
			pstade::napkin::ostream os;
#if defined ELAPSED_TIME_OUTPUT_TO_DEBUGGER
			os.reset(pstade::napkin::dout);
#else
			os.reset(std::cout);
#endif
			os <<
				boost::format(
					"%s(%d)\n"
					"\tfunc    : %s\n"
					"\taverage : %10.8f秒\n"
					"\tmin     : %10.8f秒\n"
					"\tmax     : %10.8f秒\n"
					"\ttotal   : %10.8f秒(%d回の呼び出し)\n")
					%	t.get_file()
					%	t.get_line()
					%	t.get_func()
					%	t.get_average()
					%	t.get_min()
					%	t.get_max()
					%	t.get_total()
					%	t.get_count();
		}
	};

}	//elapsed_time_detail
}	//hwm

#define HWM_ELAPSED_TIME()\
	static hwm::elapsed_time_detail::elapsed_time\
		BOOST_PP_CAT(hwm_elapsed_time_, __LINE__) (\
			__FILE__,\
			__LINE__,\
			BOOST_CURRENT_FUNCTION,\
			hwm::elapsed_time_detail::default_reporter()\
		);\
		hwm::elapsed_time_detail::ScopedAdd<\
			 hwm::elapsed_time_detail::elapsed_time	\
		>\
		BOOST_PP_CAT(hwm_elapsed_time_scoped_add, __LINE__)\
			(BOOST_PP_CAT(hwm_elapsed_time_, __LINE__));

test.cpp

#include <iostream>

//output result to debug window
//#define ELAPSED_TIME_OUTPUT_TO_DEBUGGER
#include "elapsed_time.hpp"

class A
{
public:
	A() {
		HWM_ELAPSED_TIME();
	}
};

void func()
{
	HWM_ELAPSED_TIME();
	for(int i = 0; i < 1000; ++i) {
		HWM_ELAPSED_TIME();
		A a;
		HWM_ELAPSED_TIME();
		A aa;
		{
			HWM_ELAPSED_TIME();
			A aaa;
		}
	}
}

int main()
{
	HWM_ELAPSED_TIME();
	for(int i = 0; i < 1000;++i) {
		func();
	}
}

C:\vc\test\elapsed_time_test>test
test.cpp(24)
        func    : void __cdecl func(void)
        average : 0.00000017秒
        min     : 0.00000000秒
        max     : 0.01600000秒
        total   : 0.17400000秒(1000000回の呼び出し)
test.cpp(21)
        func    : void __cdecl func(void)
        average : 0.00000041秒
        min     : 0.00000000秒
        max     : 0.01600000秒
        total   : 0.40700000秒(1000000回の呼び出し)
test.cpp(11)
        func    : __thiscall A::A(void)
        average : 0.00000005秒
        min     : 0.00000000秒
        max     : 0.01600000秒
        total   : 0.15500000秒(3000000回の呼び出し)
test.cpp(19)
        func    : void __cdecl func(void)
        average : 0.00000063秒
        min     : 0.00000000秒
        max     : 0.01600000秒
        total   : 0.62500000秒(1000000回の呼び出し)
test.cpp(17)
        func    : void __cdecl func(void)
        average : 0.00073400秒
        min     : 0.00000000秒
        max     : 0.01600000秒
        total   : 0.73400000秒(1000回の呼び出し)
test.cpp(32)
        func    : int __cdecl main(void)
        average : 0.73400000秒
        min     : 0.73400000秒
        max     : 0.73400000秒
        total   : 0.73400000秒(1回の呼び出し)

msvc9.0, gcc4.5.0, boost1.42.0, pstade1.04.3で確認。