From: Perttu Ahola Date: Sun, 16 Oct 2011 18:16:44 +0000 (+0300) Subject: Improve debug profiler usage for investigating CPU usage of server X-Git-Url: http://81.2.79.47:8989/gitweb/?a=commitdiff_plain;h=b8f2dcea4de03b21f353240935a3295f237f258f;p=zefram%2Fminetest%2Fminetest_engine.git Improve debug profiler usage for investigating CPU usage of server --- diff --git a/src/environment.cpp b/src/environment.cpp index 267dd66a..99dc6d62 100644 --- a/src/environment.cpp +++ b/src/environment.cpp @@ -28,6 +28,7 @@ with this program; if not, write to the Free Software Foundation, Inc., #include "mapgen.h" #include "settings.h" #include "log.h" +#include "profiler.h" #define PP(x) "("<<(x).X<<","<<(x).Y<<","<<(x).Z<<")" @@ -682,38 +683,41 @@ void ServerEnvironment::step(float dtime) /* Handle players */ - for(core::list::Iterator i = m_players.begin(); - i != m_players.end(); i++) { - Player *player = *i; - - // Ignore disconnected players - if(player->peer_id == 0) - continue; - - v3f playerpos = player->getPosition(); - - // Move - player->move(dtime, *m_map, 100*BS); - - /* - Add footsteps to grass - */ - if(footprints) + ScopeProfiler sp(g_profiler, "SEnv: handle players avg", SPT_LOWPASS); + for(core::list::Iterator i = m_players.begin(); + i != m_players.end(); i++) { - // Get node that is at BS/4 under player - v3s16 bottompos = floatToInt(playerpos + v3f(0,-BS/4,0), BS); - try{ - MapNode n = m_map->getNode(bottompos); - if(n.getContent() == CONTENT_GRASS) + Player *player = *i; + + // Ignore disconnected players + if(player->peer_id == 0) + continue; + + v3f playerpos = player->getPosition(); + + // Move + player->move(dtime, *m_map, 100*BS); + + /* + Add footsteps to grass + */ + if(footprints) + { + // Get node that is at BS/4 under player + v3s16 bottompos = floatToInt(playerpos + v3f(0,-BS/4,0), BS); + try{ + MapNode n = m_map->getNode(bottompos); + if(n.getContent() == CONTENT_GRASS) + { + n.setContent(CONTENT_GRASS_FOOTSTEPS); + m_map->setNode(bottompos, n); + } + } + catch(InvalidPositionException &e) { - n.setContent(CONTENT_GRASS_FOOTSTEPS); - m_map->setNode(bottompos, n); } } - catch(InvalidPositionException &e) - { - } } } @@ -722,6 +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); /* Get player block positions */ @@ -798,6 +803,8 @@ 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); + float dtime = 1.0; for(core::map::Iterator @@ -832,8 +839,10 @@ 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); //float dtime = 10.0; for(core::map::Iterator @@ -1036,6 +1045,7 @@ void ServerEnvironment::step(float dtime) Step active objects */ { + ScopeProfiler sp(g_profiler, "SEnv: step act. objs avg", SPT_LOWPASS); //TimeTaker timer("Step active objects"); // This helps the objects to send data at the same time @@ -1076,6 +1086,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); /* Remove objects that satisfy (m_removed && m_known_by_count==0) */ diff --git a/src/game.cpp b/src/game.cpp index c415db1e..276857f8 100644 --- a/src/game.cpp +++ b/src/game.cpp @@ -1070,6 +1070,8 @@ void the_game( object_hit_delay_timer -= dtime; + g_profiler->add("Elapsed time", dtime * 1000); + /* Log frametime for visualization */ diff --git a/src/profiler.h b/src/profiler.h index a30e34a7..8eaf18df 100644 --- a/src/profiler.h +++ b/src/profiler.h @@ -38,24 +38,38 @@ public: m_mutex.Init(); } - void add(const std::string &name, u32 duration) + void add(const std::string &name, float value) { JMutexAutoLock lock(m_mutex); - core::map::Node *n = m_data.find(name); + core::map::Node *n = m_data.find(name); if(n == NULL) { - m_data[name] = duration; + m_data[name] = value; } else { - n->setValue(n->getValue()+duration); + n->setValue(n->getValue() + value); + } + } + + void lowpass(const std::string &name, float value, float factor) + { + JMutexAutoLock lock(m_mutex); + core::map::Node *n = m_data.find(name); + if(n == NULL) + { + m_data[name] = value; + } + else + { + n->setValue(n->getValue() * (1.0 - 1.0/factor) + value / factor); } } void clear() { JMutexAutoLock lock(m_mutex); - for(core::map::Iterator + for(core::map::Iterator i = m_data.getIterator(); i.atEnd() == false; i++) { @@ -66,14 +80,14 @@ public: void print(std::ostream &o) { JMutexAutoLock lock(m_mutex); - for(core::map::Iterator + for(core::map::Iterator i = m_data.getIterator(); i.atEnd() == false; i++) { std::string name = i.getNode()->getKey(); - o< m_data; + core::map m_data; +}; + +enum ScopeProfilerType{ + SPT_ADD, + SPT_LOWPASS }; class ScopeProfiler { public: - ScopeProfiler(Profiler *profiler, const std::string &name): + ScopeProfiler(Profiler *profiler, const std::string &name, + enum ScopeProfilerType type = SPT_ADD): m_profiler(profiler), m_name(name), - m_timer(NULL) + m_timer(NULL), + m_type(type) { if(m_profiler) m_timer = new TimeTaker(m_name.c_str()); } // name is copied - ScopeProfiler(Profiler *profiler, const char *name): + ScopeProfiler(Profiler *profiler, const char *name, + enum ScopeProfilerType type = SPT_ADD): m_profiler(profiler), m_name(name), - m_timer(NULL) + m_timer(NULL), + m_type(type) { if(m_profiler) m_timer = new TimeTaker(m_name.c_str()); @@ -116,8 +139,16 @@ public: if(m_timer) { u32 duration = m_timer->stop(true); - if(m_profiler) - m_profiler->add(m_name, duration); + 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); + break; + } + } delete m_timer; } } @@ -125,6 +156,7 @@ private: Profiler *m_profiler; std::string m_name; TimeTaker *m_timer; + enum ScopeProfilerType m_type; }; #endif diff --git a/src/server.cpp b/src/server.cpp index 3e1034f5..ed0c97c2 100644 --- a/src/server.cpp +++ b/src/server.cpp @@ -842,31 +842,9 @@ void RemoteClient::SendObjectData( } /* - Get and write object data + Get and write object data (dummy, for compatibility) */ - /* - Get nearby blocks. - - For making players to be able to build to their nearby - environment (building is not possible on blocks that are not - in memory): - - Set blocks changed - - Add blocks to emerge queue if they are not found - - SUGGESTION: These could be ignored from the backside of the player - */ - - Player *player = server->m_env.getPlayer(peer_id); - - assert(player); - - v3f playerpos = player->getPosition(); - v3f playerspeed = player->getSpeed(); - - v3s16 center_nodepos = floatToInt(playerpos, BS); - v3s16 center = getNodeBlockPos(center_nodepos); - // Write block count writeU16(buf, 0); os.write((char*)buf, 2); @@ -1143,6 +1121,8 @@ void Server::AsyncRunStep() { DSTACK(__FUNCTION_NAME); + g_profiler->add("Server::AsyncRunStep (num)", 1); + float dtime; { JMutexAutoLock lock1(m_step_dtime_mutex); @@ -1150,14 +1130,15 @@ void Server::AsyncRunStep() } { - ScopeProfiler sp(g_profiler, "Server: selecting and sending " - "blocks to clients"); + ScopeProfiler sp(g_profiler, "Server: sel and send blocks to clients"); // Send blocks to clients SendBlocks(dtime); } if(dtime < 0.001) return; + + g_profiler->add("Server::AsyncRunStep with dtime (num)", 1); //infostream<<"Server steps "<getS16("active_object_send_range_blocks"); @@ -1720,7 +1701,6 @@ void Server::AsyncRunStep() /* Send object positions - TODO: Get rid of MapBlockObjects */ { float &counter = m_objectdata_timer; @@ -1730,7 +1710,7 @@ void Server::AsyncRunStep() JMutexAutoLock lock1(m_env_mutex); JMutexAutoLock lock2(m_con_mutex); - ScopeProfiler sp(g_profiler, "Server: sending mbo positions"); + ScopeProfiler sp(g_profiler, "Server: sending player positions"); SendObjectData(counter);