Coverage Report

Created: 2026-05-30 06:50

next uncovered line (L), next uncovered region (R), next uncovered branch (B)
/src/ogre/OgreMain/src/OgreProfiler.cpp
Line
Count
Source
1
/*
2
-----------------------------------------------------------------------------
3
This source file is part of OGRE
4
    (Object-oriented Graphics Rendering Engine)
5
For the latest info, see http://www.ogre3d.org/
6
7
Copyright (c) 2000-2014 Torus Knot Software Ltd
8
9
Permission is hereby granted, free of charge, to any person obtaining a copy
10
of this software and associated documentation files (the "Software"), to deal
11
in the Software without restriction, including without limitation the rights
12
to use, copy, modify, merge, publish, distribute, sublicense, and/or sell
13
copies of the Software, and to permit persons to whom the Software is
14
furnished to do so, subject to the following conditions:
15
16
The above copyright notice and this permission notice shall be included in
17
all copies or substantial portions of the Software.
18
19
THE SOFTWARE IS PROVIDED "AS IS", WITHOUT WARRANTY OF ANY KIND, EXPRESS OR
20
IMPLIED, INCLUDING BUT NOT LIMITED TO THE WARRANTIES OF MERCHANTABILITY,
21
FITNESS FOR A PARTICULAR PURPOSE AND NONINFRINGEMENT. IN NO EVENT SHALL THE
22
AUTHORS OR COPYRIGHT HOLDERS BE LIABLE FOR ANY CLAIM, DAMAGES OR OTHER
23
LIABILITY, WHETHER IN AN ACTION OF CONTRACT, TORT OR OTHERWISE, ARISING FROM,
24
OUT OF OR IN CONNECTION WITH THE SOFTWARE OR THE USE OR OTHER DEALINGS IN
25
THE SOFTWARE.
26
-----------------------------------------------------------------------------
27
*/
28
#include "OgreStableHeaders.h"
29
/*
30
31
    Although the code is original, many of the ideas for the profiler were borrowed from 
32
"Real-Time In-Game Profiling" by Steve Rabin which can be found in Game Programming
33
Gems 1.
34
35
    This code can easily be adapted to your own non-Ogre project. The only code that is 
36
Ogre-dependent is in the visualization/logging routines and the use of the Timer class.
37
38
    Enjoy!
39
40
*/
41
42
#include "OgreTimer.h"
43
44
#ifdef USE_REMOTERY
45
#include "Remotery.h"
46
static Remotery* rmt;
47
#endif
48
49
namespace Ogre {
50
    //-----------------------------------------------------------------------
51
    // PROFILE DEFINITIONS
52
    //-----------------------------------------------------------------------
53
    template<> Profiler* Singleton<Profiler>::msSingleton = 0;
54
    Profiler* Profiler::getSingletonPtr(void)
55
0
    {
56
0
        return msSingleton;
57
0
    }
58
    Profiler& Profiler::getSingleton(void)
59
0
    {  
60
0
        assert( msSingleton );  return ( *msSingleton );  
61
0
    }
62
63
    //-----------------------------------------------------------------------
64
    // PROFILER DEFINITIONS
65
    //-----------------------------------------------------------------------
66
    Profiler::Profiler() 
67
0
        : mCurrent(&mRoot)
68
0
        , mLast(NULL)
69
0
        , mRoot()
70
0
        , mInitialized(false)
71
0
        , mUpdateDisplayFrequency(10)
72
0
        , mCurrentFrame(0)
73
0
        , mTimer(0)
74
0
        , mTotalFrameTime(0)
75
0
        , mEnabled(false)
76
0
        , mNewEnableState(false)
77
0
        , mProfileMask(0xFFFFFFFF)
78
0
        , mMaxTotalFrameTime(0)
79
0
        , mAverageFrameTime(0)
80
0
        , mResetExtents(false)
81
0
    {
82
0
        mRoot.hierarchicalLvl = 0 - 1;
83
84
#ifdef USE_REMOTERY
85
        rmt_Settings()->reuse_open_port = true;
86
        if(auto error = rmt_CreateGlobalInstance(&rmt))
87
        {
88
            LogManager::getSingleton().logError("Could not launch Remotery - RMT_ERROR " + std::to_string(error));
89
            return;
90
        }
91
        rmt_SetCurrentThreadName("Ogre Main");
92
#endif
93
0
    }
94
    //-----------------------------------------------------------------------
95
    ProfileInstance::ProfileInstance(void)
96
0
        : parent(NULL)
97
0
        , frameNumber(0)
98
0
        , accum(0)
99
0
        , hierarchicalLvl(0)
100
0
    {
101
0
        history.numCallsThisFrame = 0;
102
0
        history.totalTimePercent = 0;
103
0
        history.totalTimeMillisecs = 0;
104
0
        history.totalCalls = 0;
105
0
        history.maxTimePercent = 0;
106
0
        history.maxTimeMillisecs = 0;
107
0
        history.minTimePercent = 1;
108
0
        history.minTimeMillisecs = 100000;
109
0
        history.currentTimePercent = 0;
110
0
        history.currentTimeMillisecs = 0;
111
112
0
        frame.frameTime = 0;
113
0
        frame.calls = 0;
114
0
    }
115
    ProfileInstance::~ProfileInstance(void)
116
0
    {                                        
117
0
        for(auto & it : children)
118
0
        {
119
0
            ProfileInstance* instance = it.second;
120
0
            OGRE_DELETE instance;
121
0
        }
122
0
        children.clear();
123
0
    }
124
    //-----------------------------------------------------------------------
125
    Profiler::~Profiler()
126
0
    {
127
#ifdef USE_REMOTERY
128
        rmt_DestroyGlobalInstance(rmt);
129
#else
130
0
        if (!mRoot.children.empty()) 
131
0
        {
132
            // log the results of our profiling before we quit
133
0
            logResults();
134
0
        }
135
136
        // clear all our lists
137
0
        mDisabledProfiles.clear();
138
0
#endif
139
0
    }
140
    //-----------------------------------------------------------------------
141
    void Profiler::setTimer(Timer* t)
142
0
    {
143
0
        mTimer = t;
144
0
    }
145
    //-----------------------------------------------------------------------
146
    Timer* Profiler::getTimer()
147
0
    {
148
0
        assert(mTimer && "Timer not set!");
149
0
        return mTimer;
150
0
    }
151
    //-----------------------------------------------------------------------
152
    void Profiler::setEnabled(bool enabled) 
153
0
    {
154
0
        if (!mInitialized && enabled) 
155
0
        {
156
0
            for(auto & l : mListeners)
157
0
                l->initializeSession();
158
159
0
            mInitialized = true;
160
0
        }
161
0
        else if (mInitialized && !enabled)
162
0
        {
163
0
            for(auto & l : mListeners)
164
0
                l->finializeSession();
165
166
0
            mInitialized = false;
167
0
        }
168
        // We store this enable/disable request until the frame ends
169
        // (don't want to screw up any open profiles!)
170
0
        mNewEnableState = enabled;
171
0
    }
172
    //-----------------------------------------------------------------------
173
    bool Profiler::getEnabled() const
174
0
    {
175
0
        return mEnabled;
176
0
    }
177
    //-----------------------------------------------------------------------
178
    void Profiler::changeEnableState() 
179
0
    {
180
0
        for(auto & l : mListeners)
181
0
            l->changeEnableState(mNewEnableState);
182
183
0
        mEnabled = mNewEnableState;
184
0
    }
185
    //-----------------------------------------------------------------------
186
    void Profiler::disableProfile(const String& profileName)
187
0
    {
188
        // even if we are in the middle of this profile, endProfile() will still end it.
189
0
        mDisabledProfiles.insert(profileName);
190
0
    }
191
    //-----------------------------------------------------------------------
192
    void Profiler::enableProfile(const String& profileName) 
193
0
    {
194
0
        mDisabledProfiles.erase(profileName);
195
0
    }
196
    //-----------------------------------------------------------------------
197
    void Profiler::beginProfile(const String& profileName, uint32 groupID) 
198
0
    {
199
#ifdef USE_REMOTERY
200
        // mask groups
201
        if ((groupID & mProfileMask) == 0)
202
            return;
203
204
        rmt_BeginCPUSampleDynamic(profileName.c_str(), RMTSF_Aggregate);
205
#else
206
        // if the profiler is enabled
207
0
        if (!mEnabled)
208
0
            return;
209
210
        // mask groups
211
0
        if ((groupID & mProfileMask) == 0)
212
0
            return;
213
214
        // empty string is reserved for the root
215
        // not really fatal anymore, however one shouldn't name one's profile as an empty string anyway.
216
0
        assert ((profileName != "") && ("Profile name can't be an empty string"));
217
218
        // we only process this profile if isn't disabled
219
0
        if (mDisabledProfiles.find(profileName) != mDisabledProfiles.end())
220
0
            return;
221
222
        // regardless of whether or not we are enabled, we need the application's root profile (ie the first profile started each frame)
223
        // we need this so bogus profiles don't show up when users enable profiling mid frame
224
        // so we check
225
226
        // this would be an internal error.
227
0
        assert (mCurrent);
228
229
        // need a timer to profile!
230
0
        assert (mTimer && "Timer not set!");
231
232
0
        ProfileInstance*& instance = mCurrent->children[profileName];
233
0
        if(instance)
234
0
        {   // found existing child.
235
236
            // Sanity check.
237
0
            assert(instance->name == profileName);
238
239
0
            if(instance->frameNumber != mCurrentFrame)
240
0
            {   // new frame, reset stats
241
0
                instance->frame.calls = 0;
242
0
                instance->frame.frameTime = 0;
243
0
                instance->frameNumber = mCurrentFrame;
244
0
            }
245
0
        }
246
0
        else
247
0
        {   // new child!
248
0
            instance = OGRE_NEW ProfileInstance();
249
0
            instance->name = profileName;
250
0
            instance->parent = mCurrent;
251
0
            instance->hierarchicalLvl = mCurrent->hierarchicalLvl + 1;
252
0
        }
253
254
0
        instance->frameNumber = mCurrentFrame;
255
256
0
        mCurrent = instance;
257
258
        // we do this at the very end of the function to get the most
259
        // accurate timing results
260
0
        mCurrent->currTime = mTimer->getMicroseconds();
261
0
#endif
262
0
    }
263
    //-----------------------------------------------------------------------
264
    void Profiler::endProfile(const String& profileName, uint32 groupID) 
265
0
    {
266
#ifdef USE_REMOTERY
267
        // mask groups
268
        if ((groupID & mProfileMask) == 0)
269
            return;
270
271
        rmt_EndCPUSample();
272
#else
273
0
        if(!mEnabled) 
274
0
        {
275
            // if the profiler received a request to be enabled or disabled
276
0
            if(mNewEnableState != mEnabled) 
277
0
            {   // note mNewEnableState == true to reach this.
278
0
                changeEnableState();
279
280
                // NOTE we will be in an 'error' state until the next begin. ie endProfile will likely get invoked using a profileName that was never started.
281
                // even then, we can't be sure that the next beginProfile will be the true start of a new frame
282
0
            }
283
284
0
            return;
285
0
        }
286
0
        else
287
0
        {
288
0
            if(mNewEnableState != mEnabled) 
289
0
            {   // note mNewEnableState == false to reach this.
290
0
                changeEnableState();
291
292
                // unwind the hierarchy, should be easy enough
293
0
                mCurrent = &mRoot;
294
0
                mLast = NULL;
295
0
            }
296
297
0
            if(&mRoot == mCurrent && mLast)
298
0
            {   // profiler was enabled this frame, but the first subsequent beginProfile was NOT the beinging of a new frame as we had hoped.
299
                // we have bogus ProfileInstance in our hierarchy, we will need to remove it, then update the overlays so as not to confuse ze user
300
301
0
                for(auto& e : mRoot.children)
302
0
                {
303
0
                    OGRE_DELETE e.second;
304
0
                }
305
0
                mRoot.children.clear();
306
307
0
                mLast = NULL;
308
309
0
                processFrameStats();
310
0
                displayResults();
311
0
            }
312
0
        }
313
314
0
        if(&mRoot == mCurrent)
315
0
            return;
316
317
        // mask groups
318
0
        if ((groupID & mProfileMask) == 0)
319
0
            return;
320
321
        // need a timer to profile!
322
0
        assert (mTimer && "Timer not set!");
323
324
        // get the end time of this profile
325
        // we do this as close the beginning of this function as possible
326
        // to get more accurate timing results
327
0
        const ulong endTime = mTimer->getMicroseconds();
328
329
        // empty string is reserved for designating an empty parent
330
0
        assert ((profileName != "") && ("Profile name can't be an empty string"));
331
332
        // we only process this profile if isn't disabled
333
        // we check the current instance name against the provided profileName as a guard against disabling a profile name /after/ said profile began
334
0
        if(mCurrent->name != profileName && mDisabledProfiles.find(profileName) != mDisabledProfiles.end()) 
335
0
            return;
336
337
        // calculate the elapsed time of this profile
338
0
        const ulong timeElapsed = endTime - mCurrent->currTime;
339
340
        // update parent's accumulator if it isn't the root
341
0
        if (&mRoot != mCurrent->parent) 
342
0
        {
343
            // add this profile's time to the parent's accumlator
344
0
            mCurrent->parent->accum += timeElapsed;
345
0
        }
346
347
0
        mCurrent->frame.frameTime += timeElapsed;
348
0
        ++mCurrent->frame.calls;
349
350
0
        mLast = mCurrent;
351
0
        mCurrent = mCurrent->parent;
352
353
0
        if (&mRoot == mCurrent) 
354
0
        {
355
            // the stack is empty and all the profiles have been completed
356
            // we have reached the end of the frame so process the frame statistics
357
358
            // we know that the time elapsed of the main loop is the total time the frame took
359
0
            mTotalFrameTime = timeElapsed;
360
361
0
            if(timeElapsed > mMaxTotalFrameTime)
362
0
                mMaxTotalFrameTime = timeElapsed;
363
364
            // we got all the information we need, so process the profiles
365
            // for this frame
366
0
            processFrameStats();
367
368
            // we display everything to the screen
369
0
            displayResults();
370
0
        }
371
0
#endif
372
0
    }
373
    //-----------------------------------------------------------------------
374
    void Profiler::processFrameStats(ProfileInstance* instance, Real& maxFrameTime)
375
0
    {
376
        // calculate what percentage of frame time this profile took
377
0
        const Real framePercentage = (Real) instance->frame.frameTime / (Real) mTotalFrameTime;
378
379
0
        const Real frameTimeMillisecs = (Real) instance->frame.frameTime / 1000.0f;
380
381
        // update the profile stats
382
0
        instance->history.currentTimePercent = framePercentage;
383
0
        instance->history.currentTimeMillisecs = frameTimeMillisecs;
384
0
        if(mResetExtents)
385
0
        {
386
0
            instance->history.totalTimePercent = framePercentage;
387
0
            instance->history.totalTimeMillisecs = frameTimeMillisecs;
388
0
            instance->history.totalCalls = 1;
389
0
        }
390
0
        else
391
0
        {
392
0
            instance->history.totalTimePercent += framePercentage;
393
0
            instance->history.totalTimeMillisecs += frameTimeMillisecs;
394
0
            instance->history.totalCalls++;
395
0
        }
396
0
        instance->history.numCallsThisFrame = instance->frame.calls;
397
398
        // if we find a new minimum for this profile, update it
399
0
        if (frameTimeMillisecs < instance->history.minTimeMillisecs || mResetExtents)
400
0
        {
401
0
            instance->history.minTimePercent = framePercentage;
402
0
            instance->history.minTimeMillisecs = frameTimeMillisecs;
403
0
        }
404
405
        // if we find a new maximum for this profile, update it
406
0
        if (frameTimeMillisecs > instance->history.maxTimeMillisecs || mResetExtents)
407
0
        {
408
0
            instance->history.maxTimePercent = framePercentage;
409
0
            instance->history.maxTimeMillisecs = frameTimeMillisecs;
410
0
        }
411
412
0
        if (instance->frame.frameTime > maxFrameTime)
413
0
            maxFrameTime = (Real)instance->frame.frameTime;
414
415
0
        for (auto& i : instance->children)
416
0
        {
417
0
            ProfileInstance* child = i.second;
418
419
            // we set the number of times each profile was called per frame to 0
420
            // because not all profiles are called every frame
421
0
            child->history.numCallsThisFrame = 0;
422
423
0
            if(child->frame.calls > 0)
424
0
            {
425
0
                processFrameStats(child, maxFrameTime);
426
0
            }
427
0
        }
428
0
    }
429
    //-----------------------------------------------------------------------
430
    void Profiler::processFrameStats(void) 
431
0
    {
432
0
        Real maxFrameTime = 0;
433
434
0
        for (auto& i : mRoot.children)
435
0
        {
436
0
            ProfileInstance* child = i.second;
437
438
            // we set the number of times each profile was called per frame to 0
439
            // because not all profiles are called every frame
440
0
            child->history.numCallsThisFrame = 0;
441
442
0
            if(child->frame.calls > 0)
443
0
            {
444
0
                processFrameStats(child, maxFrameTime);
445
0
            }
446
0
        }
447
448
        // Calculate whether the extents are now so out of date they need regenerating
449
0
        if (mCurrentFrame == 0)
450
0
            mAverageFrameTime = maxFrameTime;
451
0
        else
452
0
            mAverageFrameTime = (mAverageFrameTime + maxFrameTime) * 0.5f;
453
454
0
        if ((Real)mMaxTotalFrameTime > mAverageFrameTime * 4)
455
0
        {
456
0
            mResetExtents = true;
457
0
            mMaxTotalFrameTime = (ulong)mAverageFrameTime;
458
0
        }
459
0
        else
460
0
            mResetExtents = false;
461
0
    }
462
    //-----------------------------------------------------------------------
463
    void Profiler::displayResults() 
464
0
    {
465
        // if its time to update the display
466
0
        if (!(mCurrentFrame % mUpdateDisplayFrequency)) 
467
0
        {
468
            // ensure the root won't be culled
469
0
            mRoot.frame.calls = 1;
470
471
0
            for(auto& l : mListeners)
472
0
                l->displayResults(mRoot, mMaxTotalFrameTime);
473
0
        }
474
0
        ++mCurrentFrame;
475
0
    }
476
    //-----------------------------------------------------------------------
477
    bool Profiler::watchForMax(const String& profileName) 
478
0
    {
479
0
        assert ((profileName != "") && ("Profile name can't be an empty string"));
480
481
0
        return mRoot.watchForMax(profileName);
482
0
    }
483
    //-----------------------------------------------------------------------
484
    bool ProfileInstance::watchForMax(const String& profileName) 
485
0
    {
486
0
        for(auto& i : children)
487
0
        {
488
0
            ProfileInstance* child = i.second;
489
0
            if( (child->name == profileName && child->watchForMax()) || child->watchForMax(profileName))
490
0
                return true;
491
0
        }
492
0
        return false;
493
0
    }
494
    //-----------------------------------------------------------------------
495
    bool Profiler::watchForMin(const String& profileName) 
496
0
    {
497
0
        assert ((profileName != "") && ("Profile name can't be an empty string"));
498
0
        return mRoot.watchForMin(profileName);
499
0
    }
500
    //-----------------------------------------------------------------------
501
    bool ProfileInstance::watchForMin(const String& profileName) 
502
0
    {
503
0
        for(auto& i : children)
504
0
        {
505
0
            ProfileInstance* child = i.second;
506
0
            if( (child->name == profileName && child->watchForMin()) || child->watchForMin(profileName))
507
0
                return true;
508
0
        }
509
0
        return false;
510
0
    }
511
    //-----------------------------------------------------------------------
512
    bool Profiler::watchForLimit(const String& profileName, Real limit, bool greaterThan) 
513
0
    {
514
0
        assert ((profileName != "") && ("Profile name can't be an empty string"));
515
0
        return mRoot.watchForLimit(profileName, limit, greaterThan);
516
0
    }
517
    //-----------------------------------------------------------------------
518
    bool ProfileInstance::watchForLimit(const String& profileName, Real limit, bool greaterThan) 
519
0
    {
520
0
        for(auto& i : children)
521
0
        {
522
0
            ProfileInstance* child = i.second;
523
0
            if( (child->name == profileName && child->watchForLimit(limit, greaterThan)) || child->watchForLimit(profileName, limit, greaterThan))
524
0
                return true;
525
0
        }
526
0
        return false;
527
0
    }
528
    //-----------------------------------------------------------------------
529
    void Profiler::logResults() 
530
0
    {
531
0
        LogManager::getSingleton().logMessage("----------------------Profiler Results----------------------");
532
533
0
        for(auto& it : mRoot.children)
534
0
        {
535
0
            it.second->logResults();
536
0
        }
537
538
0
        LogManager::getSingleton().logMessage("------------------------------------------------------------");
539
0
    }
540
    //-----------------------------------------------------------------------
541
    void ProfileInstance::logResults() 
542
0
    {
543
0
        LogManager::getSingleton().logMessage(StringUtil::format(
544
0
            "%*s%s\t| Min %.2f | Max %.2f | Avg %.2f", hierarchicalLvl * 4, "", name.c_str(), history.minTimePercent,
545
0
            history.maxTimePercent, history.totalTimePercent / history.totalCalls));
546
547
0
        for(auto& it : children)
548
0
        {
549
0
            it.second->logResults();
550
0
        }
551
0
    }
552
    //-----------------------------------------------------------------------
553
    void Profiler::reset() 
554
0
    {
555
0
        mRoot.reset();
556
0
        mMaxTotalFrameTime = 0;
557
0
    }
558
    //-----------------------------------------------------------------------
559
    void ProfileInstance::reset(void)
560
0
    {
561
0
        history.currentTimePercent = history.maxTimePercent = history.totalTimePercent = 0;
562
0
        history.currentTimeMillisecs = history.maxTimeMillisecs = history.totalTimeMillisecs = 0;
563
0
        history.numCallsThisFrame = history.totalCalls = 0;
564
565
0
        history.minTimePercent = 1;
566
0
        history.minTimeMillisecs = 100000;
567
0
        for(auto& it : children)
568
0
        {
569
0
            it.second->reset();
570
0
        }
571
0
    }
572
    //-----------------------------------------------------------------------
573
    void Profiler::setUpdateDisplayFrequency(uint freq)
574
0
    {
575
0
        mUpdateDisplayFrequency = freq;
576
0
    }
577
    //-----------------------------------------------------------------------
578
    uint Profiler::getUpdateDisplayFrequency() const
579
0
    {
580
0
        return mUpdateDisplayFrequency;
581
0
    }
582
    //-----------------------------------------------------------------------
583
    void Profiler::addListener(ProfileSessionListener* listener)
584
0
    {
585
0
        if (std::find(mListeners.begin(), mListeners.end(), listener) == mListeners.end())
586
0
            mListeners.push_back(listener);
587
0
    }
588
    //-----------------------------------------------------------------------
589
    void Profiler::removeListener(ProfileSessionListener* listener)
590
0
    {
591
0
        TProfileSessionListener::iterator i = std::find(mListeners.begin(), mListeners.end(), listener);
592
0
        if (i != mListeners.end())
593
0
            mListeners.erase(i);
594
0
    }
595
    //-----------------------------------------------------------------------
596
}