Logging cleanup

AI/VCAI/VCAI.cpp

@@ -2929,7 +2929,7 @@ void AIStatus::addQuery(QueryID ID, std::string description)
 {
 	if(ID == QueryID(-1))
 	{
-		logAi->debugStream() << boost::format("The \"query\" has an id %d, it'll be ignored as non-query. Description: %s") % ID % description;
+		logAi->debug("The \"query\" has an id %d, it'll be ignored as non-query. Description: %s", ID, description);
 		return;
 	}
 
@@ -2941,7 +2941,7 @@ void AIStatus::addQuery(QueryID ID, std::string description)
 	remainingQueries[ID] = description;
 
 	cv.notify_all();
-	logAi->debugStream() << boost::format("Adding query %d - %s. Total queries count: %d") % ID % description % remainingQueries.size();
+	logAi->debug("Adding query %d - %s. Total queries count: %d", ID, description, remainingQueries.size());
 }
 
 void AIStatus::removeQuery(QueryID ID)
@@ -2953,7 +2953,7 @@ void AIStatus::removeQuery(QueryID ID)
 	remainingQueries.erase(ID);
 
 	cv.notify_all();
-	logAi->debugStream() << boost::format("Removing query %d - %s. Total queries count: %d") % ID % description % remainingQueries.size();
+	logAi->debug("Removing query %d - %s. Total queries count: %d", ID,description , remainingQueries.size());
 }
 
 int AIStatus::getQueriesCount()
@@ -2994,7 +2994,7 @@ void AIStatus::attemptedAnsweringQuery(QueryID queryID, int answerRequestID)
 	boost::unique_lock<boost::mutex> lock(mx);
 	assert(vstd::contains(remainingQueries, queryID));
 	std::string description = remainingQueries[queryID];
-	logAi->debugStream() << boost::format("Attempted answering query %d - %s. Request id=%d. Waiting for results...") % queryID % description % answerRequestID;
+	logAi->debug("Attempted answering query %d - %s. Request id=%d. Waiting for results...", queryID, description, answerRequestID);
 	requestToQueryID[answerRequestID] = queryID;
 }
 
@@ -3011,7 +3011,7 @@ void AIStatus::receivedAnswerConfirmation(int answerRequestID, int result)
 	}
 	else
 	{
-		logAi->errorStream() << "Something went really wrong, failed to answer query " << query << ": " << remainingQueries[query];
+		logAi->error("Something went really wrong, failed to answer query %d : %s", query.getNum(), remainingQueries[query]);
 		//TODO safely retry
 	}
 }
@@ -3490,7 +3490,7 @@ int3 SectorMap::findFirstVisitableTile (HeroPtr h, crint3 dst)
 		if(topObj && topObj->ID == Obj::HERO && topObj != h.h &&
 			cb->getPlayerRelations(h->tempOwner, topObj->tempOwner) != PlayerRelations::ENEMIES)
 		{
-			logAi->warnStream() << ("Another allied hero stands in our way");
+			logAi->warn("Another allied hero stands in our way");
 			return ret;
 		}
 		if(ai->myCb->getPathsInfo(h.get())->getPathInfo(curtile)->reachable())

CCallback.cpp

@@ -93,7 +93,7 @@ bool CCallback::upgradeCreature(const CArmedInstance *obj, SlotID stackPos, Crea
 
 void CCallback::endTurn()
 {
-	logGlobal->traceStream() << "Player " << *player << " ended his turn.";
+	logGlobal->trace("Player %d ended his turn.", player.get().getNum());
 	EndTurn pack;
 	sendRequest(&pack); //report that we ended turn
 }

client/CMT.cpp

@@ -169,7 +169,7 @@ void init()
 	loadDLLClasses();
 	const_cast<CGameInfo*>(CGI)->setFromLib();
 
-	logGlobal->infoStream()<<"Initializing VCMI_Lib: "<<tmh.getDiff();
+	logGlobal->info("Initializing VCMI_Lib: %d ms", tmh.getDiff());
 
 
 	if(!settings["session"]["headless"].Bool())
@@ -180,15 +180,15 @@ void init()
 
 		CCS->curh->initCursor();
 		CCS->curh->show();
-		logGlobal->infoStream()<<"Screen handler: "<<pomtime.getDiff();
+		logGlobal->info("Screen handler: %d ms", pomtime.getDiff());
 		pomtime.getDiff();
 
 		graphics->load();
-		logGlobal->infoStream()<<"\tMain graphics: "<<pomtime.getDiff();
-		logGlobal->infoStream()<<"Initializing game graphics: "<<tmh.getDiff();
+		logGlobal->info("\tMain graphics: %d ms", pomtime.getDiff());
+		logGlobal->info("Initializing game graphics: %d ms", tmh.getDiff());
 
 		CMessage::init();
-		logGlobal->infoStream()<<"Message handler: "<<tmh.getDiff();
+		logGlobal->info("Message handler: %d ms", tmh.getDiff());
 	}
 }
 
@@ -321,7 +321,7 @@ int main(int argc, char * argv[])
 	CBasicLogConfigurator logConfig(logPath, console);
 	logConfig.configureDefault();
 	logGlobal->infoStream() << NAME;
-	logGlobal->infoStream() << "Creating console and configuring logger: " << pomtime.getDiff();
+	logGlobal->info("Creating console and configuring logger: %d ms", pomtime.getDiff());
 	logGlobal->infoStream() << "The log file will be saved to " << logPath;
 
 	// Init filesystem and settings
@@ -370,7 +370,7 @@ int main(int argc, char * argv[])
 	testFile("SOUNDS/G1A.WAV", "campaign music"); //technically not a music but voiced intro sounds
 
 	conf.init();
-	logGlobal->infoStream() << "Loading settings: " << pomtime.getDiff();
+	logGlobal->info("Loading settings: %d ms", pomtime.getDiff());
 
 	srand ( time(nullptr) );
 
@@ -453,7 +453,7 @@ int main(int argc, char * argv[])
 		}
 
 		setScreenRes(res["width"].Float(), res["height"].Float(), video["bitsPerPixel"].Float(), video["fullscreen"].Bool(), video["displayIndex"].Float());
-		logGlobal->infoStream() <<"\tInitializing screen: "<<pomtime.getDiff();
+		logGlobal->info("\tInitializing screen: %d ms", pomtime.getDiff());
 	}
 
 	CCS = new CClientState();
@@ -468,7 +468,7 @@ int main(int argc, char * argv[])
 		CCS->videoh = new CEmptyVideoPlayer();
 #endif
 
-	logGlobal->infoStream()<<"\tInitializing video: "<<pomtime.getDiff();
+	logGlobal->info("\tInitializing video: %d ms", pomtime.getDiff());
 
 	//initializing audio
 	CCS->soundh = new CSoundHandler();
@@ -477,7 +477,7 @@ int main(int argc, char * argv[])
 	CCS->musich = new CMusicHandler();
 	CCS->musich->init();
 	CCS->musich->setVolume(settings["general"]["music"].Float());
-	logGlobal->infoStream()<<"Initializing screen and sound handling: "<<pomtime.getDiff();
+	logGlobal->info("Initializing screen and sound handling: %d ms", pomtime.getDiff());
 
 #ifdef __APPLE__
 	// Ctrl+click should be treated as a right click on Mac OS X
@@ -511,7 +511,7 @@ int main(int argc, char * argv[])
 	}
 	#endif // ANDROID
 #endif // THREADED
-	logGlobal->infoStream()<<"Initialization of VCMI (together): "<<total.getDiff();
+	logGlobal->info("Initialization of VCMI (together): %d ms", total.getDiff());
 
 	session["autoSkip"].Bool()  = vm.count("autoSkip");
 	session["oneGoodAI"].Bool() = vm.count("oneGoodAI");

client/CPlayerInterface.cpp

@@ -1376,8 +1376,7 @@ template <typename Handler> void CPlayerInterface::serializeTempl( Handler &h, c
 				CGPath path;
 				cb->getPathsInfo(p.first)->getPath(path, p.second);
 				paths[p.first] = path;
-				logGlobal->traceStream() << boost::format("Restored path for hero %s leading to %s with %d nodes")
-					% p.first->nodeName() % p.second % path.nodes.size();
+				logGlobal->trace("Restored path for hero %s leading to %s with %d nodes", p.first->nodeName(), p.second , path.nodes.size());
 			}
 	}
 

client/Client.cpp

@@ -189,7 +189,7 @@ void CClient::run()
 	catch (const boost::system::system_error& e)
 	{
 		logNetwork->error("Lost connection to server, ending listening thread!");
-		logNetwork->errorStream() << e.what();
+		logNetwork->error(e.what());
 		if(!terminate) //rethrow (-> boom!) only if closing connection was unexpected
 		{
 			logNetwork->error("Something wrong, lost connection while game is still ongoing...");
@@ -292,12 +292,12 @@ void CClient::loadGame(const std::string & fname, const bool server, const std::
 			loadCommonState(checkingLoader);
 			loader = checkingLoader.decay();
 		}
-		logNetwork->infoStream() << "Loaded common part of save " << tmh.getDiff();
+		logNetwork->info("Loaded common part of save %d ms", tmh.getDiff());
 		const_cast<CGameInfo*>(CGI)->mh = new CMapHandler();
 		const_cast<CGameInfo*>(CGI)->mh->map = gs->map;
 		pathInfo = make_unique<CPathsInfo>(getMapSize());
 		CGI->mh->init();
-		logNetwork->infoStream() <<"Initing maphandler: "<<tmh.getDiff();
+		logNetwork->info("Initing maphandler: %d ms", tmh.getDiff());
 	}
 	catch(std::exception &e)
 	{
@@ -354,9 +354,9 @@ void CClient::loadGame(const std::string & fname, const bool server, const std::
 	serv->addStdVecItems(gs); /*why is this here?*/
 
     //*loader >> *this;
-	logNetwork->infoStream() << "Loaded client part of save " << tmh.getDiff();
+	logNetwork->info("Loaded client part of save %d ms", tmh.getDiff());
 
-	logNetwork->infoStream() <<"Sent info to server: "<<tmh.getDiff();
+	logNetwork->info("Sent info to server: %d ms", tmh.getDiff());
 
     //*serv << clientPlayers;
 	serv->enableStackSendingByID();
@@ -405,7 +405,7 @@ void CClient::newGame( CConnection *con, StartInfo *si )
 	}
 
 	c >> si;
-	logNetwork->infoStream() <<"\tSending/Getting info to/from the server: "<<tmh.getDiff();
+	logNetwork->info("\tSending/Getting info to/from the server: %d ms", tmh.getDiff());
 	c.enableStackSendingByID();
 	c.disableSmartPointerSerialization();
 
@@ -414,7 +414,7 @@ void CClient::newGame( CConnection *con, StartInfo *si )
 	logNetwork->info("\tCreating gamestate: %i",tmh.getDiff());
 
 	gs->init(si, settings["general"]["saveRandomMaps"].Bool());
-	logNetwork->infoStream() <<"Initializing GameState (together): "<<tmh.getDiff();
+	logNetwork->info("Initializing GameState (together): %d ms", tmh.getDiff());
 
 	// Now after possible random map gen, we know exact player count.
 	// Inform server about how many players client handles
@@ -439,11 +439,11 @@ void CClient::newGame( CConnection *con, StartInfo *si )
 		{
 			const_cast<CGameInfo*>(CGI)->mh = new CMapHandler();
 			CGI->mh->map = gs->map;
-			logNetwork->infoStream() << "Creating mapHandler: " << tmh.getDiff();
+			logNetwork->info("Creating mapHandler: %d ms", tmh.getDiff());
 			CGI->mh->init();
 		}
 		pathInfo = make_unique<CPathsInfo>(getMapSize());
-		logNetwork->infoStream() << "Initializing mapHandler (together): " << tmh.getDiff();
+		logNetwork->info("Initializing mapHandler (together): %d ms", tmh.getDiff());
 	}
 
 	int humanPlayers = 0;
@@ -994,7 +994,7 @@ void CServerHandler::startServer()
 	serverThread = new boost::thread(&CServerHandler::callServer, this); //runs server executable;
 #endif
 	if(verbose)
-		logNetwork->infoStream() << "Setting up thread calling server: " << th.getDiff();
+		logNetwork->info("Setting up thread calling server: %d ms", th.getDiff());
 }
 
 void CServerHandler::waitForServer()
@@ -1021,7 +1021,7 @@ void CServerHandler::waitForServer()
 	androidTestServerReadyFlag = false;
 #endif
 	if(verbose)
-		logNetwork->infoStream() << "Waiting for server: " << th.getDiff();
+		logNetwork->info("Waiting for server: %d ms", th.getDiff());
 }
 
 CConnection * CServerHandler::connectToServer()
@@ -1037,7 +1037,7 @@ CConnection * CServerHandler::connectToServer()
 #endif
 
 	if(verbose)
-		logNetwork->infoStream()<<"\tConnecting to the server: "<<th.getDiff();
+		logNetwork->info("\tConnecting to the server: %d ms", th.getDiff());
 
 	return ret;
 }

client/battle/CBattleAnimations.cpp

@@ -371,7 +371,7 @@ bool CMeleeAttackAnimation::init()
 CMeleeAttackAnimation::CMeleeAttackAnimation(CBattleInterface * _owner, const CStack * attacker, BattleHex _dest, const CStack * _attacked)
 : CAttackAnimation(_owner, attacker, _dest, _attacked)
 {
-	logAnim->debugStream() << "Created melee attack anim for " << attacker->getName();
+	logAnim->debug("Created melee attack anim for %s", attacker->getName());
 }
 
 void CMeleeAttackAnimation::endAnim()
@@ -529,13 +529,13 @@ CMovementAnimation::CMovementAnimation(CBattleInterface *_owner, const CStack *_
       progress(0.0),
       nextHex(destTiles.front())
 {
-	logAnim->debugStream() << "Created movement anim for " << stack->getName();
+	logAnim->debug("Created movement anim for %s", stack->getName());
 }
 
 CMovementEndAnimation::CMovementEndAnimation(CBattleInterface * _owner, const CStack * _stack, BattleHex destTile)
 : CBattleStackAnimation(_owner, _stack), destinationTile(destTile)
 {
-	logAnim->debugStream() << "Created movement end anim for " << stack->getName();
+	logAnim->debug("Created movement end anim for %s", stack->getName());
 }
 
 bool CMovementEndAnimation::init()
@@ -574,7 +574,7 @@ void CMovementEndAnimation::endAnim()
 CMovementStartAnimation::CMovementStartAnimation(CBattleInterface * _owner, const CStack * _stack)
 : CBattleStackAnimation(_owner, _stack)
 {
-	logAnim->debugStream() << "Created movement start anim for " << stack->getName();
+	logAnim->debug("Created movement start anim for %s", stack->getName());
 }
 
 bool CMovementStartAnimation::init()
@@ -606,7 +606,7 @@ void CMovementStartAnimation::endAnim()
 CReverseAnimation::CReverseAnimation(CBattleInterface * _owner, const CStack * stack, BattleHex dest, bool _priority)
 : CBattleStackAnimation(_owner, stack), hex(dest), priority(_priority)
 {
-	logAnim->debugStream() << "Created reverse anim for " << stack->getName();
+	logAnim->debug("Created reverse anim for %s", stack->getName());
 }
 
 bool CReverseAnimation::init()
@@ -670,7 +670,7 @@ void CReverseAnimation::setupSecondPart()
 CShootingAnimation::CShootingAnimation(CBattleInterface * _owner, const CStack * attacker, BattleHex _dest, const CStack * _attacked, bool _catapult, int _catapultDmg)
 : CAttackAnimation(_owner, attacker, _dest, _attacked), catapultDamage(_catapultDmg)
 {
-	logAnim->debugStream() << "Created shooting anim for " << stack->getName();
+	logAnim->debug("Created shooting anim for %s", stack->getName());
 }
 
 bool CShootingAnimation::init()

client/mapHandler.cpp

@@ -382,9 +382,9 @@ void CMapHandler::init()
 	prepareFOWDefs();
 	initTerrainGraphics();
 	initBorderGraphics();
-	logGlobal->infoStream()<<"\tPreparing FoW, terrain, roads, rivers, borders: "<<th.getDiff();
+	logGlobal->info("\tPreparing FoW, terrain, roads, rivers, borders: %d ms", th.getDiff());
 	initObjectRects();
-	logGlobal->infoStream()<<"\tMaking object rects: "<<th.getDiff();
+	logGlobal->info("\tMaking object rects: %d ms", th.getDiff());
 }
 
 CMapHandler::CMapBlitter *CMapHandler::resolveBlitter(const MapDrawingInfo * info) const

lib/CPathfinder.cpp

@@ -95,7 +95,7 @@ void CPathfinder::calculatePaths()
 		return false;
 	};
 
-	//logGlobal->infoStream() << boost::format("Calculating paths for hero %s (adress  %d) of player %d") % hero->name % hero % hero->tempOwner;
+	//logGlobal->info("Calculating paths for hero %s (adress  %d) of player %d", hero->name, hero , hero->tempOwner);
 
 	//initial tile - set cost on 0 and add to the queue
 	CGPathNode * initialNode = out.getNode(out.hpos, hero->boat ? ELayer::SAIL : ELayer::LAND);

lib/VCMI_Lib.cpp

@@ -63,24 +63,24 @@ void LibClasses::loadFilesystem()
 	CStopWatch loadTime;
 
 	CResourceHandler::initialize();
-	logGlobal->infoStream()<<"\tInitialization: "<<loadTime.getDiff();
+	logGlobal->info("\tInitialization: %d ms", loadTime.getDiff());
 
 	CResourceHandler::load("config/filesystem.json");
-	logGlobal->infoStream()<<"\tData loading: "<<loadTime.getDiff();
+	logGlobal->info("\tData loading: %d ms", loadTime.getDiff());
 
 	modh = new CModHandler();
-	logGlobal->infoStream()<<"\tMod handler: "<<loadTime.getDiff();
+	logGlobal->info("\tMod handler: %d ms", loadTime.getDiff());
 
 	modh->loadMods();
 	modh->loadModFilesystems();
-	logGlobal->infoStream()<<"\tMod filesystems: "<<loadTime.getDiff();
+	logGlobal->info("\tMod filesystems: %d ms", loadTime.getDiff());
 
-	logGlobal->infoStream()<<"Basic initialization: "<<totalTime.getDiff();
+	logGlobal->info("Basic initialization: %d ms", totalTime.getDiff());
 }
 
-static void logHandlerLoaded(const std::string& name, CStopWatch &timer)
+static void logHandlerLoaded(const std::string & name, CStopWatch & timer)
 {
-   logGlobal->infoStream()<<"\t\t" << name << " handler: "<<timer.getDiff();
+   logGlobal->info("\t\t %s handler: %d ms", name, timer.getDiff());
 }
 
 template <class Handler> void createHandler(Handler *&handler, const std::string &name, CStopWatch &timer)
@@ -117,7 +117,7 @@ void LibClasses::init()
 
 	createHandler(tplh, "Template", pomtime); //templates need already resolved identifiers (refactor?)
 
-	logGlobal->infoStream()<<"\tInitializing handlers: "<< totalTime.getDiff();
+	logGlobal->info("\tInitializing handlers: %d ms", totalTime.getDiff());
 
 	modh->load();
 

lib/mapObjects/MiscObjects.cpp

@@ -2121,8 +2121,7 @@ void CGObelisk::setPropertyDer( ui8 what, ui32 val )
 			{
 				assert(val < PlayerColor::PLAYER_LIMIT_I);
 				auto progress = ++visited[TeamID(val)];
-				logGlobal->debugStream() << boost::format("Player %d: obelisk progress %d / %d")
-					% val % static_cast<int>(progress) % static_cast<int>(obeliskCount);
+				logGlobal->debug("Player %d: obelisk progress %d / %d", val, static_cast<int>(progress) , static_cast<int>(obeliskCount));
 
 				if(progress > obeliskCount)
 				{

lib/rmg/CRmgTemplateZone.cpp

@@ -742,7 +742,7 @@ do not leave zone border
 		if (!(result || distance < lastDistance || anotherPos.valid()))
 		{
 			//FIXME: seemingly this condition is messed up, tells nothing
-			//logGlobal->warnStream() << boost::format("No tile closer than %s found on path from %s to %s") % currentPos %src %dst;
+			//logGlobal->warn("No tile closer than %s found on path from %s to %s", currentPos, src , dst);
 			break;
 		}
 	}

lib/rmg/CZonePlacer.cpp

@@ -134,7 +134,7 @@ void CZonePlacer::placeZones(const CMapGenOptions * mapGenOptions, CRandomGenera
 				improvement = true;
 		}
 
-		logGlobal->traceStream() << boost::format("Total distance between zones after this iteration: %2.4f, Total overlap: %2.4f, Improved: %s") % totalDistance % totalOverlap % improvement;
+		logGlobal->trace("Total distance between zones after this iteration: %2.4f, Total overlap: %2.4f, Improved: %s", totalDistance, totalOverlap , improvement);
 
 		//save best solution
 		if (improvement)

lib/serializer/BinaryDeserializer.cpp

@@ -57,7 +57,7 @@ void CLoadFile::openNextFile(const boost::filesystem::path & fname, int minimalV
 
 		if(serializer.fileVersion > SERIALIZATION_VERSION)
 		{
-			logGlobal->warnStream() << boost::format("Warning format version mismatch: found %d when current is %d! (file %s)\n") % serializer.fileVersion % SERIALIZATION_VERSION % fName;
+			logGlobal->warn("Warning format version mismatch: found %d when current is %d! (file %s)\n", serializer.fileVersion, SERIALIZATION_VERSION , fName);
 
 			auto versionptr = (char*)&serializer.fileVersion;
 			std::reverse(versionptr, versionptr + 4);