[Logging] Cleanup AI Logging Events (#2615)

common/eqemu_logsys_log_aliases.h

@@ -39,7 +39,7 @@
 } while (0)
 
 #define LogAIModerate(message, ...) do {\
-    if (LogSys.IsLogEnabled(Logs::General, Logs::AI))\
+    if (LogSys.IsLogEnabled(Logs::Moderate, Logs::AI))\
         OutF(LogSys, Logs::Moderate, Logs::AI, __FILE__, __func__, __LINE__, message, ##__VA_ARGS__);\
 } while (0)
 
@@ -584,6 +584,11 @@
         OutF(LogSys, Logs::General, Logs::AIScanClose, __FILE__, __func__, __LINE__, message, ##__VA_ARGS__);\
 } while (0)
 
+#define LogAIScanCloseModerate(message, ...) do {\
+    if (LogSys.IsLogEnabled(Logs::Moderate, Logs::AIScanClose))\
+        OutF(LogSys, Logs::Moderate, Logs::AIScanClose, __FILE__, __func__, __LINE__, message, ##__VA_ARGS__);\
+} while (0)
+
 #define LogAIScanCloseDetail(message, ...) do {\
     if (LogSys.IsLogEnabled(Logs::Detail, Logs::AIScanClose))\
         OutF(LogSys, Logs::Detail, Logs::AIScanClose, __FILE__, __func__, __LINE__, message, ##__VA_ARGS__);\
@@ -894,6 +899,9 @@
 #define LogAI(message, ...) do {\
 } while (0)
 
+#define LogAIModerate(message, ...) do {\
+} while (0)
+
 #define LogAIDetail(message, ...) do {\
 } while (0)
 
@@ -1146,6 +1154,9 @@
 #define LogAIScanClose(message, ...) do {\
 } while (0)
 
+#define LogAIScanCloseModerate(message, ...) do {\
+} while (0)
+
 #define LogAIScanCloseDetail(message, ...) do {\
 } while (0)
 

zone/bot.cpp

@@ -2135,7 +2135,7 @@ bool Bot::Process()
 	}
 
 	if (mob_close_scan_timer.Check()) {
-		LogAIScanClose(
+		LogAIScanCloseDetail(
 			"is_moving [{}] bot [{}] timer [{}]",
 			moving ? "true" : "false",
 			GetCleanName(),
@@ -9838,7 +9838,7 @@ void EntityList::ScanCloseClientMobs(std::unordered_map<uint16, Mob*>& close_mob
 		}
 	}
 
-	LogAIScanClose("Close Client Mob List Size [{}] for mob [{}]", close_mobs.size(), scanning_mob->GetCleanName());
+	LogAIScanCloseModerate("Close Client Mob List Size [{}] for mob [{}]", close_mobs.size(), scanning_mob->GetCleanName());
 }
 
 uint8 Bot::GetNumberNeedingHealedInGroup(uint8 hpr, bool includePets) {

zone/botspellsai.cpp

@@ -1165,7 +1165,7 @@ bool Bot::AIDoSpellCast(uint8 i, Mob* tar, int32 mana_cost, uint32* oDontDoAgain
 				|| dist2 <= GetActSpellRange(AIBot_spells[i].spellid, spells[AIBot_spells[i].spellid].range)*GetActSpellRange(AIBot_spells[i].spellid, spells[AIBot_spells[i].spellid].range)) && (mana_cost <= GetMana() || GetMana() == GetMaxMana()))
 	{
 		casting_spell_AIindex = i;
-		LogAIDetail("Bot::AIDoSpellCast: spellid = [{}], tar = [{}], mana = [{}], Name: [{}]", AIBot_spells[i].spellid, tar->GetName(), mana_cost, spells[AIBot_spells[i].spellid].name);
+		LogAIModerate("Bot::AIDoSpellCast: spellid = [{}], tar = [{}], mana = [{}], Name: [{}]", AIBot_spells[i].spellid, tar->GetName(), mana_cost, spells[AIBot_spells[i].spellid].name);
 		result = Mob::CastSpell(AIBot_spells[i].spellid, tar->GetID(), EQ::spells::CastingSlot::Gem2, spells[AIBot_spells[i].spellid].cast_time, AIBot_spells[i].manacost == -2 ? 0 : mana_cost, oDontDoAgainBefore, -1, -1, 0, &(AIBot_spells[i].resist_adjust));
 
 		if (IsCasting() && IsSitting())
@@ -1205,7 +1205,7 @@ bool Bot::AI_PursueCastCheck() {
 
 		AIautocastspell_timer->Disable();	//prevent the timer from going off AGAIN while we are casting.
 
-		LogAI("Bot Engaged (pursuing) autocast check triggered. Trying to cast offensive spells");
+		LogAIDetail("Bot Engaged (pursuing) autocast check triggered. Trying to cast offensive spells");
 
 		if (!AICastSpell(GetTarget(), 100, SpellType_Snare)) {
 			if (!AICastSpell(GetTarget(), 100, SpellType_Lifetap)) {
@@ -1233,7 +1233,7 @@ bool Bot::AI_IdleCastCheck() {
 
 	if (AIautocastspell_timer->Check(false)) {
 #if BotAI_DEBUG_Spells >= 25
-		LogAI("Bot Non-Engaged autocast check triggered: [{}]", GetCleanName());
+		LogAIDetail("Bot Non-Engaged autocast check triggered: [{}]", GetCleanName());
 #endif
 		AIautocastspell_timer->Disable();	//prevent the timer from going off AGAIN while we are casting.
 
@@ -1389,7 +1389,7 @@ bool Bot::AI_EngagedCastCheck() {
 		EQ::constants::StanceType botStance = GetBotStance();
 		bool mayGetAggro = HasOrMayGetAggro();
 
-		LogAI("Engaged autocast check triggered (BOTS). Trying to cast healing spells then maybe offensive spells");
+		LogAIDetail("Engaged autocast check triggered (BOTS). Trying to cast healing spells then maybe offensive spells");
 
 		if (botClass == CLERIC) {
 			if (!AICastSpell(GetTarget(), GetChanceToCastBySpellType(SpellType_Escape), SpellType_Escape)) {
@@ -1714,13 +1714,10 @@ bool Bot::AIHealRotation(Mob* tar, bool useFastHeals) {
 		}
 	}
 
-#if BotAI_DEBUG_Spells >= 10
+	LogAIModerate("Bot::AIHealRotation: heal spellid = [{}], fastheals = [{}], casterlevel = [{}]",
-	LogAI("Bot::AIHealRotation: heal spellid = [{}], fastheals = [{}], casterlevel = [{}]",
 		botSpell.SpellId, ((useFastHeals) ? ('T') : ('F')), GetLevel());
-#endif
+
-#if BotAI_DEBUG_Spells >= 25
+	LogAIDetail("Bot::AIHealRotation: target = [{}], current_time = [{}], donthealmebefore = [{}]", tar->GetCleanName(), Timer::GetCurrentTime(), tar->DontHealMeBefore());
-	LogAI("Bot::AIHealRotation: target = [{}], current_time = [{}], donthealmebefore = [{}]", tar->GetCleanName(), Timer::GetCurrentTime(), tar->DontHealMeBefore());
-#endif
 
 	// If there is still no spell id, then there isn't going to be one so we are done
 	if (botSpell.SpellId == 0)
@@ -2899,7 +2896,7 @@ bool Bot::AI_AddBotSpells(uint32 bot_spell_id) {
 	auto* parentlist = content_db.GetBotSpells(spell_list->parent_list);
 
 	auto debug_msg = fmt::format(
-		"Loading NPCSpells onto {}: dbspellsid={}, level={}",
+		"Loading Bot spells onto {}: dbspellsid={}, level={}",
 		GetName(),
 		bot_spell_id,
 		GetLevel()
@@ -2908,42 +2905,20 @@ bool Bot::AI_AddBotSpells(uint32 bot_spell_id) {
 	if (spell_list) {
 		debug_msg.append(
 			fmt::format(
-				" (found, {}), parentlist={}",
+				" (found, {})",
-				spell_list->entries.size(),
+				spell_list->entries.size()
-				spell_list->parent_list
 			)
 		);
 
-		if (spell_list->parent_list) {
+		LogAIModerate("[{}]", debug_msg);
-			if (parentlist) {
-				debug_msg.append(
-					fmt::format(
-						" (found, {})",
-						parentlist->entries.size()
-					)
-				);
-			} else {
-				debug_msg.append(" (not found)");
-			}
-		}
-	} else {
-		debug_msg.append(" (not found)");
-	}
-
-	LogAIDetail("[{}]", debug_msg);
-
-	if (parentlist) {
-		for (const auto &iter : parentlist->entries) {
-			LogAI("([{}]) [{}]", iter.spellid, spells[iter.spellid].name);
-		}
-	}
-
-	LogAIModerate("fin (parent list)");
-
-	if (spell_list) {
 		for (const auto &iter : spell_list->entries) {
 			LogAIDetail("([{}]) [{}]", iter.spellid, spells[iter.spellid].name);
 		}
+	} 
+	else 
+	{
+		debug_msg.append(" (not found)");
+		LogAIModerate("[{}]", debug_msg);
 	}
 
 	LogAIModerate("fin (spell list)");

zone/entity.cpp

@@ -2951,7 +2951,7 @@ void EntityList::ScanCloseMobs(
 		}
 	}
 
-	LogAIScanClose(
+	LogAIScanCloseModerate(
 		"[{}] Scanning Close List | list_size [{}] moving [{}]",
 		scanning_mob->GetCleanName(),
 		close_mobs.size(),

zone/spells.cpp

@@ -3457,7 +3457,7 @@ int Mob::CanBuffStack(uint16 spellid, uint8 caster_level, bool iFailIfOverwrite)
 {
 	int i, ret, firstfree = -2;
 
-	LogAI("Checking if buff [{}] cast at level [{}] can stack on me.[{}]", spellid, caster_level, iFailIfOverwrite?" failing if we would overwrite something":"");
+	LogAIModerate("Checking if buff [{}] cast at level [{}] can stack on me.[{}]", spellid, caster_level, iFailIfOverwrite?" failing if we would overwrite something":"");
 
 	int buff_count = GetMaxTotalSlots();
 	for (i=0; i < buff_count; i++)
@@ -3481,7 +3481,7 @@ int Mob::CanBuffStack(uint16 spellid, uint8 caster_level, bool iFailIfOverwrite)
 		if(ret == 1) {
 			// should overwrite current slot
 			if(iFailIfOverwrite) {
-				LogAI("Buff [{}] would overwrite [{}] in slot [{}], reporting stack failure", spellid, curbuf.spellid, i);
+				LogAIDetail("Buff [{}] would overwrite [{}] in slot [{}], reporting stack failure", spellid, curbuf.spellid, i);
 				return(-1);
 			}
 			if(firstfree == -2)
@@ -3489,12 +3489,12 @@ int Mob::CanBuffStack(uint16 spellid, uint8 caster_level, bool iFailIfOverwrite)
 		}
 		if(ret == -1) {
 
-			LogAI("Buff [{}] would conflict with [{}] in slot [{}], reporting stack failure", spellid, curbuf.spellid, i);
+			LogAIDetail("Buff [{}] would conflict with [{}] in slot [{}], reporting stack failure", spellid, curbuf.spellid, i);
 			return -1;	// stop the spell, can't stack it
 		}
 	}
 
-	LogAI("Reporting that buff [{}] could successfully be placed into slot [{}]", spellid, firstfree);
+	LogAIModerate("Reporting that buff [{}] could successfully be placed into slot [{}]", spellid, firstfree);
 
 	return firstfree;
 }

zone/waypoints.cpp

@@ -205,14 +205,14 @@ void NPC::MoveTo(const glm::vec4 &position, bool saveguardspot)
 	if (IsNPC() && GetGrid() != 0) {    // he is on a grid
 		if (GetGrid() < 0) {    // currently stopped by a quest command
 			SetGrid(0 - GetGrid());    // get him moving again
-			LogAI("MoveTo during quest wandering. Canceling quest wandering and going back to grid [{}] when MoveTo is done", GetGrid());
+			LogAIDetail("MoveTo during quest wandering. Canceling quest wandering and going back to grid [{}] when MoveTo is done", GetGrid());
 		}
 		AI_walking_timer->Disable();    // disable timer in case he is paused at a wp
 		if (cur_wp >= 0) {    // we've not already done a MoveTo()
 			save_wp = cur_wp;    // save the current waypoint
 			cur_wp  = EQ::WaypointStatus::QuestControlGrid;
 		}
-		LogAI("MoveTo [{}], pausing regular grid wandering. Grid [{}], save_wp [{}]",
+		LogAIDetail("MoveTo [{}], pausing regular grid wandering. Grid [{}], save_wp [{}]",
 			to_string(static_cast<glm::vec3>(position)).c_str(),
 			-GetGrid(),
 			save_wp);
@@ -221,7 +221,7 @@ void NPC::MoveTo(const glm::vec4 &position, bool saveguardspot)
 		roamer  = true;
 		save_wp = 0;
 		cur_wp  = EQ::WaypointStatus::QuestControlNoGrid;
-		LogAI("MoveTo [{}] without a grid", to_string(static_cast<glm::vec3>(position)).c_str());
+		LogAIDetail("MoveTo [{}] without a grid", to_string(static_cast<glm::vec3>(position)).c_str());
 	}
 
 	glm::vec3 dest(position);
@@ -239,7 +239,7 @@ void NPC::MoveTo(const glm::vec4 &position, bool saveguardspot)
 		if (m_GuardPoint.w == -1)
 			m_GuardPoint.w = CalculateHeadingToTarget(position.x, position.y);
 
-		LogAI("Setting guard position to [{}]", to_string(static_cast<glm::vec3>(m_GuardPoint)).c_str());
+		LogAIModerate("Setting guard position to [{}]", to_string(static_cast<glm::vec3>(m_GuardPoint)).c_str());
 	}
 
 	cur_wp_pause        = 0;
@@ -261,7 +261,7 @@ void NPC::UpdateWaypoint(int wp_index)
 
 	m_CurrentWayPoint = glm::vec4(cur->x, cur->y, cur->z, cur->heading);
 	cur_wp_pause = cur->pause;
-	LogAI("Next waypoint [{}]: ({}, {}, {}, {})", wp_index, m_CurrentWayPoint.x, m_CurrentWayPoint.y, m_CurrentWayPoint.z, m_CurrentWayPoint.w);
+	LogAIModerate("Next waypoint [{}]: ({}, {}, {}, {})", wp_index, m_CurrentWayPoint.x, m_CurrentWayPoint.y, m_CurrentWayPoint.z, m_CurrentWayPoint.w);
 
 }
 
@@ -559,7 +559,7 @@ void NPC::SetWaypointPause()
 
 void NPC::SaveGuardSpot(bool ClearGuardSpot) {
 	if (ClearGuardSpot) {
-		LogAI("Clearing guard order.");
+		LogAIModerate("Clearing guard order.");
 		m_GuardPoint = glm::vec4();
 	} else {
 		m_GuardPoint = m_Position;
@@ -712,7 +712,7 @@ void Mob::SendTo(float new_x, float new_y, float new_z) {
 	m_Position.x = new_x;
 	m_Position.y = new_y;
 	m_Position.z = new_z;
-	LogAI("Sent To ({}, {}, {})", new_x, new_y, new_z);
+	LogAIDetail("Sent To ({}, {}, {})", new_x, new_y, new_z);
 
 	if (flymode == GravityBehavior::Flying)
 		return;
@@ -728,7 +728,7 @@ void Mob::SendTo(float new_x, float new_y, float new_z) {
 
 			float newz = zone->zonemap->FindBestZ(dest, nullptr);
 
-			LogAI("BestZ returned {} at {}, {}, {}", newz, m_Position.x, m_Position.y, m_Position.z);
+			LogAIModerate("BestZ returned {} at {}, {}, {}", newz, m_Position.x, m_Position.y, m_Position.z);
 
 			if ((newz > -2000) && std::abs(newz - dest.z) < RuleR(Map, FixPathingZMaxDeltaSendTo)) // Sanity check.
 				m_Position.z = newz + 1;