1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
|
// TimeProfiler.cpp: implementation of the CTimeProfiler class.
//
//////////////////////////////////////////////////////////////////////
#include "TimeProfiler.h"
#include <SDL_timer.h>
#include <cstring>
#include "mmgr.h"
#include "lib/gml/gml.h"
#include "LogOutput.h"
#include "UnsyncedRNG.h"
BasicTimer::BasicTimer(const char* const myname) : name(myname), starttime(SDL_GetTicks())
{
}
ScopedTimer::ScopedTimer(const char* const myname) : BasicTimer(myname)
{
}
ScopedTimer::~ScopedTimer()
{
const unsigned stoptime = SDL_GetTicks();
profiler.AddTime(name, stoptime - starttime);
}
ScopedOnceTimer::ScopedOnceTimer(const char* const myname) : BasicTimer(myname)
{
}
ScopedOnceTimer::ScopedOnceTimer(const std::string& myname): BasicTimer(myname.c_str())
{
}
ScopedOnceTimer::~ScopedOnceTimer()
{
const unsigned stoptime = SDL_GetTicks();
LogObject() << name << ": " << stoptime - starttime << " ms";
}
//////////////////////////////////////////////////////////////////////
// Construction/Destruction
//////////////////////////////////////////////////////////////////////
CTimeProfiler profiler;
CTimeProfiler::CTimeProfiler()
{
currentPosition = 0;
lastBigUpdate = SDL_GetTicks();
}
CTimeProfiler::~CTimeProfiler()
{
}
void CTimeProfiler::Update()
{
GML_STDMUTEX_LOCK_NOPROF(time); // Update
++currentPosition;
currentPosition &= TimeRecord::frames_size-1;
std::map<std::string,TimeRecord>::iterator pi;
for (pi = profile.begin(); pi != profile.end(); ++pi)
{
pi->second.frames[currentPosition]=0;
}
const unsigned curTime = SDL_GetTicks();
const unsigned timeDiff = curTime - lastBigUpdate;
if (timeDiff > 500) // twice every second
{
for (std::map<std::string,TimeRecord>::iterator pi = profile.begin(); pi != profile.end(); ++pi)
{
pi->second.percent = ((float)pi->second.current) / ((float)timeDiff);
pi->second.current=0;
}
lastBigUpdate = curTime;
}
}
float CTimeProfiler::GetPercent(const char *name)
{
GML_STDMUTEX_LOCK_NOPROF(time); // GetTimePercent
return profile[name].percent;
}
void CTimeProfiler::AddTime(const std::string& name, unsigned time)
{
GML_STDMUTEX_LOCK_NOPROF(time); // AddTime
std::map<std::string, TimeRecord>::iterator pi;
if ( (pi = profile.find(name)) != profile.end() ) {
// profile already exists
pi->second.total+=time;
pi->second.current+=time;
pi->second.frames[currentPosition]+=time;
} else {
// create a new profile
profile[name].total=time;
profile[name].current=time;
profile[name].percent=0;
memset(profile[name].frames, 0, TimeRecord::frames_size*sizeof(unsigned));
static UnsyncedRNG rand;
rand.Seed(SDL_GetTicks());
profile[name].color.x = rand.RandFloat();
profile[name].color.y = rand.RandFloat();
profile[name].color.z = rand.RandFloat();
profile[name].showGraph=true;
}
}
void CTimeProfiler::PrintProfilingInfo() const
{
logOutput.Print("%35s|%18s|%s",
"Part",
"Total Time",
"Time of the last 0.5s");
std::map<std::string, CTimeProfiler::TimeRecord>::const_iterator pi;
for (pi = profile.begin(); pi != profile.end(); ++pi) {
#if GML_MUTEX_PROFILER
if ((pi->first.size() < 5) || pi->first.substr(pi->first.size()-5,5).compare("Mutex")!=0) {
continue;
}
#endif // GML_MUTEX_PROFILER
logOutput.Print("%35s %16.2fs %5.2f%%",
pi->first.c_str(),
((float)pi->second.total) / 1000.f,
pi->second.percent * 100);
}
}
|
