Overall improvements to log messages (#9598)

Hide some unnecessarily verbose ones behind --trace or disable them entirely.
Remove duplicate ones. Improve their contents in some places.

src/client/client.cpp

@@ -60,6 +60,20 @@ with this program; if not, write to the Free Software Foundation, Inc.,
 
 extern gui::IGUIEnvironment* guienv;
 
+/*
+	Utility classes
+*/
+
+void PacketCounter::print(std::ostream &o) const
+{
+	for (const auto &it : m_packets) {
+		auto name = it.first >= TOCLIENT_NUM_MSG_TYPES ? "?"
+			: toClientCommandTable[it.first].name;
+		o << "cmd " << it.first << " (" << name << ") count "
+			<< it.second << std::endl;
+	}
+}
+
 /*
 	Client
 */
@@ -336,12 +350,12 @@ void Client::step(float dtime)
 	{
 		float &counter = m_packetcounter_timer;
 		counter -= dtime;
-		if(counter <= 0.0)
+		if(counter <= 0.0f)
 		{
-			counter = 20.0;
+			counter = 30.0f;
 
 			infostream << "Client packetcounter (" << m_packetcounter_timer
-					<< "):"<<std::endl;
+					<< "s):"<<std::endl;
 			m_packetcounter.print(infostream);
 			m_packetcounter.clear();
 		}
@@ -621,14 +635,17 @@ void Client::step(float dtime)
 
 	m_mod_storage_save_timer -= dtime;
 	if (m_mod_storage_save_timer <= 0.0f) {
-		verbosestream << "Saving registered mod storages." << std::endl;
 		m_mod_storage_save_timer = g_settings->getFloat("server_map_save_interval");
+		int n = 0;
 		for (std::unordered_map<std::string, ModMetadata *>::const_iterator
 				it = m_mod_storages.begin(); it != m_mod_storages.end(); ++it) {
 			if (it->second->isModified()) {
 				it->second->save(getModStoragePath());
+				n++;
 			}
 		}
+		if (n > 0)
+			infostream << "Saved " << n << " modified mod storages." << std::endl;
 	}
 
 	// Write server map
@@ -653,8 +670,8 @@ bool Client::loadMedia(const std::string &data, const std::string &filename)
 	};
 	name = removeStringEnd(filename, image_ext);
 	if (!name.empty()) {
-		verbosestream<<"Client: Attempting to load image "
-		<<"file \""<<filename<<"\""<<std::endl;
+		TRACESTREAM(<< "Client: Attempting to load image "
+			<< "file \"" << filename << "\"" << std::endl);
 
 		io::IFileSystem *irrfs = RenderingEngine::get_filesystem();
 		video::IVideoDriver *vdrv = RenderingEngine::get_video_driver();
@@ -687,10 +704,9 @@ bool Client::loadMedia(const std::string &data, const std::string &filename)
 	};
 	name = removeStringEnd(filename, sound_ext);
 	if (!name.empty()) {
-		verbosestream<<"Client: Attempting to load sound "
-		<<"file \""<<filename<<"\""<<std::endl;
-		m_sound->loadSoundData(name, data);
-		return true;
+		TRACESTREAM(<< "Client: Attempting to load sound "
+			<< "file \"" << filename << "\"" << std::endl);
+		return m_sound->loadSoundData(name, data);
 	}
 
 	const char *model_ext[] = {
@@ -714,8 +730,8 @@ bool Client::loadMedia(const std::string &data, const std::string &filename)
 	};
 	name = removeStringEnd(filename, translate_ext);
 	if (!name.empty()) {
-		verbosestream << "Client: Loading translation: "
-				<< "\"" << filename << "\"" << std::endl;
+		TRACESTREAM(<< "Client: Loading translation: "
+				<< "\"" << filename << "\"" << std::endl);
 		g_translations->loadTranslation(data);
 		return true;
 	}

src/client/client.h

@@ -82,30 +82,19 @@ class PacketCounter
 
 	void add(u16 command)
 	{
-		std::map<u16, u16>::iterator n = m_packets.find(command);
-		if(n == m_packets.end())
-		{
+		auto n = m_packets.find(command);
+		if (n == m_packets.end())
 			m_packets[command] = 1;
-		}
 		else
-		{
 			n->second++;
-		}
 	}
 
 	void clear()
 	{
-		for (auto &m_packet : m_packets) {
-			m_packet.second = 0;
-		}
+		m_packets.clear();
 	}
 
-	void print(std::ostream &o)
-	{
-		for (const auto &m_packet : m_packets) {
-			o << "cmd "<< m_packet.first <<" count "<< m_packet.second << std::endl;
-		}
-	}
+	void print(std::ostream &o) const;
 
 private:
 	// command, count

src/client/content_cao.cpp

@@ -576,9 +576,10 @@ void GenericCAO::addToScene(ITextureSource *tsrc)
 
 	m_visuals_expired = false;
 
-	if (!m_prop.is_visible) {
+	if (!m_prop.is_visible)
 		return;
-	}
+
+	infostream << "GenericCAO::addToScene(): " << m_prop.visual << std::endl;
 
 	if (m_enable_shaders) {
 		IShaderSource *shader_source = m_client->getShaderSource();
@@ -593,7 +594,6 @@ void GenericCAO::addToScene(ITextureSource *tsrc)
 	}
 
 	auto grabMatrixNode = [this] {
-		infostream << "GenericCAO::addToScene(): " << m_prop.visual << std::endl;
 		m_matrixnode = RenderingEngine::get_scene_manager()->
 				addDummyTransformationSceneNode();
 		m_matrixnode->grab();

src/client/fontengine.cpp

@@ -239,7 +239,7 @@ void FontEngine::updateSkin()
 	FATAL_ERROR_IF(font == NULL, "Could not create/get font");
 
 	u32 text_height = font->getDimension(L"Hello, world!").Height;
-	infostream << "text_height=" << text_height << std::endl;
+	infostream << "FontEngine: measured text_height=" << text_height << std::endl;
 }
 
 /******************************************************************************/

src/client/game.cpp

@@ -2010,7 +2010,6 @@ void Game::processItemSelection(u16 *new_playeritem)
 	for (u16 i = 0; i <= max_item; i++) {
 		if (wasKeyDown((GameKeyType) (KeyType::SLOT_1 + i))) {
 			*new_playeritem = i;
-			infostream << "Selected item: " << new_playeritem << std::endl;
 			break;
 		}
 	}
@@ -2039,7 +2038,7 @@ void Game::openInventory()
 	if (!player || !player->getCAO())
 		return;
 
-	infostream << "the_game: " << "Launching inventory" << std::endl;
+	infostream << "Game: Launching inventory" << std::endl;
 
 	PlayerInventoryFormSource *fs_src = new PlayerInventoryFormSource(client);
 

src/client/renderingengine.cpp

@@ -226,27 +226,17 @@ bool RenderingEngine::setupTopLevelWindow(const std::string &name)
 {
 	// FIXME: It would make more sense for there to be a switch of some
 	// sort here that would call the correct toplevel setup methods for
-	// the environment Minetest is running in but for now not deviating
-	// from the original pattern.
+	// the environment Minetest is running in.
 
 	/* Setting Xorg properties for the top level window */
 	setupTopLevelXorgWindow(name);
-	/* Done with Xorg properties */
 
 	/* Setting general properties for the top level window */
 	verbosestream << "Client: Configuring general top level"
 		<< " window properties"
 		<< std::endl;
-
 	bool result = setWindowIcon();
 
-	verbosestream << "Client: Finished configuring general top level"
-		<< " window properties"
-		<< std::endl;
-	/* Done with general properties */
-
-	// FIXME: setWindowIcon returns a bool result but it is unused.
-	// For now continue to return this result.
 	return result;
 }
 
@@ -262,7 +252,7 @@ void RenderingEngine::setupTopLevelXorgWindow(const std::string &name)
 		return;
 	}
 
-	verbosestream << "Client: Configuring Xorg specific top level"
+	verbosestream << "Client: Configuring X11-specific top level"
 		<< " window properties"
 		<< std::endl;
 
@@ -309,8 +299,6 @@ void RenderingEngine::setupTopLevelXorgWindow(const std::string &name)
 	Atom NET_WM_PID = XInternAtom(x11_dpl, "_NET_WM_PID", false);
 
 	pid_t pid = getpid();
-	infostream << "Client: PID is '" << static_cast<long>(pid) << "'"
-		<< std::endl;
 
 	XChangeProperty(x11_dpl, x11_win, NET_WM_PID,
 			XA_CARDINAL, 32, PropModeReplace,
@@ -327,10 +315,6 @@ void RenderingEngine::setupTopLevelXorgWindow(const std::string &name)
 	XChangeProperty (x11_dpl, x11_win, WM_CLIENT_LEADER,
 		XA_WINDOW, 32, PropModeReplace,
 		reinterpret_cast<unsigned char *>(&x11_win), 1);
-
-	verbosestream << "Client: Finished configuring Xorg specific top level"
-		<< " window properties"
-		<< std::endl;
 #endif
 }
 

src/client/sound_openal.cpp

@@ -165,8 +165,8 @@ SoundBuffer *load_opened_ogg_file(OggVorbis_File *oggFile,
 				<< "preparing sound buffer" << std::endl;
 	}
 
-	infostream << "Audio file "
-		<< filename_for_logging << " loaded" << std::endl;
+	//infostream << "Audio file "
+	//	<< filename_for_logging << " loaded" << std::endl;
 
 	// Clean up!
 	ov_clear(oggFile);
@@ -498,9 +498,11 @@ class OpenALSoundManager: public ISoundManager
 	// Remove stopped sounds
 	void maintain()
 	{
-		verbosestream<<"OpenALSoundManager::maintain(): "
-				<<m_sounds_playing.size()<<" playing sounds, "
-				<<m_buffers.size()<<" sound names loaded"<<std::endl;
+		if (!m_sounds_playing.empty()) {
+			verbosestream << "OpenALSoundManager::maintain(): "
+					<< m_sounds_playing.size() <<" playing sounds, "
+					<< m_buffers.size() <<" sound names loaded"<<std::endl;
+		}
 		std::unordered_set<int> del_list;
 		for (const auto &sp : m_sounds_playing) {
 			int id = sp.first;
@@ -530,7 +532,7 @@ class OpenALSoundManager: public ISoundManager
 		SoundBuffer *buf = load_ogg_from_file(filepath);
 		if (buf)
 			addBuffer(name, buf);
-		return false;
+		return !!buf;
 	}
 
 	bool loadSoundData(const std::string &name,
@@ -539,7 +541,7 @@ class OpenALSoundManager: public ISoundManager
 		SoundBuffer *buf = load_ogg_from_buffer(filedata, name);
 		if (buf)
 			addBuffer(name, buf);
-		return false;
+		return !!buf;
 	}
 
 	void updateListener(const v3f &pos, const v3f &vel, const v3f &at, const v3f &up)

src/client/tile.cpp

@@ -471,8 +471,8 @@ TextureSource::~TextureSource()
 		driver->removeTexture(t);
 	}
 
-	infostream << "~TextureSource() "<< textures_before << "/"
-			<< driver->getTextureCount() << std::endl;
+	infostream << "~TextureSource() before cleanup: "<< textures_before
+			<< " after: " << driver->getTextureCount() << std::endl;
 }
 
 u32 TextureSource::getTextureId(const std::string &name)
@@ -763,6 +763,9 @@ void TextureSource::rebuildImagesAndTextures()
 	video::IVideoDriver *driver = RenderingEngine::get_video_driver();
 	sanity_check(driver);
 
+	infostream << "TextureSource: recreating " << m_textureinfo_cache.size()
+		<< " textures" << std::endl;
+
 	// Recreate textures
 	for (TextureInfo &ti : m_textureinfo_cache) {
 		video::IImage *img = generateImage(ti.name);
@@ -1270,8 +1273,6 @@ bool TextureSource::generateImagePart(std::string part_of_name,
 				video::IImage *img = generateImage(filename);
 				if (img) {
 					core::dimension2d<u32> dim = img->getDimension();
-					infostream<<"Size "<<dim.Width
-							<<"x"<<dim.Height<<std::endl;
 					core::position2d<s32> pos_base(x, y);
 					video::IImage *img2 =
 							driver->createImage(video::ECF_A8R8G8B8, dim);

src/content/subgames.cpp

@@ -253,7 +253,7 @@ std::vector<WorldSpec> getAvailableWorlds()
 	worldspaths.insert(porting::path_user + DIR_DELIM + "worlds");
 	infostream << "Searching worlds..." << std::endl;
 	for (const std::string &worldspath : worldspaths) {
-		infostream << "  In " << worldspath << ": " << std::endl;
+		infostream << "  In " << worldspath << ": ";
 		std::vector<fs::DirListNode> dirvector = fs::GetDirListing(worldspath);
 		for (const fs::DirListNode &dln : dirvector) {
 			if (!dln.dir)

src/content_sao.cpp

@@ -711,13 +711,11 @@ float LuaEntitySAO::getMinimumSavedMovement()
 
 std::string LuaEntitySAO::getDescription()
 {
-	std::ostringstream os(std::ios::binary);
-	os<<"LuaEntitySAO at (";
-	os<<(m_base_position.X/BS)<<",";
-	os<<(m_base_position.Y/BS)<<",";
-	os<<(m_base_position.Z/BS);
-	os<<")";
-	return os.str();
+	std::ostringstream oss;
+	oss << "LuaEntitySAO \"" << m_init_name << "\" ";
+	auto pos = floatToInt(m_base_position, BS);
+	oss << "at " << PP(pos);
+	return oss.str();
 }
 
 void LuaEntitySAO::setHP(s32 hp, const PlayerHPChangeReason &reason)

src/craftdef.cpp

@@ -1066,8 +1066,8 @@ class CCraftDefManager: public IWritableCraftDefManager
 	}
 	virtual void registerCraft(CraftDefinition *def, IGameDef *gamedef)
 	{
-		verbosestream << "registerCraft: registering craft definition: "
-				<< def->dump() << std::endl;
+		TRACESTREAM(<< "registerCraft: registering craft definition: "
+				<< def->dump() << std::endl);
 		m_craft_defs[(int) CRAFT_HASH_TYPE_UNHASHED][0].push_back(def);
 
 		CraftInput input;

src/emerge.cpp

@@ -136,7 +136,6 @@ EmergeManager::EmergeManager(Server *server)
 		nthreads = Thread::getNumberOfProcessors() - 2;
 	if (nthreads < 1)
 		nthreads = 1;
-	verbosestream << "Using " << nthreads << " emerge threads." << std::endl;
 
 	m_qlimit_total = g_settings->getU16("emergequeue_limit_total");
 	if (!g_settings->getU16NoEx("emergequeue_limit_diskonly", m_qlimit_diskonly))

src/itemdef.cpp

@@ -463,7 +463,7 @@ class CItemDefManager: public IWritableItemDefManager
 	}
 	virtual void registerItem(const ItemDefinition &def)
 	{
-		verbosestream<<"ItemDefManager: registering \""<<def.name<<"\""<<std::endl;
+		TRACESTREAM(<< "ItemDefManager: registering " << def.name << std::endl);
 		// Ensure that the "" item (the hand) always has ToolCapabilities
 		if (def.name.empty())
 			FATAL_ERROR_IF(!def.tool_capabilities, "Hand does not have ToolCapabilities");
@@ -490,8 +490,8 @@ class CItemDefManager: public IWritableItemDefManager
 			const std::string &convert_to)
 	{
 		if (m_item_definitions.find(name) == m_item_definitions.end()) {
-			verbosestream<<"ItemDefManager: setting alias "<<name
-				<<" -> "<<convert_to<<std::endl;
+			TRACESTREAM(<< "ItemDefManager: setting alias " << name
+				<< " -> " << convert_to << std::endl);
 			m_aliases[name] = convert_to;
 		}
 	}