From: Perttu Ahola <celeron55@gmail.com>
Date: Mon, 30 May 2011 21:15:43 +0000 (+0300)
Subject: Reduced the CPU usage of the sent block selector algorithm
X-Git-Tag: 0.2.20110731_3~161
X-Git-Url: https://git.librecmc.org/?a=commitdiff_plain;h=223b3793485a76f87599d39364b1003c2ca7c49c;p=oweals%2Fminetest.git

Reduced the CPU usage of the sent block selector algorithm
---

diff --git a/minetest.conf.example b/minetest.conf.example
index 1a1dbe0fc..743186853 100644
--- a/minetest.conf.example
+++ b/minetest.conf.example
@@ -92,10 +92,6 @@
 # Server side stuff
 #
 
-# Set to true to enable experimental features
-# (varies from version to version, see wiki)
-#enable_experimental = false
-
 # Map directory (everything in the world is stored here)
 #map-dir = /home/palle/custom_map
 
@@ -112,6 +108,13 @@
 # Gives some stuff to players at the beginning
 #give_initial_stuff = false
 
+# Set to true to enable experimental features
+# (varies from version to version, see wiki)
+#enable_experimental = false
+
+# Profiler data print interval. 0 = disable.
+#profiler_print_interval = 10
+
 # Player and object positions are sent at intervals specified by this
 #objectdata_inverval = 0.2
 
diff --git a/src/defaultsettings.cpp b/src/defaultsettings.cpp
index 6fcdc1dbb..73f22a7f7 100644
--- a/src/defaultsettings.cpp
+++ b/src/defaultsettings.cpp
@@ -74,12 +74,13 @@ void set_default_settings()
 	g_settings.setDefault("give_initial_stuff", "false");
 	g_settings.setDefault("default_password", "");
 	g_settings.setDefault("default_privs", "build, shout");
+	g_settings.setDefault("profiler_print_interval", "0");
 
 	g_settings.setDefault("objectdata_interval", "0.2");
 	g_settings.setDefault("active_object_range", "2");
 	g_settings.setDefault("max_simultaneous_block_sends_per_client", "1");
 	//g_settings.setDefault("max_simultaneous_block_sends_per_client", "2");
-	g_settings.setDefault("max_simultaneous_block_sends_server_total", "4");
+	g_settings.setDefault("max_simultaneous_block_sends_server_total", "8");
 	g_settings.setDefault("max_block_send_distance", "8");
 	g_settings.setDefault("max_block_generate_distance", "8");
 	g_settings.setDefault("time_send_interval", "20");
diff --git a/src/game.cpp b/src/game.cpp
index 6932b45f1..e8e6cb71f 100644
--- a/src/game.cpp
+++ b/src/game.cpp
@@ -903,6 +903,10 @@ void the_game(
 
 	bool first_loop_after_window_activation = true;
 
+	// TODO: Convert the static interval timers to these
+	// Interval limiter for profiler
+	IntervalLimiter m_profiler_interval;
+
 	// Time is in milliseconds
 	// NOTE: getRealTime() causes strange problems in wine (imprecision?)
 	// NOTE: So we have to use getTime() and call run()s between them
@@ -1089,6 +1093,21 @@ void the_game(
 			}
 		}
 
+		/*
+			Profiler
+		*/
+		float profiler_print_interval =
+				g_settings.getFloat("profiler_print_interval");
+		if(profiler_print_interval != 0)
+		{
+			if(m_profiler_interval.step(0.030, profiler_print_interval))
+			{
+				dstream<<"Profiler:"<<std::endl;
+				g_profiler.print(dstream);
+				g_profiler.clear();
+			}
+		}
+
 		/*
 			Direct handling of user input
 		*/
diff --git a/src/main.cpp b/src/main.cpp
index 3d342e596..a739d71bf 100644
--- a/src/main.cpp
+++ b/src/main.cpp
@@ -215,6 +215,8 @@ FIXME: Server sometimes goes into some infinite PeerNotFoundException loop
 FIXME: The new optimized map sending doesn't sometimes send enough blocks
        from big caves and such
 
+* Take player's walking direction into account in GetNextBlocks
+
 Environment:
 ------------
 
@@ -308,6 +310,10 @@ Making it more portable:
 Stuff to do before release:
 ---------------------------
 
+Fixes to the current release:
+-----------------------------
+- Make AuthManager to save only when data has changed
+
 Stuff to do after release:
 ---------------------------
 - Make sure server handles removing grass when a block is placed (etc)
@@ -386,6 +392,9 @@ Settings g_settings;
 // This is located in defaultsettings.cpp
 extern void set_default_settings();
 
+// Global profiler
+Profiler g_profiler;
+
 /*
 	Random stuff
 */
@@ -436,7 +445,14 @@ std::ostream *derr_client_ptr = &dstream;
 class TimeGetter
 {
 public:
-	TimeGetter(IrrlichtDevice *device):
+	virtual u32 getTime() = 0;
+};
+
+// A precise irrlicht one
+class IrrlichtTimeGetter: public TimeGetter
+{
+public:
+	IrrlichtTimeGetter(IrrlichtDevice *device):
 		m_device(device)
 	{}
 	u32 getTime()
@@ -448,8 +464,18 @@ public:
 private:
 	IrrlichtDevice *m_device;
 };
+// Not so precise one which works without irrlicht
+class SimpleTimeGetter: public TimeGetter
+{
+public:
+	u32 getTime()
+	{
+		return porting::getTimeMs();
+	}
+};
 
 // A pointer to a global instance of the time getter
+// TODO: why?
 TimeGetter *g_timegetter = NULL;
 
 u32 getTimeMs()
@@ -1208,6 +1234,9 @@ int main(int argc, char *argv[])
 	{
 		DSTACK("Dedicated server branch");
 
+		// Create time getter
+		g_timegetter = new SimpleTimeGetter();
+		
 		// Create server
 		Server server(map_dir.c_str());
 		server.start(port);
@@ -1290,7 +1319,7 @@ int main(int argc, char *argv[])
 	device = device;
 	
 	// Create time getter
-	g_timegetter = new TimeGetter(device);
+	g_timegetter = new IrrlichtTimeGetter(device);
 	
 	// Create game callback for menus
 	g_gamecallback = new MainGameCallback(device);
diff --git a/src/main.h b/src/main.h
index fcf150f87..450525c26 100644
--- a/src/main.h
+++ b/src/main.h
@@ -28,6 +28,10 @@ extern Settings g_settings;
 #include "tile.h"
 extern ITextureSource *g_texturesource;
 
+// Global profiler
+#include "profiler.h"
+extern Profiler g_profiler;
+
 // Debug streams
 
 #include <fstream>
diff --git a/src/map.cpp b/src/map.cpp
index a49de3c46..f9809e9fd 100644
--- a/src/map.cpp
+++ b/src/map.cpp
@@ -5692,9 +5692,9 @@ void ClientMap::renderMap(video::IVideoDriver* driver, s32 pass)
 			p_nodes_min.Y / MAP_BLOCKSIZE - 1,
 			p_nodes_min.Z / MAP_BLOCKSIZE - 1);
 	v3s16 p_blocks_max(
-			p_nodes_max.X / MAP_BLOCKSIZE + 1,
-			p_nodes_max.Y / MAP_BLOCKSIZE + 1,
-			p_nodes_max.Z / MAP_BLOCKSIZE + 1);
+			p_nodes_max.X / MAP_BLOCKSIZE,
+			p_nodes_max.Y / MAP_BLOCKSIZE,
+			p_nodes_max.Z / MAP_BLOCKSIZE);
 	
 	u32 vertex_count = 0;
 	
diff --git a/src/mapblock.cpp b/src/mapblock.cpp
index c448ef236..b2f972dde 100644
--- a/src/mapblock.cpp
+++ b/src/mapblock.cpp
@@ -540,10 +540,10 @@ void updateFastFaceRow(
 		
 		v3s16 p_next;
 		
-		bool next_makes_face;
+		bool next_makes_face = false;
 		v3s16 next_p_corrected;
 		v3s16 next_face_dir_corrected;
-		u8 next_lights[4];
+		u8 next_lights[4] = {0,0,0,0};
 		TileSpec next_tile;
 		
 		// If at last position, there is nothing to compare to and
diff --git a/src/profiler.h b/src/profiler.h
new file mode 100644
index 000000000..a30e34a7c
--- /dev/null
+++ b/src/profiler.h
@@ -0,0 +1,131 @@
+/*
+Minetest-c55
+Copyright (C) 2011 celeron55, Perttu Ahola <celeron55@gmail.com>
+
+This program is free software; you can redistribute it and/or modify
+it under the terms of the GNU General Public License as published by
+the Free Software Foundation; either version 2 of the License, or
+(at your option) any later version.
+
+This program is distributed in the hope that it will be useful,
+but WITHOUT ANY WARRANTY; without even the implied warranty of
+MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+GNU General Public License for more details.
+
+You should have received a copy of the GNU General Public License along
+with this program; if not, write to the Free Software Foundation, Inc.,
+51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
+*/
+
+#ifndef PROFILER_HEADER
+#define PROFILER_HEADER
+
+#include "common_irrlicht.h"
+#include <string>
+#include "utility.h"
+#include <jmutex.h>
+#include <jmutexautolock.h>
+
+/*
+	Time profiler
+*/
+
+class Profiler
+{
+public:
+	Profiler()
+	{
+		m_mutex.Init();
+	}
+
+	void add(const std::string &name, u32 duration)
+	{
+		JMutexAutoLock lock(m_mutex);
+		core::map<std::string, u32>::Node *n = m_data.find(name);
+		if(n == NULL)
+		{
+			m_data[name] = duration;
+		}
+		else
+		{
+			n->setValue(n->getValue()+duration);
+		}
+	}
+
+	void clear()
+	{
+		JMutexAutoLock lock(m_mutex);
+		for(core::map<std::string, u32>::Iterator
+				i = m_data.getIterator();
+				i.atEnd() == false; i++)
+		{
+			i.getNode()->setValue(0);
+		}
+	}
+
+	void print(std::ostream &o)
+	{
+		JMutexAutoLock lock(m_mutex);
+		for(core::map<std::string, u32>::Iterator
+				i = m_data.getIterator();
+				i.atEnd() == false; i++)
+		{
+			std::string name = i.getNode()->getKey();
+			o<<name<<": ";
+			s32 clampsize = 40;
+			s32 space = clampsize-name.size();
+			for(s32 j=0; j<space; j++)
+			{
+				if(j%2 == 0 && j < space - 1)
+					o<<"-";
+				else
+					o<<" ";
+			}
+			o<<i.getNode()->getValue();
+			o<<std::endl;
+		}
+	}
+
+private:
+	JMutex m_mutex;
+	core::map<std::string, u32> m_data;
+};
+
+class ScopeProfiler
+{
+public:
+	ScopeProfiler(Profiler *profiler, const std::string &name):
+		m_profiler(profiler),
+		m_name(name),
+		m_timer(NULL)
+	{
+		if(m_profiler)
+			m_timer = new TimeTaker(m_name.c_str());
+	}
+	// name is copied
+	ScopeProfiler(Profiler *profiler, const char *name):
+		m_profiler(profiler),
+		m_name(name),
+		m_timer(NULL)
+	{
+		if(m_profiler)
+			m_timer = new TimeTaker(m_name.c_str());
+	}
+	~ScopeProfiler()
+	{
+		if(m_timer)
+		{
+			u32 duration = m_timer->stop(true);
+			if(m_profiler)
+				m_profiler->add(m_name, duration);
+			delete m_timer;
+		}
+	}
+private:
+	Profiler *m_profiler;
+	std::string m_name;
+	TimeTaker *m_timer;
+};
+
+#endif
+
diff --git a/src/server.cpp b/src/server.cpp
index 56874c46c..6f1f1e6e8 100644
--- a/src/server.cpp
+++ b/src/server.cpp
@@ -312,11 +312,14 @@ void RemoteClient::GetNextBlocks(Server *server, float dtime,
 	TimeTaker timer("RemoteClient::GetNextBlocks", &timer_result);*/
 	
 	// Increment timers
-	m_nearest_unsent_reset_timer += dtime;
 	m_nothing_to_send_pause_timer -= dtime;
 	
 	if(m_nothing_to_send_pause_timer >= 0)
+	{
+		// Keep this reset
+		m_nearest_unsent_reset_timer = 0;
 		return;
+	}
 
 	// Won't send anything if already sending
 	if(m_blocks_sending.size() >= g_settings.getU16
@@ -326,14 +329,21 @@ void RemoteClient::GetNextBlocks(Server *server, float dtime,
 		return;
 	}
 
+	//TimeTaker timer("RemoteClient::GetNextBlocks");
+	
 	Player *player = server->m_env.getPlayer(peer_id);
 
 	assert(player != NULL);
 
 	v3f playerpos = player->getPosition();
 	v3f playerspeed = player->getSpeed();
+	v3f playerspeeddir(0,0,0);
+	if(playerspeed.getLength() > 1.0*BS)
+		playerspeeddir = playerspeed / playerspeed.getLength();
+	// Predict to next block
+	v3f playerpos_predicted = playerpos + playerspeeddir*MAP_BLOCKSIZE*BS;
 
-	v3s16 center_nodepos = floatToInt(playerpos, BS);
+	v3s16 center_nodepos = floatToInt(playerpos_predicted, BS);
 
 	v3s16 center = getNodeBlockPos(center_nodepos);
 	
@@ -344,6 +354,9 @@ void RemoteClient::GetNextBlocks(Server *server, float dtime,
 	camera_dir.rotateYZBy(player->getPitch());
 	camera_dir.rotateXZBy(player->getYaw());
 
+	/*dstream<<"camera_dir=("<<camera_dir.X<<","<<camera_dir.Y<<","
+			<<camera_dir.Z<<")"<<std::endl;*/
+
 	/*
 		Get the starting value of the block finder radius.
 	*/
@@ -356,11 +369,18 @@ void RemoteClient::GetNextBlocks(Server *server, float dtime,
 
 	/*dstream<<"m_nearest_unsent_reset_timer="
 			<<m_nearest_unsent_reset_timer<<std::endl;*/
-	if(m_nearest_unsent_reset_timer > 5.0)
+			
+	// This has to be incremented only when the nothing to send pause
+	// is not active
+	m_nearest_unsent_reset_timer += dtime;
+	
+	// Reset periodically to avoid possible bugs or other mishaps
+	if(m_nearest_unsent_reset_timer > 10.0)
 	{
 		m_nearest_unsent_reset_timer = 0;
 		m_nearest_unsent_d = 0;
-		//dstream<<"Resetting m_nearest_unsent_d"<<std::endl;
+		dstream<<"Resetting m_nearest_unsent_d for "
+				<<server->getPlayerName(peer_id)<<std::endl;
 	}
 
 	//s16 last_nearest_unsent_d = m_nearest_unsent_d;
@@ -402,11 +422,22 @@ void RemoteClient::GetNextBlocks(Server *server, float dtime,
 	s16 d_max = g_settings.getS16("max_block_send_distance");
 	s16 d_max_gen = g_settings.getS16("max_block_generate_distance");
 	
+	// Don't loop very much at a time
+	if(d_max > d_start+1)
+		d_max = d_start+1;
+	/*if(d_max_gen > d_start+2)
+		d_max_gen = d_start+2;*/
+	
 	//dstream<<"Starting from "<<d_start<<std::endl;
 
 	bool sending_something = false;
 
-	for(s16 d = d_start; d <= d_max; d++)
+	bool no_blocks_found_for_sending = true;
+
+	bool queue_is_full = false;
+	
+	s16 d;
+	for(d = d_start; d <= d_max; d++)
 	{
 		//dstream<<"RemoteClient::SendBlocks(): d="<<d<<std::endl;
 		
@@ -451,7 +482,10 @@ void RemoteClient::GetNextBlocks(Server *server, float dtime,
 
 			// Don't select too many blocks for sending
 			if(num_blocks_selected >= max_simul_dynamic)
-				goto queue_full;
+			{
+				queue_is_full = true;
+				goto queue_full_break;
+			}
 			
 			// Don't send blocks that are currently being transferred
 			if(m_blocks_sending.find(p) != NULL)
@@ -513,6 +547,8 @@ void RemoteClient::GetNextBlocks(Server *server, float dtime,
 			}
 #endif
 
+			//dstream<<"d="<<d<<std::endl;
+			
 			/*
 				Don't generate or send if not in sight
 			*/
@@ -527,7 +563,9 @@ void RemoteClient::GetNextBlocks(Server *server, float dtime,
 			*/
 			{
 				if(m_blocks_sent.find(p) != NULL)
+				{
 					continue;
+				}
 			}
 
 			/*
@@ -539,11 +577,14 @@ void RemoteClient::GetNextBlocks(Server *server, float dtime,
 			bool block_is_invalid = false;
 			if(block != NULL)
 			{
+				// Block is dummy if data doesn't exist.
+				// It means it has been not found from disk and not generated
 				if(block->isDummy())
 				{
 					surely_not_found_on_disk = true;
 				}
-
+				
+				// Block is valid if lighting is up-to-date and data exists
 				if(block->isValid() == false)
 				{
 					block_is_invalid = true;
@@ -564,8 +605,8 @@ void RemoteClient::GetNextBlocks(Server *server, float dtime,
 					If block is not close, don't send it unless it is near
 					ground level.
 
-					Block is not near ground level if night-time mesh
-					doesn't differ from day-time mesh.
+					Block is near ground level if night-time mesh
+					differs from day-time mesh.
 				*/
 				if(d > 3)
 				{
@@ -586,14 +627,16 @@ void RemoteClient::GetNextBlocks(Server *server, float dtime,
 			}
 
 			/*
-				Record the lowest d from which a a block has been
+				Record the lowest d from which a block has been
 				found being not sent and possibly to exist
 			*/
-			if(new_nearest_unsent_d == -1 || d < new_nearest_unsent_d)
+			if(no_blocks_found_for_sending)
 			{
 				if(generate == true)
 					new_nearest_unsent_d = d;
 			}
+
+			no_blocks_found_for_sending = false;
 					
 			/*
 				Add inexistent block to emerge queue.
@@ -633,20 +676,30 @@ void RemoteClient::GetNextBlocks(Server *server, float dtime,
 			sending_something = true;
 		}
 	}
-queue_full:
+queue_full_break:
 
-	if(new_nearest_unsent_d != -1)
+	//dstream<<"Stopped at "<<d<<std::endl;
+	
+	if(no_blocks_found_for_sending)
 	{
-		m_nearest_unsent_d = new_nearest_unsent_d;
+		if(queue_is_full == false)
+			new_nearest_unsent_d = d;
 	}
 
+	if(new_nearest_unsent_d != -1)
+		m_nearest_unsent_d = new_nearest_unsent_d;
+
 	if(sending_something == false)
 	{
 		m_nothing_to_send_counter++;
-		if(m_nothing_to_send_counter >= 3)
+		if((s16)m_nothing_to_send_counter >=
+				g_settings.getS16("max_block_send_distance"))
 		{
 			// Pause time in seconds
-			m_nothing_to_send_pause_timer = 2.0;
+			m_nothing_to_send_pause_timer = 1.0;
+			dstream<<"nothing to send to "
+					<<server->getPlayerName(peer_id)
+					<<" (d="<<d<<")"<<std::endl;
 		}
 	}
 	else
@@ -1130,8 +1183,12 @@ void Server::AsyncRunStep()
 		dtime = m_step_dtime;
 	}
 	
-	// Send blocks to clients
-	SendBlocks(dtime);
+	{
+		ScopeProfiler sp(&g_profiler, "Server: selecting and sending "
+				"blocks to clients");
+		// Send blocks to clients
+		SendBlocks(dtime);
+	}
 	
 	if(dtime < 0.001)
 		return;
@@ -1196,12 +1253,14 @@ void Server::AsyncRunStep()
 	{
 		// Process connection's timeouts
 		JMutexAutoLock lock2(m_con_mutex);
+		ScopeProfiler sp(&g_profiler, "Server: connection timeout processing");
 		m_con.RunTimeouts(dtime);
 	}
 	
 	{
 		// 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();
 	}
 
@@ -1209,6 +1268,7 @@ void Server::AsyncRunStep()
 		// Step environment
 		// This also runs Map's timers
 		JMutexAutoLock lock(m_env_mutex);
+		ScopeProfiler sp(&g_profiler, "Server: environment step");
 		m_env.step(dtime);
 	}
 	
@@ -1225,7 +1285,9 @@ void Server::AsyncRunStep()
 		m_liquid_transform_timer -= 1.00;
 		
 		JMutexAutoLock lock(m_env_mutex);
-		
+
+		ScopeProfiler sp(&g_profiler, "Server: liquid transform");
+
 		core::map<v3s16, MapBlock*> modified_blocks;
 		m_env.getMap().transformLiquids(modified_blocks);
 #if 0		
@@ -1298,10 +1360,11 @@ void Server::AsyncRunStep()
 	*/
 	{
 		//dstream<<"Server: Checking added and deleted active objects"<<std::endl;
-
 		JMutexAutoLock envlock(m_env_mutex);
 		JMutexAutoLock conlock(m_con_mutex);
-		
+
+		ScopeProfiler sp(&g_profiler, "Server: checking added and deleted objects");
+
 		// Radius inside which objects are active
 		s16 radius = 32;
 
@@ -1446,6 +1509,8 @@ void Server::AsyncRunStep()
 		JMutexAutoLock envlock(m_env_mutex);
 		JMutexAutoLock conlock(m_con_mutex);
 
+		ScopeProfiler sp(&g_profiler, "Server: sending object messages");
+
 		// Key = object id
 		// Value = data sent by object
 		core::map<u16, core::list<ActiveObjectMessage>* > buffered_messages;
@@ -1598,6 +1663,9 @@ void Server::AsyncRunStep()
 		{
 			JMutexAutoLock lock1(m_env_mutex);
 			JMutexAutoLock lock2(m_con_mutex);
+
+			ScopeProfiler sp(&g_profiler, "Server: sending mbo positions");
+
 			SendObjectData(counter);
 
 			counter = 0.0;
@@ -1612,7 +1680,9 @@ void Server::AsyncRunStep()
 
 		JMutexAutoLock envlock(m_env_mutex);
 		JMutexAutoLock conlock(m_con_mutex);
-		
+
+		ScopeProfiler sp(&g_profiler, "Server: stepping node metadata");
+
 		core::map<v3s16, MapBlock*> changed_blocks;
 		m_env.getMap().nodeMetadataStep(dtime, changed_blocks);
 
@@ -1655,6 +1725,8 @@ void Server::AsyncRunStep()
 		{
 			counter = 0.0;
 
+			ScopeProfiler sp(&g_profiler, "Server: saving stuff");
+
 			// Auth stuff
 			m_authmanager.save();
 			
@@ -3646,20 +3718,24 @@ void Server::SendBlocks(float dtime)
 	core::array<PrioritySortedBlockTransfer> queue;
 
 	s32 total_sending = 0;
-
-	for(core::map<u16, RemoteClient*>::Iterator
-		i = m_clients.getIterator();
-		i.atEnd() == false; i++)
+	
 	{
-		RemoteClient *client = i.getNode()->getValue();
-		assert(client->peer_id == i.getNode()->getKey());
+		ScopeProfiler sp(&g_profiler, "Server: selecting blocks for sending");
 
-		total_sending += client->SendingCount();
-		
-		if(client->serialization_version == SER_FMT_VER_INVALID)
-			continue;
-		
-		client->GetNextBlocks(this, dtime, queue);
+		for(core::map<u16, RemoteClient*>::Iterator
+			i = m_clients.getIterator();
+			i.atEnd() == false; i++)
+		{
+			RemoteClient *client = i.getNode()->getValue();
+			assert(client->peer_id == i.getNode()->getKey());
+
+			total_sending += client->SendingCount();
+			
+			if(client->serialization_version == SER_FMT_VER_INVALID)
+				continue;
+			
+			client->GetNextBlocks(this, dtime, queue);
+		}
 	}
 
 	// Sort.
@@ -4531,25 +4607,48 @@ void dedicated_server_loop(Server &server, bool &kill)
 {
 	DSTACK(__FUNCTION_NAME);
 	
-	std::cout<<DTIME<<std::endl;
-	std::cout<<"========================"<<std::endl;
-	std::cout<<"Running dedicated server"<<std::endl;
-	std::cout<<"========================"<<std::endl;
-	std::cout<<std::endl;
+	dstream<<DTIME<<std::endl;
+	dstream<<"========================"<<std::endl;
+	dstream<<"Running dedicated server"<<std::endl;
+	dstream<<"========================"<<std::endl;
+	dstream<<std::endl;
+
+	IntervalLimiter m_profiler_interval;
 
 	for(;;)
 	{
 		// This is kind of a hack but can be done like this
 		// because server.step() is very light
-		sleep_ms(30);
+		{
+			ScopeProfiler sp(&g_profiler, "dedicated server sleep");
+			sleep_ms(30);
+		}
 		server.step(0.030);
 
 		if(server.getShutdownRequested() || kill)
 		{
-			std::cout<<DTIME<<" dedicated_server_loop(): Quitting."<<std::endl;
+			dstream<<DTIME<<" dedicated_server_loop(): Quitting."<<std::endl;
 			break;
 		}
 
+		/*
+			Profiler
+		*/
+		float profiler_print_interval =
+				g_settings.getFloat("profiler_print_interval");
+		if(profiler_print_interval != 0)
+		{
+			if(m_profiler_interval.step(0.030, profiler_print_interval))
+			{
+				dstream<<"Profiler:"<<std::endl;
+				g_profiler.print(dstream);
+				g_profiler.clear();
+			}
+		}
+		
+		/*
+			Player info
+		*/
 		static int counter = 0;
 		counter--;
 		if(counter <= 0)
@@ -4562,10 +4661,10 @@ void dedicated_server_loop(Server &server, bool &kill)
 			u32 sum = PIChecksum(list);
 			if(sum != sum_old)
 			{
-				std::cout<<DTIME<<"Player info:"<<std::endl;
+				dstream<<DTIME<<"Player info:"<<std::endl;
 				for(i=list.begin(); i!=list.end(); i++)
 				{
-					i->PrintLine(&std::cout);
+					i->PrintLine(&dstream);
 				}
 			}
 			sum_old = sum;
diff --git a/src/server.h b/src/server.h
index 7b73e476c..6bee10685 100644
--- a/src/server.h
+++ b/src/server.h
@@ -500,6 +500,15 @@ private:
 	// When called, connection mutex should be locked
 	RemoteClient* getClient(u16 peer_id);
 	
+	// When called, environment mutex should be locked
+	std::string getPlayerName(u16 peer_id)
+	{
+		Player *player = m_env.getPlayer(peer_id);
+		if(player == NULL)
+			return "[id="+itos(peer_id);
+		return player->getName();
+	}
+
 	/*
 		Get a player from memory or creates one.
 		If player is already connected, return NULL
@@ -627,6 +636,8 @@ private:
 	*/
 	u16 m_ignore_map_edit_events_peer_id;
 
+	Profiler *m_profiler;
+
 	friend class EmergeThread;
 	friend class RemoteClient;
 };
diff --git a/src/utility.h b/src/utility.h
index f18d31278..534aea483 100644
--- a/src/utility.h
+++ b/src/utility.h
@@ -244,6 +244,9 @@ inline f32 readF1000(std::istream &is)
 {
 	char buf[2];
 	is.read(buf, 2);
+	// TODO: verify if this gets rid of the valgrind warning
+	//if(is.gcount() != 2)
+	//	return 0;
 	return readF1000((u8*)buf);
 }