やあ子供たち。寒いけど春はもうすぐそこまで来ているぞ。でも今はスノボシーズン真っ只中なので、若者はプログラミングなんかしてないでスノボに行った方がいいぞ、雪山にな。
さて今日は簡単なプロファイリング用便利クラスを紹介するぞ。その名もSimpleProfilerだ。ちょっとだけ長めになってしまったがまずは以下がコードだよ。有用だと思った人は自由に使ってみてくれ。
#define _CRT_SECURE_NO_WARNINGS
#include <Windows.h>
#include <process.h>
#include <time.h>
#include <iostream>
#include <sstream>
#include <vector>
#include <functional>
#include <algorithm>
#include <stack>
using namespace std;
class SimpleProfiler
{
class MarkBase
{
public:
MarkBase(const string& str, const clock_t cl)
:_title(str), _clock(cl) {}
virtual void dummyFunc() {}
string _title;
clock_t _clock;
};
class Scope : public MarkBase
{
public:
Scope(const string& str, const clock_t cl, const bool is_pop=false)
:MarkBase(str, cl),_is_pop(is_pop){}
bool _is_pop;
float _result;
};
public:
SimpleProfiler(void) {
_tak = [](clock_t a, clock_t b) ->float
{return (b - a) / (float)CLOCKS_PER_SEC; };
}
void MarkHere(const string& str) {
_mark_vec.push_back(new MarkBase(str, clock()));
return;
}
string Dump(void)
{
ostringstream oss;
oss << "[SimpleProfiler] ****** Dump Starts ******" << endl;
for (int i = 0; i < _mark_vec.size(); ++i)
{
auto im = _mark_vec[i];
if (auto p = dynamic_cast<Scope*>(im))
{
if( !p->_is_pop)
oss << "[SimpleProfiler] *-->>--" << p->_title <<":"<<p->_result << "(s)" << endl;
else
oss << "[SimpleProfiler] *--<<--" << endl;
}
else
{
if (i == _mark_vec.size() - 1)
oss << "[SimpleProfiler] * " << im->_title << endl;
else
oss << "[SimpleProfiler] * " << im->_title << "[" << i << "-" << i + 1 << "]:"
<< _tak(im->_clock, _mark_vec[i + 1]->_clock) << "(s)" << endl;
}
}
oss << "[SimpleProfiler] ******* Dump Ends *******" << endl;
return oss.str();
}
void PushScope(const string& str)
{
_scope_stack.push(_mark_vec.size());
_mark_vec.push_back(new Scope(str, clock()));
}
void PopScope(void)
{
int id = _scope_stack.top();
_scope_stack.pop();
auto pushed = dynamic_cast< Scope*>(_mark_vec[id]);
pushed->_result = _tak(pushed->_clock, clock());
_mark_vec.push_back(new Scope("--", clock(), true));
}
stack< int > _scope_stack;
vector< MarkBase* > _mark_vec;
function< float(clock_t a, clock_t b) > _tak;
};
さて、使い方は以下のようになるよ。今回はちょっとした計算課題をシングルスレッドで計算させた場合と、マルチスレッドで計算させた場合との計算時間の測定を題材にしてみたよ。
unsigned int __stdcall func(void* pv)
{
float sum = 0;
for (int i = 0; i < 300000000; ++i)
{
sum += 1 / (float)(i + 1);
}
cout << sum << endl;
return 0;
}
int main(int argc, char* argv[])
{
SimpleProfiler sp;
const int num_thread = 4;
sp.PushScope("Today's Test");
sp.PushScope("single thread test");
{
for (int i = 0; i < num_thread; ++i)
{
char s[234];
sprintf(s, " %d th test.", i);
sp.MarkHere(s);
func(nullptr);
}
}
sp.PopScope();
sp.PushScope("multi thread test");
{
vector< HANDLE > handles(num_thread);
sp.MarkHere(" _beginthreadex call");
for (auto& ih : handles)
{
DWORD dw;
ih = (HANDLE)_beginthreadex(0, 0, func, nullptr, 0, (unsigned int*)&dw);
}
sp.MarkHere(" ResumeThread() call");
for_each(handles.begin(), handles.end(), [](HANDLE& h) { ResumeThread(h); });
sp.MarkHere(" WaitForMultipleObjects() call");
WaitForMultipleObjects(num_thread, handles.data(), TRUE, INFINITE);
sp.MarkHere(" CloseHandle() call");
for_each(handles.begin(), handles.end(), [](HANDLE& h) { CloseHandle(h); });
}
sp.PopScope();
sp.PopScope();
cout << sp.Dump();
cout << "its done" << endl;
getchar();
return 0;
}
SimpleProfilerの使用可能なメソッドはとても簡単で、４つだけだ。
- SimpleProfiler(コンストラクタ）
- MarkHere 時間を計測したい点で呼び出します。
- PushScope/PopScope 時間を計測したい、特定の区間（スコープ）を定義、スコープは複数定義可能で互いに入れ子構造にすることも出来る。
- Dump 各マーク間、およびスコープ内でかかった時間の計測結果を時系列に表示。
15.4037
15.4037
15.4037
15.4037
15.4037
15.4037
15.4037
[SimpleProfiler] ****** Dump Starts ******
[SimpleProfiler] *-->>--Today's Test:12.369(s)
[SimpleProfiler] *-->>--single thread test:10.651(s)
[SimpleProfiler] * 0 th test.[2-3]:2.566(s)
[SimpleProfiler] * 1 th test.[3-4]:2.696(s)
[SimpleProfiler] * 2 th test.[4-5]:2.694(s)
[SimpleProfiler] * 3 th test.[5-6]:2.695(s)
[SimpleProfiler] *--<<--
[SimpleProfiler] *-->>--multi thread test:1.718(s)
[SimpleProfiler] * _beginthreadex call[8-9]:0(s)
[SimpleProfiler] * ResumeThread() call[9-10]:0(s)
[SimpleProfiler] * WaitForMultipleObjects() call[10-11]:1.718(s)
[SimpleProfiler] * CloseHandle() call[11-12]:0(s)
[SimpleProfiler] *--<<--
[SimpleProfiler] *--<<--
[SimpleProfiler] ******* Dump Ends *******
its done
出力結果は上述のようになるよ。マーク間の計測時間と、スコープ内処理でかかった総合時間がそれぞれ見やすく表示されているのがおわかりいただけると思う。よく、特定の処理の時間計測で、自分でclock()呼んで、変数に入れて、表示して、とかを一切やらなくてよく、かつ解り易く状況を手っ取り早く知ることができる、これがSimpleProfilerの特徴だよ。
それでは今日はこの辺で。寝ろ！
