Merge pull request #2939 from elsid/more_stats

Add stats for all updates

apps/openmw/engine.cpp

@@ -67,6 +67,140 @@ namespace
         if (ret != 0)
             Log(Debug::Error) << "SDL error: " << SDL_GetError();
     }
+
+    struct UserStats
+    {
+        const std::string mLabel;
+        const std::string mBegin;
+        const std::string mEnd;
+        const std::string mTaken;
+
+        UserStats(const std::string& label, const std::string& prefix)
+            : mLabel(label),
+              mBegin(prefix + "_time_begin"),
+              mEnd(prefix + "_time_end"),
+              mTaken(prefix + "_time_taken")
+        {}
+    };
+
+    enum class UserStatsType : std::size_t
+    {
+        Input,
+        Sound,
+        State,
+        Script,
+        Mechanics,
+        Physics,
+        World,
+        Gui,
+
+        Number,
+    };
+
+    template <UserStatsType type>
+    struct UserStatsValue
+    {
+        static const UserStats sValue;
+    };
+
+    template <>
+    const UserStats UserStatsValue<UserStatsType::Input>::sValue {"Input", "input"};
+
+    template <>
+    const UserStats UserStatsValue<UserStatsType::Sound>::sValue {"Sound", "sound"};
+
+    template <>
+    const UserStats UserStatsValue<UserStatsType::State>::sValue {"State", "state"};
+
+    template <>
+    const UserStats UserStatsValue<UserStatsType::Script>::sValue {"Script", "script"};
+
+    template <>
+    const UserStats UserStatsValue<UserStatsType::Mechanics>::sValue {"Mech", "mechanics"};
+
+    template <>
+    const UserStats UserStatsValue<UserStatsType::Physics>::sValue {"Phys", "physics"};
+
+    template <>
+    const UserStats UserStatsValue<UserStatsType::World>::sValue {"World", "world"};
+
+    template <>
+    const UserStats UserStatsValue<UserStatsType::Gui>::sValue {"Gui", "gui"};
+
+    template <UserStatsType type>
+    struct ForEachUserStatsValue
+    {
+        template <class F>
+        static void apply(F&& f)
+        {
+            f(UserStatsValue<type>::sValue);
+            using Next = ForEachUserStatsValue<static_cast<UserStatsType>(static_cast<std::size_t>(type) + 1)>;
+            Next::apply(std::forward<F>(f));
+        }
+    };
+
+    template <>
+    struct ForEachUserStatsValue<UserStatsType::Number>
+    {
+        template <class F>
+        static void apply(F&&) {}
+    };
+
+    template <class F>
+    void forEachUserStatsValue(F&& f)
+    {
+        ForEachUserStatsValue<static_cast<UserStatsType>(0)>::apply(std::forward<F>(f));
+    }
+
+    template <UserStatsType sType>
+    class ScopedProfile
+    {
+        public:
+            ScopedProfile(osg::Timer_t frameStart, unsigned int frameNumber, const osg::Timer& timer, osg::Stats& stats)
+                : mScopeStart(timer.tick()),
+                  mFrameStart(frameStart),
+                  mFrameNumber(frameNumber),
+                  mTimer(timer),
+                  mStats(stats)
+            {
+            }
+
+            ScopedProfile(const ScopedProfile&) = delete;
+            ScopedProfile& operator=(const ScopedProfile&) = delete;
+
+            ~ScopedProfile()
+            {
+                const osg::Timer_t end = mTimer.tick();
+                const UserStats& stats = UserStatsValue<sType>::sValue;
+
+                mStats.setAttribute(mFrameNumber, stats.mBegin, mTimer.delta_s(mFrameStart, mScopeStart));
+                mStats.setAttribute(mFrameNumber, stats.mTaken, mTimer.delta_s(mScopeStart, end));
+                mStats.setAttribute(mFrameNumber, stats.mEnd, mTimer.delta_s(mFrameStart, end));
+            }
+
+        private:
+            const osg::Timer_t mScopeStart;
+            const osg::Timer_t mFrameStart;
+            const unsigned int mFrameNumber;
+            const osg::Timer& mTimer;
+            osg::Stats& mStats;
+    };
+
+    void initStatsHandler(Resource::Profiler& profiler)
+    {
+        const osg::Vec4f textColor(1.f, 1.f, 1.f, 1.f);
+        const osg::Vec4f barColor(1.f, 1.f, 1.f, 1.f);
+        const float multiplier = 1000;
+        const bool average = true;
+        const bool averageInInverseSpace = false;
+        const float maxValue = 10000;
+
+        forEachUserStatsValue([&] (const UserStats& v)
+        {
+            profiler.addUserStatsLine(v.mLabel, textColor, barColor, v.mTaken, multiplier,
+                                      average, averageInInverseSpace, v.mBegin, v.mEnd, maxValue);
+        });
+    }
 }
 
 void OMW::Engine::executeLocalScripts()
@@ -87,16 +221,25 @@ bool OMW::Engine::frame(float frametime)
 {
     try
     {
-        mStartTick = mViewer->getStartTick();
+        const osg::Timer_t frameStart = mViewer->getStartTick();
+        const unsigned int frameNumber = mViewer->getFrameStamp()->getFrameNumber();
+        const osg::Timer* const timer = osg::Timer::instance();
+        osg::Stats* const stats = mViewer->getViewerStats();
 
         mEnvironment.setFrameDuration(frametime);
 
         // update input
+        {
+            ScopedProfile<UserStatsType::Input> profile(frameStart, frameNumber, *timer, *stats);
             mEnvironment.getInputManager()->update(frametime, false);
+        }
 
         // When the window is minimized, pause the game. Currently this *has* to be here to work around a MyGUI bug.
         // If we are not currently rendering, then RenderItems will not be reused resulting in a memory leak upon changing widget textures (fixed in MyGUI 3.3.2),
         // and destroyed widgets will not be deleted (not fixed yet, https://github.com/MyGUI/mygui/issues/21)
+        {
+            ScopedProfile<UserStatsType::Sound> profile(frameStart, frameNumber, *timer, *stats);
+
             if (!mEnvironment.getWindowManager()->isWindowVisible())
             {
                 mEnvironment.getSoundManager()->pausePlayback();
@@ -108,18 +251,23 @@ bool OMW::Engine::frame(float frametime)
             // sound
             if (mUseSound)
                 mEnvironment.getSoundManager()->update(frametime);
+        }
 
         // Main menu opened? Then scripts are also paused.
         bool paused = mEnvironment.getWindowManager()->containsMode(MWGui::GM_MainMenu);
 
         // update game state
+        {
+            ScopedProfile<UserStatsType::State> profile(frameStart, frameNumber, *timer, *stats);
             mEnvironment.getStateManager()->update (frametime);
+        }
 
         bool guiActive = mEnvironment.getWindowManager()->isGuiMode();
 
-        osg::Timer_t beforeScriptTick = osg::Timer::instance()->tick();
+        {
-        if (mEnvironment.getStateManager()->getState()!=
+            ScopedProfile<UserStatsType::Script> profile(frameStart, frameNumber, *timer, *stats);
-            MWBase::StateManager::State_NoGame)
+
+            if (mEnvironment.getStateManager()->getState() != MWBase::StateManager::State_NoGame)
             {
                 if (!paused)
                 {
@@ -142,64 +290,50 @@ bool OMW::Engine::frame(float frametime)
                     mEnvironment.getWorld()->rechargeItems(frametime, true);
                 }
             }
-        osg::Timer_t afterScriptTick = osg::Timer::instance()->tick();
-
-        // update actors
-        osg::Timer_t beforeMechanicsTick = osg::Timer::instance()->tick();
-        if (mEnvironment.getStateManager()->getState()!=
-            MWBase::StateManager::State_NoGame)
-        {
-            mEnvironment.getMechanicsManager()->update(frametime,
-                guiActive);
         }
-        osg::Timer_t afterMechanicsTick = osg::Timer::instance()->tick();
 
-        if (mEnvironment.getStateManager()->getState()==
+        // update mechanics
-            MWBase::StateManager::State_Running)
+        {
+            ScopedProfile<UserStatsType::Mechanics> profile(frameStart, frameNumber, *timer, *stats);
+
+            if (mEnvironment.getStateManager()->getState() != MWBase::StateManager::State_NoGame)
+            {
+                mEnvironment.getMechanicsManager()->update(frametime, guiActive);
+            }
+
+            if (mEnvironment.getStateManager()->getState() == MWBase::StateManager::State_Running)
             {
                 MWWorld::Ptr player = mEnvironment.getWorld()->getPlayerPtr();
                 if(!guiActive && player.getClass().getCreatureStats(player).isDead())
                     mEnvironment.getStateManager()->endGame();
             }
+        }
 
         // update physics
-        osg::Timer_t beforePhysicsTick = osg::Timer::instance()->tick();
+        {
-        if (mEnvironment.getStateManager()->getState()!=
+            ScopedProfile<UserStatsType::Physics> profile(frameStart, frameNumber, *timer, *stats);
-            MWBase::StateManager::State_NoGame)
+
+            if (mEnvironment.getStateManager()->getState() != MWBase::StateManager::State_NoGame)
             {
                 mEnvironment.getWorld()->updatePhysics(frametime, guiActive);
             }
-        osg::Timer_t afterPhysicsTick = osg::Timer::instance()->tick();
+        }
 
         // update world
-        osg::Timer_t beforeWorldTick = osg::Timer::instance()->tick();
+        {
-        if (mEnvironment.getStateManager()->getState()!=
+            ScopedProfile<UserStatsType::World> profile(frameStart, frameNumber, *timer, *stats);
-            MWBase::StateManager::State_NoGame)
+
+            if (mEnvironment.getStateManager()->getState() != MWBase::StateManager::State_NoGame)
             {
                 mEnvironment.getWorld()->update(frametime, guiActive);
             }
-        osg::Timer_t afterWorldTick = osg::Timer::instance()->tick();
+        }
 
         // update GUI
+        {
+            ScopedProfile<UserStatsType::Gui> profile(frameStart, frameNumber, *timer, *stats);
             mEnvironment.getWindowManager()->update(frametime);
-
+        }
-        unsigned int frameNumber = mViewer->getFrameStamp()->getFrameNumber();
-        osg::Stats* stats = mViewer->getViewerStats();
-        stats->setAttribute(frameNumber, "script_time_begin", osg::Timer::instance()->delta_s(mStartTick, beforeScriptTick));
-        stats->setAttribute(frameNumber, "script_time_taken", osg::Timer::instance()->delta_s(beforeScriptTick, afterScriptTick));
-        stats->setAttribute(frameNumber, "script_time_end", osg::Timer::instance()->delta_s(mStartTick, afterScriptTick));
-
-        stats->setAttribute(frameNumber, "mechanics_time_begin", osg::Timer::instance()->delta_s(mStartTick, beforeMechanicsTick));
-        stats->setAttribute(frameNumber, "mechanics_time_taken", osg::Timer::instance()->delta_s(beforeMechanicsTick, afterMechanicsTick));
-        stats->setAttribute(frameNumber, "mechanics_time_end", osg::Timer::instance()->delta_s(mStartTick, afterMechanicsTick));
-
-        stats->setAttribute(frameNumber, "physics_time_begin", osg::Timer::instance()->delta_s(mStartTick, beforePhysicsTick));
-        stats->setAttribute(frameNumber, "physics_time_taken", osg::Timer::instance()->delta_s(beforePhysicsTick, afterPhysicsTick));
-        stats->setAttribute(frameNumber, "physics_time_end", osg::Timer::instance()->delta_s(mStartTick, afterPhysicsTick));
-
-        stats->setAttribute(frameNumber, "world_time_begin", osg::Timer::instance()->delta_s(mStartTick, beforeWorldTick));
-        stats->setAttribute(frameNumber, "world_time_taken", osg::Timer::instance()->delta_s(beforeWorldTick, afterWorldTick));
-        stats->setAttribute(frameNumber, "world_time_end", osg::Timer::instance()->delta_s(mStartTick, afterWorldTick));
 
         if (stats->collectStats("resource"))
         {
@@ -212,7 +346,6 @@ bool OMW::Engine::frame(float frametime)
 
             mEnvironment.reportStats(frameNumber, *stats);
         }
-
     }
     catch (const std::exception& e)
     {
@@ -255,8 +388,6 @@ OMW::Engine::Engine(Files::ConfigurationManager& configurationManager)
             throw std::runtime_error("Could not initialize SDL! " + std::string(SDL_GetError()));
         }
     }
-
-    mStartTick = osg::Timer::instance()->tick();
 }
 
 OMW::Engine::~Engine()
@@ -703,14 +834,7 @@ void OMW::Engine::go()
     // Setup profiler
     osg::ref_ptr<Resource::Profiler> statshandler = new Resource::Profiler;
 
-    statshandler->addUserStatsLine("Script", osg::Vec4f(1.f, 1.f, 1.f, 1.f), osg::Vec4f(1.f, 1.f, 1.f, 1.f),
+    initStatsHandler(*statshandler);
-                                   "script_time_taken", 1000.0, true, false, "script_time_begin", "script_time_end", 10000);
-    statshandler->addUserStatsLine("Mech", osg::Vec4f(1.f, 1.f, 1.f, 1.f), osg::Vec4f(1.f, 1.f, 1.f, 1.f),
-                                   "mechanics_time_taken", 1000.0, true, false, "mechanics_time_begin", "mechanics_time_end", 10000);
-    statshandler->addUserStatsLine("Phys", osg::Vec4f(1.f, 1.f, 1.f, 1.f), osg::Vec4f(1.f, 1.f, 1.f, 1.f),
-                                   "physics_time_taken", 1000.0, true, false, "physics_time_begin", "physics_time_end", 10000);
-    statshandler->addUserStatsLine("World", osg::Vec4f(1.f, 1.f, 1.f, 1.f), osg::Vec4f(1.f, 1.f, 1.f, 1.f),
-                                   "world_time_taken", 1000.0, true, false, "world_time_begin", "world_time_end", 10000);
 
     mViewer->addEventHandler(statshandler);
 

apps/openmw/engine.hpp

@@ -111,8 +111,6 @@ namespace OMW
             bool mScriptBlacklistUse;
             bool mNewGame;
 
-            osg::Timer_t mStartTick;
-
             // not implemented
             Engine (const Engine&);
             Engine& operator= (const Engine&);