1 /* This file is part of the Spring engine (GPL v2 or later), see LICENSE.html */
2
3 #include <assert.h>
4 #include <deque>
5
6 #include "ProfileDrawer.h"
7 #include "InputReceiver.h"
8 #include "Game/GlobalUnsynced.h"
9 #include "System/EventHandler.h"
10 #include "System/Rectangle.h"
11 #include "System/ThreadPool.h"
12 #include "System/TimeProfiler.h"
13 #include "Rendering/GL/myGL.h"
14 #include "Rendering/Fonts/glFont.h"
15 #include "Rendering/GlobalRendering.h"
16 #include "Rendering/GL/VertexArray.h"
17 #include "Sim/Misc/GlobalConstants.h" // for GAME_SPEED
18 #include "Sim/Misc/GlobalSynced.h"
19 #include "Sim/Path/IPathManager.h"
20 #include "Sim/Projectiles/ProjectileHandler.h"
21 #include "lib/lua/include/LuaUser.h"
22
23 ProfileDrawer* ProfileDrawer::instance = NULL;
24
25 static const float start_x = 0.6f;
26 static const float end_x = 0.99f;
27 static const float start_y = 0.95f;
28 static const float lineHeight = 0.017f;
29
30 static const auto DBG_FONT_FLAGS = (FONT_SCALE | FONT_NORM | FONT_SHADOW);
31
32 typedef std::pair<spring_time,spring_time> TimeSlice;
33 static std::deque<TimeSlice> vidFrames;
34 static std::deque<TimeSlice> simFrames;
35 static std::deque<TimeSlice> lgcFrames;
36 static std::deque<TimeSlice> swpFrames;
37 static std::deque<TimeSlice> uusFrames;
38
39
ProfileDrawer()40 ProfileDrawer::ProfileDrawer()
41 : CEventClient("[ProfileDrawer]", 199991, false)
42 {
43 autoLinkEvents = true;
44 RegisterLinkedEvents(this);
45 eventHandler.AddClient(this);
46 }
47
48
~ProfileDrawer()49 ProfileDrawer::~ProfileDrawer()
50 {
51 }
52
53
SetEnabled(bool enable)54 void ProfileDrawer::SetEnabled(bool enable)
55 {
56 if (enable) {
57 assert(instance == NULL);
58 instance = new ProfileDrawer();
59 // reset peak indicators each time the drawer is restarted
60 for (auto& p: profiler.profile)
61 p.second.peak = 0.0f;
62 } else {
63 ProfileDrawer* tmpInstance = instance;
64 instance = NULL;
65 delete tmpInstance;
66 }
67 }
68
69
IsEnabled()70 bool ProfileDrawer::IsEnabled()
71 {
72 return (instance != NULL);
73 }
74
75
76
DrawTimeSlice(std::deque<TimeSlice> & frames,const spring_time curTime,const spring_time maxHist,const float drawArea[4])77 static void DrawTimeSlice(std::deque<TimeSlice>& frames, const spring_time curTime, const spring_time maxHist, const float drawArea[4])
78 {
79 // remove old entries
80 while (!frames.empty() && (curTime - frames.front().second) > maxHist) {
81 frames.pop_front();
82 }
83
84 const float y1 = drawArea[1];
85 const float y2 = drawArea[3];
86
87 // render
88 CVertexArray* va = GetVertexArray();
89 va->Initialize();
90 for (TimeSlice& ts: frames) {
91 float x1 = (ts.first % maxHist).toSecsf() / maxHist.toSecsf();
92 float x2 = (ts.second % maxHist).toSecsf() / maxHist.toSecsf();
93 x2 = std::max(x1 + globalRendering->pixelX, x2);
94
95 x1 = drawArea[0] + x1 * (drawArea[2] - drawArea[0]);
96 x2 = drawArea[0] + x2 * (drawArea[2] - drawArea[0]);
97
98 va->AddVertex0(x1, y1, 0.0f);
99 va->AddVertex0(x1, y2, 0.0f);
100 va->AddVertex0(x2, y2, 0.0f);
101 va->AddVertex0(x2, y1, 0.0f);
102
103 const float mx1 = x1 + 3 * globalRendering->pixelX;
104 const float mx2 = x2 - 3 * globalRendering->pixelX;
105 if (mx1 < mx2) {
106 va->AddVertex0(mx1, y1 + 3 * globalRendering->pixelX, 0.0f);
107 va->AddVertex0(mx1, y2 - 3 * globalRendering->pixelX, 0.0f);
108 va->AddVertex0(mx2, y2 - 3 * globalRendering->pixelX, 0.0f);
109 va->AddVertex0(mx2, y1 + 3 * globalRendering->pixelX, 0.0f);
110 }
111 }
112
113 va->DrawArray0(GL_QUADS);
114 }
115
116
DrawThreadBarcode()117 static void DrawThreadBarcode()
118 {
119 const float maxHist_f = 4.0f;
120 const spring_time curTime = spring_now();
121 const spring_time maxHist = spring_secs(maxHist_f);
122 auto& coreProf = profiler.profileCore;
123 const auto numThreads = coreProf.size();
124
125 const float drawArea[4] = {0.01f, 0.30f, (start_x / 2), 0.35f};
126
127 // background
128 CVertexArray* va = GetVertexArray();
129 va->Initialize();
130 va->AddVertex0(drawArea[0] - 10 * globalRendering->pixelX, drawArea[1] - 10 * globalRendering->pixelY, 0.0f);
131 va->AddVertex0(drawArea[0] - 10 * globalRendering->pixelX, drawArea[3] + 10 * globalRendering->pixelY, 0.0f);
132 va->AddVertex0(drawArea[2] + 10 * globalRendering->pixelX, drawArea[3] + 10 * globalRendering->pixelY, 0.0f);
133 va->AddVertex0(drawArea[2] + 10 * globalRendering->pixelX, drawArea[1] - 10 * globalRendering->pixelY, 0.0f);
134 glColor4f(0.0f,0.0f,0.0f, 0.5f);
135 va->DrawArray0(GL_QUADS);
136
137 // title
138 font->glFormat(drawArea[0], drawArea[3], 0.7f, FONT_TOP | DBG_FONT_FLAGS, "ThreadPool (%.0fsec)", maxHist_f);
139
140 // bars
141 glColor4f(1.0f,0.0f,0.0f, 0.6f);
142 int i = 0;
143 for (auto& frames: coreProf) {
144 float drawArea2[4] = {drawArea[0], 0.f, drawArea[2], 0.f};
145 drawArea2[1] = drawArea[1] + ((drawArea[3] - drawArea[1]) / numThreads) * i++;
146 drawArea2[3] = drawArea[1] + ((drawArea[3] - drawArea[1]) / numThreads) * i - 4 * globalRendering->pixelY;
147 DrawTimeSlice(frames, curTime, maxHist, drawArea2);
148 }
149
150 // feeder
151 va = GetVertexArray();
152 va->Initialize();
153 const float r = (curTime % maxHist).toSecsf() / maxHist_f;
154 const float xf = drawArea[0] + r * (drawArea[2] - drawArea[0]);
155 va->AddVertex0(xf, drawArea[1], 0.0f);
156 va->AddVertex0(xf, drawArea[3], 0.0f);
157 va->AddVertex0(xf + 5 * globalRendering->pixelX, drawArea[3], 0.0f);
158 va->AddVertex0(xf + 5 * globalRendering->pixelX, drawArea[1], 0.0f);
159 glColor3f(1.0f,0.0f,0.0f);
160 va->DrawArray0(GL_QUADS);
161 }
162
163
DrawFrameBarcode()164 static void DrawFrameBarcode()
165 {
166 const float maxHist_f = 0.5f;
167 const spring_time curTime = spring_now();
168 const spring_time maxHist = spring_secs(maxHist_f);
169 float drawArea[4] = {0.01f, 0.2f, start_x - 0.05f, 0.25f};
170
171 // background
172 CVertexArray* va = GetVertexArray();
173 va->Initialize();
174 va->AddVertex0(drawArea[0] - 10 * globalRendering->pixelX, drawArea[1] - 10 * globalRendering->pixelY, 0.0f);
175 va->AddVertex0(drawArea[0] - 10 * globalRendering->pixelX, drawArea[3] + 20 * globalRendering->pixelY, 0.0f);
176 va->AddVertex0(drawArea[2] + 10 * globalRendering->pixelX, drawArea[3] + 20 * globalRendering->pixelY, 0.0f);
177 va->AddVertex0(drawArea[2] + 10 * globalRendering->pixelX, drawArea[1] - 10 * globalRendering->pixelY, 0.0f);
178 glColor4f(0.0f,0.0f,0.0f, 0.5f);
179 va->DrawArray0(GL_QUADS);
180
181 // title and legend
182 font->glFormat(drawArea[0], drawArea[3] + 10 * globalRendering->pixelY, 0.7f, FONT_TOP | DBG_FONT_FLAGS,
183 "Frame Grapher (%.2fsec)"
184 "\xff\xff\x80\xff GC"
185 "\xff\xff\xff\x01 Unsynced"
186 "\xff\x01\x01\xff Swap"
187 "\xff\x01\xff\x01 Video"
188 "\xff\xff\x01\x01 Sim"
189 , maxHist_f);
190
191 // gc frames
192 glColor4f(1.0f,0.5f,1.0f, 0.55f);
193 DrawTimeSlice(lgcFrames, curTime, maxHist, drawArea);
194
195 // updateunsynced frames
196 glColor4f(1.0f,1.0f,0.0f, 0.9f);
197 DrawTimeSlice(uusFrames, curTime, maxHist, drawArea);
198
199 // video swap frames
200 glColor4f(0.0f,0.0f,1.0f, 0.55f);
201 DrawTimeSlice(swpFrames, curTime, maxHist, drawArea);
202
203 // video frames
204 glColor4f(0.0f,1.0f,0.0f, 0.55f);
205 DrawTimeSlice(vidFrames, curTime, maxHist, drawArea);
206
207 // sim frames
208 glColor4f(1.0f,0.0f,0.0f, 0.55f);
209 DrawTimeSlice(simFrames, curTime, maxHist, drawArea);
210
211 // draw `feeder` indicating current time pos
212 va = GetVertexArray();
213 va->Initialize();
214 // draw feeder
215 const float r = (curTime % maxHist).toSecsf() / maxHist_f;
216 const float xf = drawArea[0] + r * (drawArea[2] - drawArea[0]);
217 va->AddVertex0(xf, drawArea[1], 0.0f);
218 va->AddVertex0(xf, drawArea[3], 0.0f);
219 va->AddVertex0(xf + 10 * globalRendering->pixelX, drawArea[3], 0.0f);
220 va->AddVertex0(xf + 10 * globalRendering->pixelX, drawArea[1], 0.0f);
221
222 // draw scale (horizontal bar that indicates 30FPS timing length)
223 const float xs1 = drawArea[2] - 1.f/(30.f*maxHist_f) * (drawArea[2] - drawArea[0]);
224 const float xs2 = drawArea[2] + 0.0f * (drawArea[2] - drawArea[0]);
225 va->AddVertex0(xs1, drawArea[3] + 2 * globalRendering->pixelY, 0.0f);
226 va->AddVertex0(xs1, drawArea[3] + 10 * globalRendering->pixelY, 0.0f);
227 va->AddVertex0(xs2, drawArea[3] + 10 * globalRendering->pixelY, 0.0f);
228 va->AddVertex0(xs2, drawArea[3] + 2 * globalRendering->pixelY, 0.0f);
229 glColor4f(1.0f,0.0f,0.0f, 1.0f);
230 va->DrawArray0(GL_QUADS);
231 }
232
233
DrawProfiler()234 static void DrawProfiler()
235 {
236 font->SetTextColor(1,1,1,1);
237
238 // draw the background of the window
239 {
240 CVertexArray* va = GetVertexArray();
241 va->Initialize();
242 va->AddVertex0(start_x, start_y + lineHeight + 0.005f, 0);
243 va->AddVertex0(end_x, start_y + lineHeight + 0.005f, 0);
244 va->AddVertex0(start_x, start_y - profiler.profile.size() * lineHeight - 0.01f, 0);
245 va->AddVertex0(end_x, start_y - profiler.profile.size() * lineHeight - 0.01f, 0);
246 glColor4f(0.0f, 0.0f, 0.5f, 0.5f);
247 va->DrawArray0(GL_TRIANGLE_STRIP);
248 }
249
250 const float textSize = 0.5f;
251
252 // table header
253 {
254 const float fStartY = start_y + 0.005f;
255 float fStartX = start_x + 0.005f + 0.015f + 0.005f;
256
257 // print total-time running since application start
258 fStartX += 0.04f;
259 font->glFormat(fStartX, fStartY, textSize, FONT_SHADOW | FONT_DESCENDER | FONT_SCALE | FONT_NORM | FONT_RIGHT, "totaltime");
260
261 // print percent of CPU time used within the last 500ms
262 fStartX += 0.06f;
263 font->glFormat(fStartX, fStartY, textSize, FONT_SHADOW | FONT_DESCENDER | FONT_SCALE | FONT_NORM | FONT_RIGHT, "cur-%%usage");
264 fStartX += 0.04f;
265 font->glFormat(fStartX, fStartY, textSize, FONT_SHADOW | FONT_DESCENDER | FONT_SCALE | FONT_NORM | FONT_RIGHT, "max-%%usage");
266 fStartX += 0.04f;
267 font->glFormat(fStartX, fStartY, textSize, FONT_SHADOW | FONT_DESCENDER | FONT_SCALE | FONT_NORM | FONT_RIGHT, "lag");
268
269 // print timer name
270 fStartX += 0.01f;
271 font->glFormat(fStartX, fStartY, textSize, FONT_SHADOW | FONT_DESCENDER | FONT_SCALE | FONT_NORM, "title");
272 }
273
274 // draw the textual info (total-time, short-time percentual time, timer-name)
275 int y = 1;
276 for (auto pi = profiler.profile.begin(); pi != profiler.profile.end(); ++pi, ++y) {
277 const auto& profileData = pi->second;
278
279 const float fStartY = start_y - y * lineHeight;
280 float fStartX = start_x + 0.005f + 0.015f + 0.005f;
281
282 // print total-time running since application start
283 fStartX += 0.04f;
284 font->glFormat(fStartX, fStartY, textSize, FONT_DESCENDER | FONT_SCALE | FONT_NORM | FONT_RIGHT, "%.2fs", profileData.total.toSecsf());
285
286 // print percent of CPU time used within the last 500ms
287 fStartX += 0.06f;
288 font->glFormat(fStartX, fStartY, textSize, FONT_DESCENDER | FONT_SCALE | FONT_NORM | FONT_RIGHT, "%.2f%%", profileData.percent * 100);
289 fStartX += 0.04f;
290 font->glFormat(fStartX, fStartY, textSize, FONT_DESCENDER | FONT_SCALE | FONT_NORM | FONT_RIGHT, "\xff\xff%c%c%.2f%%", profileData.newPeak?1:255, profileData.newPeak?1:255, profileData.peak * 100);
291 fStartX += 0.04f;
292 font->glFormat(fStartX, fStartY, textSize, FONT_DESCENDER | FONT_SCALE | FONT_NORM | FONT_RIGHT, "\xff\xff%c%c%.0fms", profileData.newLagPeak?1:255, profileData.newLagPeak?1:255, profileData.maxLag);
293
294 // print timer name
295 fStartX += 0.01f;
296 font->glFormat(fStartX, fStartY, textSize, FONT_DESCENDER | FONT_SCALE | FONT_NORM, pi->first);
297 }
298
299
300 // draw the Timer selection boxes
301 const float boxSize = lineHeight*0.9;
302 const float selOffset = boxSize*0.2;
303 glPushMatrix();
304 glTranslatef(start_x + 0.005f, start_y + boxSize, 0); // we are now at upper left of first box
305 CVertexArray* va = GetVertexArray();
306 CVertexArray* va2 = GetVertexArray();
307 va->Initialize();
308 va2->Initialize();
309 int i = 1;
310 for (auto pi = profiler.profile.begin(); pi != profiler.profile.end(); ++pi, ++i){
311 auto& fc = pi->second.color;
312 SColor c(fc[0], fc[1], fc[2]);
313 va->AddVertexC(float3(0, -i*lineHeight, 0), c); // upper left
314 va->AddVertexC(float3(0, -i*lineHeight-boxSize, 0), c); // lower left
315 va->AddVertexC(float3(boxSize, -i*lineHeight-boxSize, 0), c); // lower right
316 va->AddVertexC(float3(boxSize, -i*lineHeight, 0), c); // upper right
317
318 if (pi->second.showGraph) {
319 va2->AddVertex0(lineHeight+selOffset, -i*lineHeight-selOffset, 0); // upper left
320 va2->AddVertex0(lineHeight+selOffset, -i*lineHeight-boxSize+selOffset, 0); // lower left
321 va2->AddVertex0(lineHeight+boxSize-selOffset, -i*lineHeight-boxSize+selOffset, 0); // lower right
322 va2->AddVertex0(lineHeight+boxSize-selOffset, -i*lineHeight-selOffset, 0); // upper right
323 }
324 }
325 // draw the boxes
326 va->DrawArrayC(GL_QUADS);
327 // draw the 'graph view disabled' cross
328 glColor3f(1,0,0);
329 va2->DrawArray0(GL_QUADS);
330 glPopMatrix();
331
332 // draw the graph
333 glLineWidth(3.0f);
334 for (auto pi = profiler.profile.begin(); pi != profiler.profile.end(); ++pi) {
335 if (!pi->second.showGraph) {
336 continue;
337 }
338 CVertexArray* va = GetVertexArray();
339 va->Initialize();
340 const float steps_x = (end_x - start_x) / CTimeProfiler::TimeRecord::frames_size;
341 for (size_t a=0; a < CTimeProfiler::TimeRecord::frames_size; ++a) {
342 // profile runtime; eg 0.5f means: uses 50% of a CPU (during that frame)
343 // This may be more then 1.0f, in case an operation
344 // which ran over many frames, ended in this one.
345 const float p = pi->second.frames[a].toSecsf() * GAME_SPEED;
346 const float x = start_x + (a * steps_x);
347 const float y = 0.02f + (p * 0.96f);
348 va->AddVertex0(x, y, 0.0f);
349 }
350
351 glColorf3((float3)pi->second.color);
352 va->DrawArray0(GL_LINE_STRIP);
353 }
354 glLineWidth(1.0f);
355 }
356
357
DrawInfoText()358 static void DrawInfoText()
359 {
360 // background
361 CVertexArray* va = GetVertexArray();
362 va->Initialize();
363 va->AddVertex0(0.01f - 10 * globalRendering->pixelX, 0.02f - 10 * globalRendering->pixelY, 0.0f);
364 va->AddVertex0(0.01f - 10 * globalRendering->pixelX, 0.16f + 20 * globalRendering->pixelY, 0.0f);
365 va->AddVertex0(start_x - 0.05f + 10 * globalRendering->pixelX, 0.16f + 20 * globalRendering->pixelY, 0.0f);
366 va->AddVertex0(start_x - 0.05f + 10 * globalRendering->pixelX, 0.02f - 10 * globalRendering->pixelY, 0.0f);
367 glColor4f(0.0f,0.0f,0.0f, 0.5f);
368 va->DrawArray0(GL_QUADS);
369
370 //print some infos (fps,gameframe,particles)
371 font->SetTextColor(1,1,0.5f,0.8f);
372
373 font->glFormat(0.01f, 0.02f, 1.0f, DBG_FONT_FLAGS, "FPS: %0.1f SimFPS: %0.1f SimFrame: %d Speed: %2.2f (%2.2f) Particles: %d (%d)",
374 globalRendering->FPS, gu->simFPS, gs->frameNum, gs->speedFactor, gs->wantedSpeedFactor, projectileHandler->syncedProjectiles.size() + projectileHandler->unsyncedProjectiles.size(), projectileHandler->currentParticles);
375
376 // 16ms := 60fps := 30simFPS + 30drawFPS
377 font->glFormat(0.01f, 0.07f, 0.7f, DBG_FONT_FLAGS, "avgFrame: %s%2.1fms\b avgDrawFrame: %s%2.1fms\b avgSimFrame: %s%2.1fms\b",
378 (gu->avgFrameTime > 30) ? "\xff\xff\x01\x01" : "", gu->avgFrameTime,
379 (gu->avgDrawFrameTime > 16) ? "\xff\xff\x01\x01" : "", gu->avgDrawFrameTime,
380 (gu->avgSimFrameTime > 16) ? "\xff\xff\x01\x01" : "", gu->avgSimFrameTime
381 );
382
383 const int2 pfsUpdates = pathManager->GetNumQueuedUpdates();
384 const char* fmtString = "[%s-PFS] queued updates: %i %i";
385
386 switch (pathManager->GetPathFinderType()) {
387 case PFS_TYPE_DEFAULT: {
388 font->glFormat(0.01f, 0.12f, 0.7f, DBG_FONT_FLAGS, fmtString, "DEFAULT", pfsUpdates.x, pfsUpdates.y);
389 } break;
390 case PFS_TYPE_QTPFS: {
391 font->glFormat(0.01f, 0.12f, 0.7f, DBG_FONT_FLAGS, fmtString, "QT", pfsUpdates.x, pfsUpdates.y);
392 } break;
393 }
394
395 SLuaInfo luaInfo = {0, 0, 0, 0};
396 spring_lua_alloc_get_stats(&luaInfo);
397
398 font->glFormat(
399 0.01f, 0.15f, 0.7f, DBG_FONT_FLAGS,
400 "Lua-allocated memory: %.1fMB (%.5uK allocs : %.5u usecs : %.1u states)",
401 luaInfo.allocedBytes / 1024.0f / 1024.0f,
402 luaInfo.numLuaAllocs / 1000,
403 luaInfo.luaAllocTime,
404 luaInfo.numLuaStates
405 );
406 }
407
408
409
DrawScreen()410 void ProfileDrawer::DrawScreen()
411 {
412 SCOPED_TIMER("ProfileDrawer");
413
414 glMatrixMode(GL_MODELVIEW);
415 glPushMatrix();
416 glLoadIdentity();
417 glMatrixMode(GL_PROJECTION);
418 glPushMatrix();
419 glLoadIdentity();
420 gluOrtho2D(0,1,0,1);
421
422 glDisable(GL_TEXTURE_2D);
423 font->Begin();
424 font->SetTextColor(1,1,0.5f,0.8f);
425
426 DrawThreadBarcode();
427 DrawFrameBarcode();
428 DrawProfiler();
429 DrawInfoText();
430
431 font->End();
432 glColor4f(1.0f,1.0f,1.0f,1.0f);
433 glEnable(GL_TEXTURE_2D);
434 glMatrixMode(GL_PROJECTION);
435 glPopMatrix();
436 glMatrixMode(GL_MODELVIEW);
437 glPopMatrix();
438 }
439
MousePress(int x,int y,int button)440 bool ProfileDrawer::MousePress(int x, int y, int button)
441 {
442 if (!IsAbove(x, y))
443 return false;
444
445 const float my = CInputReceiver::MouseY(y);
446 const int selIndex = (int) ((start_y - my) / lineHeight);
447
448 // switch the selected Timers showGraph value
449 if ((selIndex >= 0) && (selIndex < profiler.profile.size())) {
450 auto pi = profiler.profile.begin();
451 std::advance(pi, selIndex);
452 pi->second.showGraph = !pi->second.showGraph;
453 return true;
454 }
455
456 return false;
457 }
458
IsAbove(int x,int y)459 bool ProfileDrawer::IsAbove(int x, int y)
460 {
461 const float mx = CInputReceiver::MouseX(x);
462 const float my = CInputReceiver::MouseY(y);
463
464 // check if a Timer selection box was hit
465 if (mx<start_x || mx>end_x || my<start_y - profiler.profile.size()*lineHeight || my>start_y) {
466 return false;
467 }
468
469 return true;
470 }
471
472
DbgTimingInfo(DbgTimingInfoType type,const spring_time start,const spring_time end)473 void ProfileDrawer::DbgTimingInfo(DbgTimingInfoType type, const spring_time start, const spring_time end)
474 {
475 if (!IsEnabled())
476 return;
477
478 switch (type) {
479 case TIMING_VIDEO: {
480 vidFrames.emplace_back(start, end);
481 } break;
482 case TIMING_SIM: {
483 simFrames.emplace_back(start, end);
484 } break;
485 case TIMING_GC: {
486 lgcFrames.emplace_back(start, end);
487 } break;
488 case TIMING_SWAP: {
489 swpFrames.emplace_back(start, end);
490 } break;
491 case TIMING_UNSYNCED: {
492 uusFrames.emplace_back(start, end);
493 } break;
494 }
495 }
496