From 2419d0029ac36952aaa74b685d529a3592adb6aa Mon Sep 17 00:00:00 2001 From: Perttu Ahola Date: Sun, 16 Oct 2011 22:39:35 +0300 Subject: [PATCH] Some more profiler stuff to get the hang on what really uses CPU --- src/content_sao.cpp | 11 ++++++++ src/environment.cpp | 14 ++++++----- src/game.cpp | 2 +- src/profiler.h | 61 +++++++++++++++++++++++++++++++++------------ src/server.cpp | 2 +- 5 files changed, 66 insertions(+), 24 deletions(-) diff --git a/src/content_sao.cpp b/src/content_sao.cpp index 1968b7b..9569b65 100644 --- a/src/content_sao.cpp +++ b/src/content_sao.cpp @@ -21,6 +21,7 @@ with this program; if not, write to the Free Software Foundation, Inc., #include "collision.h" #include "environment.h" #include "settings.h" +#include "profiler.h" core::map ServerActiveObject::m_types; @@ -137,6 +138,8 @@ ServerActiveObject* ItemSAO::create(ServerEnvironment *env, u16 id, v3f pos, void ItemSAO::step(float dtime, bool send_recommended) { + ScopeProfiler sp2(g_profiler, "ItemSAO::step avg", SPT_AVG); + assert(m_env); const float interval = 0.2; @@ -291,6 +294,8 @@ ServerActiveObject* RatSAO::create(ServerEnvironment *env, u16 id, v3f pos, void RatSAO::step(float dtime, bool send_recommended) { + ScopeProfiler sp2(g_profiler, "RatSAO::step avg", SPT_AVG); + assert(m_env); if(m_is_active == false) @@ -480,6 +485,8 @@ ServerActiveObject* Oerkki1SAO::create(ServerEnvironment *env, u16 id, v3f pos, void Oerkki1SAO::step(float dtime, bool send_recommended) { + ScopeProfiler sp2(g_profiler, "Oerkki1SAO::step avg", SPT_AVG); + assert(m_env); if(m_is_active == false) @@ -752,6 +759,8 @@ ServerActiveObject* FireflySAO::create(ServerEnvironment *env, u16 id, v3f pos, void FireflySAO::step(float dtime, bool send_recommended) { + ScopeProfiler sp2(g_profiler, "FireflySAO::step avg", SPT_AVG); + assert(m_env); if(m_is_active == false) @@ -1065,6 +1074,8 @@ static void explodeSquare(Map *map, v3s16 p0, v3s16 size) void MobV2SAO::step(float dtime, bool send_recommended) { + ScopeProfiler sp2(g_profiler, "MobV2SAO::step avg", SPT_AVG); + assert(m_env); Map *map = &m_env->getMap(); diff --git a/src/environment.cpp b/src/environment.cpp index 99dc6d6..47743bf 100644 --- a/src/environment.cpp +++ b/src/environment.cpp @@ -684,7 +684,7 @@ void ServerEnvironment::step(float dtime) Handle players */ { - ScopeProfiler sp(g_profiler, "SEnv: handle players avg", SPT_LOWPASS); + ScopeProfiler sp(g_profiler, "SEnv: handle players avg", SPT_AVG); for(core::list::Iterator i = m_players.begin(); i != m_players.end(); i++) { @@ -726,7 +726,7 @@ void ServerEnvironment::step(float dtime) */ if(m_active_blocks_management_interval.step(dtime, 2.0)) { - ScopeProfiler sp(g_profiler, "SEnv: manage act. block list avg", SPT_LOWPASS); + ScopeProfiler sp(g_profiler, "SEnv: manage act. block list avg /2s", SPT_AVG); /* Get player block positions */ @@ -803,7 +803,7 @@ void ServerEnvironment::step(float dtime) */ if(m_active_blocks_nodemetadata_interval.step(dtime, 1.0)) { - ScopeProfiler sp(g_profiler, "SEnv: mess in act. blocks avg", SPT_LOWPASS); + ScopeProfiler sp(g_profiler, "SEnv: mess in act. blocks avg /1s", SPT_AVG); float dtime = 1.0; @@ -842,7 +842,7 @@ void ServerEnvironment::step(float dtime) if(m_active_blocks_test_interval.step(dtime, 10.0)) { - ScopeProfiler sp(g_profiler, "SEnv: modify in blocks avg", SPT_LOWPASS); + ScopeProfiler sp(g_profiler, "SEnv: modify in blocks avg /10s", SPT_AVG); //float dtime = 10.0; for(core::map::Iterator @@ -1045,8 +1045,10 @@ void ServerEnvironment::step(float dtime) Step active objects */ { - ScopeProfiler sp(g_profiler, "SEnv: step act. objs avg", SPT_LOWPASS); + ScopeProfiler sp(g_profiler, "SEnv: step act. objs avg", SPT_AVG); //TimeTaker timer("Step active objects"); + + g_profiler->avg("SEnv: num of objects", m_active_objects.size()); // This helps the objects to send data at the same time bool send_recommended = false; @@ -1086,7 +1088,7 @@ void ServerEnvironment::step(float dtime) */ if(m_object_management_interval.step(dtime, 0.5)) { - ScopeProfiler sp(g_profiler, "SEnv: remove removed objs avg", SPT_LOWPASS); + ScopeProfiler sp(g_profiler, "SEnv: remove removed objs avg /.5s", SPT_AVG); /* Remove objects that satisfy (m_removed && m_known_by_count==0) */ diff --git a/src/game.cpp b/src/game.cpp index 276857f..e666e08 100644 --- a/src/game.cpp +++ b/src/game.cpp @@ -1070,7 +1070,7 @@ void the_game( object_hit_delay_timer -= dtime; - g_profiler->add("Elapsed time", dtime * 1000); + g_profiler->add("Elapsed time", dtime); /* Log frametime for visualization diff --git a/src/profiler.h b/src/profiler.h index 8eaf18d..129118e 100644 --- a/src/profiler.h +++ b/src/profiler.h @@ -41,28 +41,48 @@ public: void add(const std::string &name, float value) { JMutexAutoLock lock(m_mutex); - core::map::Node *n = m_data.find(name); - if(n == NULL) { - m_data[name] = value; + /* No average shall have been used; mark add used as -2 */ + core::map::Node *n = m_avgcounts.find(name); + if(n == NULL) + m_avgcounts[name] = -2; + else{ + if(n->getValue() == -1) + n->setValue(-2); + assert(n->getValue() == -2); + } } - else { - n->setValue(n->getValue() + value); + core::map::Node *n = m_data.find(name); + if(n == NULL) + m_data[name] = value; + else + n->setValue(n->getValue() + value); } } - void lowpass(const std::string &name, float value, float factor) + void avg(const std::string &name, float value) { JMutexAutoLock lock(m_mutex); - core::map::Node *n = m_data.find(name); - if(n == NULL) { - m_data[name] = value; + core::map::Node *n = m_avgcounts.find(name); + if(n == NULL) + m_avgcounts[name] = 1; + else{ + /* No add shall have been used */ + assert(n->getValue() != -2); + if(n->getValue() <= 0) + n->setValue(1); + else + n->setValue(n->getValue() + 1); + } } - else { - n->setValue(n->getValue() * (1.0 - 1.0/factor) + value / factor); + core::map::Node *n = m_data.find(name); + if(n == NULL) + m_data[name] = value; + else + n->setValue(n->getValue() + value); } } @@ -75,6 +95,7 @@ public: { i.getNode()->setValue(0); } + m_avgcounts.clear(); } void print(std::ostream &o) @@ -85,6 +106,12 @@ public: i.atEnd() == false; i++) { std::string name = i.getNode()->getKey(); + int avgcount = 1; + core::map::Node *n = m_avgcounts.find(name); + if(n){ + if(n->getValue() >= 1) + avgcount = n->getValue(); + } o<<" "<getValue(); + o<<(i.getNode()->getValue() / avgcount); o< m_data; + core::map m_avgcounts; }; enum ScopeProfilerType{ SPT_ADD, - SPT_LOWPASS + SPT_AVG }; class ScopeProfiler @@ -138,14 +166,15 @@ public: { if(m_timer) { - u32 duration = m_timer->stop(true); + float duration_ms = m_timer->stop(true); + float duration = duration_ms / 1000.0; if(m_profiler){ switch(m_type){ case SPT_ADD: m_profiler->add(m_name, duration); break; - case SPT_LOWPASS: - m_profiler->lowpass(m_name, duration, 20.0); + case SPT_AVG: + m_profiler->avg(m_name, duration); break; } } diff --git a/src/server.cpp b/src/server.cpp index ed0c97c..14c019d 100644 --- a/src/server.cpp +++ b/src/server.cpp @@ -1214,7 +1214,7 @@ void Server::AsyncRunStep() JMutexAutoLock lock(m_env_mutex); // Step environment ScopeProfiler sp(g_profiler, "SEnv step"); - ScopeProfiler sp2(g_profiler, "SEnv step avg", SPT_LOWPASS); + ScopeProfiler sp2(g_profiler, "SEnv step avg", SPT_AVG); m_env.step(dtime); }