From b8f2dcea4de03b21f353240935a3295f237f258f Mon Sep 17 00:00:00 2001
From: Perttu Ahola <celeron55@gmail.com>
Date: Sun, 16 Oct 2011 21:16:44 +0300
Subject: [PATCH] Improve debug profiler usage for investigating CPU usage of
server
---
src/environment.cpp | 65 ++++++++++++++++++++++++++-------------------
src/game.cpp | 2 ++
src/profiler.h | 62 +++++++++++++++++++++++++++++++-----------
src/server.cpp | 40 +++++++---------------------
4 files changed, 97 insertions(+), 72 deletions(-)
diff --git a/src/environment.cpp b/src/environment.cpp
index 267dd66af..99dc6d62b 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<Player*>::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<Player*>::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<v3s16, bool>::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<v3s16, bool>::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 c415db1e3..276857f80 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 a30e34a7c..8eaf18df5 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<std::string, u32>::Node *n = m_data.find(name);
+ core::map<std::string, float>::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<std::string, float>::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<std::string, u32>::Iterator
+ for(core::map<std::string, float>::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<std::string, u32>::Iterator
+ for(core::map<std::string, float>::Iterator
i = m_data.getIterator();
i.atEnd() == false; i++)
{
std::string name = i.getNode()->getKey();
- o<<name<<": ";
+ o<<" "<<name<<": ";
s32 clampsize = 40;
- s32 space = clampsize-name.size();
+ s32 space = clampsize - name.size();
for(s32 j=0; j<space; j++)
{
if(j%2 == 0 && j < space - 1)
@@ -88,25 +102,34 @@ public:
private:
JMutex m_mutex;
- core::map<std::string, u32> m_data;
+ core::map<std::string, float> 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 3e1034f50..ed0c97c29 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 "<<dtime<<std::endl;
//infostream<<"Server::AsyncRunStep(): dtime="<<dtime<<std::endl;
@@ -1184,7 +1165,6 @@ void Server::AsyncRunStep()
{
// This has to be called so that the client list gets synced
// with the peer list of the connection
- ScopeProfiler sp(g_profiler, "Server: peer change handling");
handlePeerChanges();
}
@@ -1233,7 +1213,8 @@ void Server::AsyncRunStep()
{
JMutexAutoLock lock(m_env_mutex);
// Step environment
- ScopeProfiler sp(g_profiler, "Server: environment step");
+ ScopeProfiler sp(g_profiler, "SEnv step");
+ ScopeProfiler sp2(g_profiler, "SEnv step avg", SPT_LOWPASS);
m_env.step(dtime);
}
@@ -1340,7 +1321,7 @@ void Server::AsyncRunStep()
JMutexAutoLock envlock(m_env_mutex);
JMutexAutoLock conlock(m_con_mutex);
- ScopeProfiler sp(g_profiler, "Server: checking added and deleted objects");
+ ScopeProfiler sp(g_profiler, "Server: checking added and deleted objs");
// Radius inside which objects are active
s16 radius = g_settings->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);
--
2.25.1