From 318e487515e8f4a823a78f401dabf229f21f44e1 Mon Sep 17 00:00:00 2001 From: Aeadoin <109764533+Aeadoin@users.noreply.github.com> Date: Sun, 4 Dec 2022 14:22:53 -0500 Subject: [PATCH] [Logging] Cleanup AI Logging Events (#2615) --- common/eqemu_logsys_log_aliases.h | 13 ++++++- zone/bot.cpp | 4 +-- zone/botspellsai.cpp | 57 +++++++++---------------------- zone/entity.cpp | 2 +- zone/spells.cpp | 8 ++--- zone/waypoints.cpp | 16 ++++----- 6 files changed, 43 insertions(+), 57 deletions(-) diff --git a/common/eqemu_logsys_log_aliases.h b/common/eqemu_logsys_log_aliases.h index 927111f1f..9c3ab2f8e 100644 --- a/common/eqemu_logsys_log_aliases.h +++ b/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) diff --git a/zone/bot.cpp b/zone/bot.cpp index 50dc62e00..e750ecc16 100644 --- a/zone/bot.cpp +++ b/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& 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) { diff --git a/zone/botspellsai.cpp b/zone/botspellsai.cpp index ec8c87ff1..90c0dae7d 100644 --- a/zone/botspellsai.cpp +++ b/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 - LogAI("Bot::AIHealRotation: heal spellid = [{}], fastheals = [{}], casterlevel = [{}]", + LogAIModerate("Bot::AIHealRotation: heal spellid = [{}], fastheals = [{}], casterlevel = [{}]", botSpell.SpellId, ((useFastHeals) ? ('T') : ('F')), GetLevel()); -#endif -#if BotAI_DEBUG_Spells >= 25 - LogAI("Bot::AIHealRotation: target = [{}], current_time = [{}], donthealmebefore = [{}]", tar->GetCleanName(), Timer::GetCurrentTime(), tar->DontHealMeBefore()); -#endif + + LogAIDetail("Bot::AIHealRotation: target = [{}], current_time = [{}], donthealmebefore = [{}]", tar->GetCleanName(), Timer::GetCurrentTime(), tar->DontHealMeBefore()); // 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={}", - spell_list->entries.size(), - spell_list->parent_list + " (found, {})", + spell_list->entries.size() ) ); - if (spell_list->parent_list) { - 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) { + LogAIModerate("[{}]", debug_msg); 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)"); diff --git a/zone/entity.cpp b/zone/entity.cpp index bbf5f0878..f79e04838 100644 --- a/zone/entity.cpp +++ b/zone/entity.cpp @@ -2951,7 +2951,7 @@ void EntityList::ScanCloseMobs( } } - LogAIScanClose( + LogAIScanCloseModerate( "[{}] Scanning Close List | list_size [{}] moving [{}]", scanning_mob->GetCleanName(), close_mobs.size(), diff --git a/zone/spells.cpp b/zone/spells.cpp index 2a05f2764..9ac0ac0e9 100644 --- a/zone/spells.cpp +++ b/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; } diff --git a/zone/waypoints.cpp b/zone/waypoints.cpp index 38a857e51..2fb825de1 100644 --- a/zone/waypoints.cpp +++ b/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(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(position)).c_str()); + LogAIDetail("MoveTo [{}] without a grid", to_string(static_cast(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(m_GuardPoint)).c_str()); + LogAIModerate("Setting guard position to [{}]", to_string(static_cast(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;