pa/eqemu-server
2
0
Fork 0
mirror of https://github.com/EQEmu/Server.git synced 2026-05-16 22:58:34 +00:00
Code Issues Actions Packages Projects Releases Wiki Activity

[Logging] More AI Logging Cleanup (#2616)

Browse Source 
* [Logging] Additional AI Cleanup

* More cleanup/formatting fixes

* Typo
This commit is contained in:
Aeadoin
2022-12-10 18:36:40 -05:00
committed by GitHub
parent 3dfeda9cea
commit c8218574cc
16 changed files with 143 additions and 140 deletions
Download Patch File Download Diff File Expand all files Collapse all files
zone/bot.cpp
+50 -49
View File
@@ -1610,9 +1610,8 @@ int32 Bot::acmod() {
}
else
return (65 + ((agility - 300) / 21));
#if EQDEBUG >= 11
LogError("Error in Bot::acmod(): Agility: [{}], Level: [{}]",agility,level);
#endif
LogError("[Bot::acmod] Agility [{}] Level [{}]",agility,level);
return 0;
}
@@ -2136,7 +2135,7 @@ bool Bot::Process()
if (mob_close_scan_timer.Check()) {
LogAIScanCloseDetail(
"is_moving [{}] bot [{}] timer [{}]",
"[Bot::Process] is_moving [{}] bot [{}] timer [{}]",
moving ? "true" : "false",
GetCleanName(),
mob_close_scan_timer.GetDuration()
@@ -2294,7 +2293,7 @@ void Bot::BotRangedAttack(Mob* other) {
//make sure the attack and ranged timers are up
//if the ranged timer is disabled, then they have no ranged weapon and shouldent be attacking anyhow
if((attack_timer.Enabled() && !attack_timer.Check(false)) || (ranged_timer.Enabled() && !ranged_timer.Check())) {
LogCombat("Bot Archery attack canceled. Timer not up. Attack [{}], ranged [{}]", attack_timer.GetRemainingTime(), ranged_timer.GetRemainingTime());
LogCombatDetail("[Bot::BotRangedAttack] Bot Archery attack canceled. Timer not up. Attack [{}] ranged [{}]", attack_timer.GetRemainingTime(), ranged_timer.GetRemainingTime());
Message(0, "Error: Timer not up. Attack %d, ranged %d", attack_timer.GetRemainingTime(), ranged_timer.GetRemainingTime());
return;
}
@@ -2312,7 +2311,7 @@ void Bot::BotRangedAttack(Mob* other) {
if(!RangeWeapon || !Ammo)
return;
LogCombat("Shooting [{}] with bow [{}] ([{}]) and arrow [{}] ([{}])", other->GetCleanName(), RangeWeapon->Name, RangeWeapon->ID, Ammo->Name, Ammo->ID);
LogCombatDetail("[Bot::BotRangedAttack] Shooting [{}] with bow [{}] ([{}]) and arrow [{}] ([{}])", other->GetCleanName(), RangeWeapon->Name, RangeWeapon->ID, Ammo->Name, Ammo->ID);
if(!IsAttackAllowed(other) || IsCasting() || DivineAura() || IsStunned() || IsMezzed() || (GetAppearance() == eaDead))
return;
@@ -2322,21 +2321,21 @@ void Bot::BotRangedAttack(Mob* other) {
//break invis when you attack
if(invisible) {
LogCombat("Removing invisibility due to melee attack");
LogCombatModerate("[Bot::BotRangedAttack] Removing invisibility due to melee attack");
BuffFadeByEffect(SE_Invisibility);
BuffFadeByEffect(SE_Invisibility2);
invisible = false;
}
if(invisible_undead) {
LogCombat("Removing invisibility vs. undead due to melee attack");
LogCombatModerate("[Bot::BotRangedAttack] Removing invisibility vs. undead due to melee attack");
BuffFadeByEffect(SE_InvisVsUndead);
BuffFadeByEffect(SE_InvisVsUndead2);
invisible_undead = false;
}
if(invisible_animals) {
LogCombat("Removing invisibility vs. animals due to melee attack");
LogCombatModerate("[Bot::BotRangedAttack] Removing invisibility vs. animals due to melee attack");
BuffFadeByEffect(SE_InvisVsAnimals);
invisible_animals = false;
}
@@ -3496,7 +3495,7 @@ void Bot::AI_Process()
if (GetTarget() && !IsRooted()) {
LogAI("Pursuing [{}] while engaged", GetTarget()->GetCleanName());
LogAIDetail("[Bot::AI_Process] Pursuing [{}] while engaged", GetTarget()->GetCleanName());
Goal = GetTarget()->GetPosition();
if (DistanceSquared(m_Position, Goal) <= leash_distance) {
RunTo(Goal.x, Goal.y, Goal.z);
@@ -3882,7 +3881,7 @@ void Bot::PetAIProcess() {
else if (botPet->GetTarget() && botPet->GetAIMovementTimer()->Check()) {
botPet->SetRunAnimSpeed(0);
if(!botPet->IsRooted()) {
LogAI("Pursuing [{}] while engaged", botPet->GetTarget()->GetCleanName());
LogAIDetail("[Bot::AI_Process] Pursuing [{}] while engaged", botPet->GetTarget()->GetCleanName());
botPet->RunTo(botPet->GetTarget()->GetX(), botPet->GetTarget()->GetY(), botPet->GetTarget()->GetZ());
return;
} else {
@@ -4417,7 +4416,7 @@ void Bot::AddBotItem(
if (!inst) {
LogError(
"Bot:AddItem Invalid Item data: ID [{}] Charges [{}] Aug1 [{}] Aug2 [{}] Aug3 [{}] Aug4 [{}] Aug5 [{}] Aug6 [{}] Attuned [{}]",
"[Bot::AI_Process] Bot:AddItem Invalid Item data: ID [{}] Charges [{}] Aug1 [{}] Aug2 [{}] Aug3 [{}] Aug4 [{}] Aug5 [{}] Aug6 [{}] Attuned [{}]",
item_id,
charges,
augment_one,
@@ -4432,7 +4431,7 @@ void Bot::AddBotItem(
}
if (!database.botdb.SaveItemBySlot(this, slot_id, inst)) {
LogError("Failed to save item by slot to slot [{}] for [{}].", slot_id, GetCleanName());
LogError("[Bot::AI_Process] Failed to save item by slot to slot [{}] for [{}].", slot_id, GetCleanName());
safe_delete(inst);
return;
}
@@ -4683,7 +4682,7 @@ void Bot::PerformTradeWithClient(int16 begin_slot_id, int16 end_slot_id, Client*
}
if (!trade_instance->GetItem()) {
LogError("Bot::PerformTradeWithClient could not find item from instance in trade for {} with {} in slot {}.", client->GetCleanName(), GetCleanName(), trade_index);
LogError("[Bot::PerformTradeWithClient] could not find item from instance in trade for [{}] with [{}] in slot [{}].", client->GetCleanName(), GetCleanName(), trade_index);
client->Message(
Chat::White,
fmt::format(
@@ -4702,7 +4701,7 @@ void Bot::PerformTradeWithClient(int16 begin_slot_id, int16 end_slot_id, Client*
auto item_link = linker.GenerateLink();
if (trade_index != invslot::slotCursor && !trade_instance->IsDroppable()) {
LogError("Bot::PerformTradeWithClient trade hack detected by {} with {}.", client->GetCleanName(), GetCleanName());
LogError("[Bot::PerformTradeWithClient] trade hack detected by [{}] with [{}].", client->GetCleanName(), GetCleanName());
client->Message(Chat::White, "Trade hack detected, the trade has been cancelled.");
client->ResetTrade();
return;
@@ -4791,14 +4790,14 @@ void Bot::PerformTradeWithClient(int16 begin_slot_id, int16 end_slot_id, Client*
}
if (trade_instance->GetItem()->LoreGroup == -1 && check_iterator.trade_item_instance->GetItem()->ID == trade_instance->GetItem()->ID) {
LogError("Bot::PerformTradeWithClient trade hack detected by {} with {}.", client->GetCleanName(), GetCleanName());
LogError("[Bot::PerformTradeWithClient] trade hack detected by [{}] with [{}].", client->GetCleanName(), GetCleanName());
client->Message(Chat::White, "Trade hack detected, the trade has been cancelled.");
client->ResetTrade();
return;
}
if ((trade_instance->GetItem()->LoreGroup > 0) && (check_iterator.trade_item_instance->GetItem()->LoreGroup == trade_instance->GetItem()->LoreGroup)) {
LogError("Bot::PerformTradeWithClient trade hack detected by {} with {}.", client->GetCleanName(), GetCleanName());
LogError("[Bot::PerformTradeWithClient] trade hack detected by [{}] with [{}].", client->GetCleanName(), GetCleanName());
client->Message(Chat::White, "Trade hack detected, the trade has been cancelled.");
client->ResetTrade();
return;
@@ -4922,7 +4921,7 @@ void Bot::PerformTradeWithClient(int16 begin_slot_id, int16 end_slot_id, Client*
}
if (!return_instance->GetItem()) {
LogError("Bot::PerformTradeWithClient error processing bot slot {} for {} in trade with {}.", return_iterator.from_bot_slot, GetCleanName(), client->GetCleanName());
LogError("[Bot::PerformTradeWithClient] error processing bot slot [{}] for [{}] in trade with [{}].", return_iterator.from_bot_slot, GetCleanName(), client->GetCleanName());
client->Message(
Chat::White,
fmt::format(
@@ -5230,7 +5229,7 @@ void Bot::Damage(Mob *from, int64 damage, uint16 spell_id, EQ::skills::SkillType
//handle EVENT_ATTACK. Resets after we have not been attacked for 12 seconds
if(attacked_timer.Check()) {
LogCombat("Triggering EVENT_ATTACK due to attack by [{}]", from->GetName());
LogCombat("[Bot::Damage] Triggering EVENT_ATTACK due to attack by [{}]", from->GetName());
parse->EventBot(EVENT_ATTACK, this, from, "", 0);
}
@@ -5238,7 +5237,7 @@ void Bot::Damage(Mob *from, int64 damage, uint16 spell_id, EQ::skills::SkillType
// if spell is lifetap add hp to the caster
if (spell_id != SPELL_UNKNOWN && IsLifetapSpell(spell_id)) {
int64 healed = GetActSpellHealing(spell_id, damage);
LogCombat("Applying lifetap heal of [{}] to [{}]", healed, GetCleanName());
LogCombatDetail("[Bot::Damage] Applying lifetap heal of [{}] to [{}]", healed, GetCleanName());
HealDamage(healed);
entity_list.FilteredMessageClose(this, true, RuleI(Range, SpellMessages), Chat::Emote, FilterSocials, "%s beams a smile at %s", GetCleanName(), from->GetCleanName() );
}
@@ -5274,13 +5273,13 @@ void Bot::AddToHateList(Mob* other, int64 hate, int64 damage, bool iYellForHelp,
bool Bot::Attack(Mob* other, int Hand, bool FromRiposte, bool IsStrikethrough, bool IsFromSpell, ExtraAttackOptions *opts) {
if (!other) {
SetTarget(nullptr);
LogError("A null Mob object was passed to Bot::Attack for evaluation!");
LogErrorDetail("[Bot::Attack] A null Mob object was passed to Bot::Attack for evaluation!");
return false;
}
if ((GetHP() <= 0) || (GetAppearance() == eaDead)) {
SetTarget(nullptr);
LogCombat("Attempted to attack [{}] while unconscious or, otherwise, appearing dead", other->GetCleanName());
LogCombatModerate("[Bot::Attack] Attempted to attack [{}] while unconscious or, otherwise, appearing dead", other->GetCleanName());
return false;
}
@@ -5292,20 +5291,20 @@ bool Bot::Attack(Mob* other, int Hand, bool FromRiposte, bool IsStrikethrough, b
// takes more to compare a call result, load for a call, load a compare to address and compare, and finally
// push a value to an address than to just load for a call and push a value to an address.
LogCombat("Attacking [{}] with hand [{}] [{}]", other->GetCleanName(), Hand, (FromRiposte ? "(this is a riposte)" : ""));
LogCombat("[Bot::Attack] Attacking [{}] with hand [{}] [{}]", other->GetCleanName(), Hand, (FromRiposte ? "(this is a riposte)" : ""));
if ((IsCasting() && (GetClass() != BARD) && !IsFromSpell) || (!IsAttackAllowed(other))) {
if(GetOwnerID())
entity_list.MessageClose(this, 1, 200, 10, "%s says, '%s is not a legal target master.'", GetCleanName(), GetTarget()->GetCleanName());
if(other) {
RemoveFromHateList(other);
LogCombat("I am not allowed to attack [{}]", other->GetCleanName());
LogCombat("[Bot::Attack] I am not allowed to attack [{}]", other->GetCleanName());
}
return false;
}
if(DivineAura()) {//cant attack while invulnerable
LogCombat("Attack canceled, Divine Aura is in effect");
LogCombat("[Bot::Attack] Attack canceled, Divine Aura is in effect");
return false;
}
@@ -5323,19 +5322,19 @@ bool Bot::Attack(Mob* other, int Hand, bool FromRiposte, bool IsStrikethrough, b
if(weapon != nullptr) {
if (!weapon->IsWeapon()) {
LogCombat("Attack canceled, Item [{}] ([{}]) is not a weapon", weapon->GetItem()->Name, weapon->GetID());
LogCombat("[Bot::Attack] Attack canceled, Item [{}] ([{}]) is not a weapon", weapon->GetItem()->Name, weapon->GetID());
return false;
}
LogCombat("Attacking with weapon: [{}] ([{}])", weapon->GetItem()->Name, weapon->GetID());
LogCombat("[Bot::Attack] Attacking with weapon: [{}] ([{}])", weapon->GetItem()->Name, weapon->GetID());
}
else
LogCombat("Attacking without a weapon");
LogCombat("[Bot::Attack] Attacking without a weapon");
// calculate attack_skill and skillinuse depending on hand and weapon
// also send Packet to near clients
DamageHitInfo my_hit;
my_hit.skill = AttackAnimation(Hand, weapon);
LogCombat("Attacking with [{}] in slot [{}] using skill [{}]", weapon?weapon->GetItem()->Name:"Fist", Hand, my_hit.skill);
LogCombat("[Bot::Attack] Attacking with [{}] in slot [{}] using skill [{}]", weapon?weapon->GetItem()->Name:"Fist", Hand, my_hit.skill);
// Now figure out damage
my_hit.damage_done = 1;
@@ -5383,7 +5382,7 @@ bool Bot::Attack(Mob* other, int Hand, bool FromRiposte, bool IsStrikethrough, b
}
}
LogCombat("Damage calculated: base [{}] min damage [{}] skill [{}]", my_hit.base_damage, my_hit.min_damage, my_hit.skill);
LogCombat("[Bot::Attack] Damage calculated: base [{}] min damage [{}] skill [{}]", my_hit.base_damage, my_hit.min_damage, my_hit.skill);
int hit_chance_bonus = 0;
my_hit.offense = offense(my_hit.skill);
@@ -5401,7 +5400,7 @@ bool Bot::Attack(Mob* other, int Hand, bool FromRiposte, bool IsStrikethrough, b
DoAttack(other, my_hit, opts, FromRiposte);
LogCombat("Final damage after all reductions: [{}]", my_hit.damage_done);
LogCombat("[Bot::Attack] Final damage after all reductions: [{}]", my_hit.damage_done);
} else {
my_hit.damage_done = DMG_INVULNERABLE;
}
@@ -6022,7 +6021,7 @@ int32 Bot::CalcBotFocusEffect(focusType bottype, uint16 focus_id, uint16 spell_i
return 0;
break;
default:
LogInfo("CalcFocusEffect: unknown limit spelltype [{}]", focus_spell.base_value[i]);
LogInfo("[Bot::CalcBotFocusEffect] CalcFocusEffect: unknown limit spelltype [{}]", focus_spell.base_value[i]);
}
break;
@@ -6255,7 +6254,7 @@ int32 Bot::CalcBotFocusEffect(focusType bottype, uint16 focus_id, uint16 spell_i
break;
}
default:
LogSpells("CalcFocusEffect: unknown effectid [{}]", focus_spell.effect_id[i]);
LogSpellsModerate("[Bot::CalcBotFocusEffect] unknown effectid [{}]", focus_spell.effect_id[i]);
break;
}
}
@@ -6295,7 +6294,7 @@ float Bot::GetProcChances(float ProcBonus, uint16 hand) {
ProcChance += (ProcChance * ProcBonus / 100.0f);
}
LogCombat("Proc chance [{}] ([{}] from bonuses)", ProcChance, ProcBonus);
LogCombat("[Bot::GetProcChances] Proc chance [{}] ([{}] from bonuses)", ProcChance, ProcBonus);
return ProcChance;
}
@@ -6349,13 +6348,13 @@ bool Bot::TryFinishingBlow(Mob *defender, int64 &damage)
int fb_damage = aabonuses.FinishingBlow[1];
int levelreq = aabonuses.FinishingBlowLvl[0];
if (defender->GetLevel() <= levelreq && (chance >= zone->random.Int(1, 1000))) {
LogCombat("Landed a finishing blow: levelreq at [{}], other level [{}]",
LogCombat("[Bot::TryFinishingBlow] Landed a finishing blow: levelreq at [{}] other level [{}]",
levelreq, defender->GetLevel());
entity_list.MessageCloseString(this, false, 200, Chat::MeleeCrit, FINISHING_BLOW, GetName());
damage = fb_damage;
return true;
} else {
LogCombat("failed a finishing blow: levelreq at [{}], other level [{}]",
LogCombat("[Bot::TryFinishingBlow] failed a finishing blow: levelreq at [{}] other level [{}]",
levelreq, defender->GetLevel());
return false;
}
@@ -6364,14 +6363,14 @@ bool Bot::TryFinishingBlow(Mob *defender, int64 &damage)
}
void Bot::DoRiposte(Mob* defender) {
LogCombat("Preforming a riposte");
LogCombatDetail("[Bot::DoRiposte] Preforming a riposte");
if (!defender)
return;
defender->Attack(this, EQ::invslot::slotPrimary, true);
int32 DoubleRipChance = (defender->GetAABonuses().GiveDoubleRiposte[0] + defender->GetSpellBonuses().GiveDoubleRiposte[0] + defender->GetItemBonuses().GiveDoubleRiposte[0]);
if(DoubleRipChance && (DoubleRipChance >= zone->random.Int(0, 100))) {
LogCombat("Preforming a double riposte ([{}] percent chance)", DoubleRipChance);
LogCombatDetail("[Bot::DoRiposte] Preforming a double riposte ([{}] percent chance)", DoubleRipChance);
defender->Attack(this, EQ::invslot::slotPrimary, true);
}
@@ -7118,7 +7117,7 @@ int64 Bot::CalcMaxMana() {
break;
}
default: {
LogDebug("Invalid Class [{}] in CalcMaxMana", GetCasterClass());
LogDebug("[Bot::CalcMaxMana] Invalid Class [{}] in CalcMaxMana", GetCasterClass());
max_mana = 0;
break;
}
@@ -7668,7 +7667,9 @@ bool Bot::CastSpell(
(IsSilenced() && !IsDiscipline(spell_id)) ||
(IsAmnesiad() && IsDiscipline(spell_id))
) {
LogSpells("Spell casting canceled: not able to cast now. Valid? [{}], casting [{}], waiting? [{}], spellend? [{}], stunned? [{}], feared? [{}], mezed? [{}], silenced? [{}]", IsValidSpell(spell_id), casting_spell_id, delaytimer, spellend_timer.Enabled(), IsStunned(), IsFeared(), IsMezzed(), IsSilenced() );
LogSpellsModerate("[Bot::CastSpell] Spell casting canceled: not able to cast now. Valid? [{}] casting [{}] waiting? [{}] spellend? [{}] stunned? [{}] feared? [{}] mezed? [{}] silenced? [{}]",
IsValidSpell(spell_id), casting_spell_id, delaytimer, spellend_timer.Enabled(), IsStunned(), IsFeared(), IsMezzed(), IsSilenced()
);
if (IsSilenced() && !IsDiscipline(spell_id)) {
MessageString(Chat::White, SILENCED_STRING);
}
@@ -7695,7 +7696,7 @@ bool Bot::CastSpell(
}
if (DivineAura()) {
LogSpells("Spell casting canceled: cannot cast while Divine Aura is in effect");
LogSpellsDetail("[Bot::CastSpell] Spell casting canceled: cannot cast while Divine Aura is in effect");
InterruptSpell(173, 0x121, false);
return false;
}
@@ -7705,13 +7706,13 @@ bool Bot::CastSpell(
InterruptSpell(fizzle_msg, 0x121, spell_id);
uint32 use_mana = ((spells[spell_id].mana) / 4);
LogSpells("Spell casting canceled: fizzled. [{}] mana has been consumed", use_mana);
LogSpellsModerate("[Bot::CastSpell] Spell casting canceled: fizzled. [{}] mana has been consumed", use_mana);
SetMana(GetMana() - use_mana);
return false;
}
if (HasActiveSong()) {
LogSpells("Casting a new spell/song while singing a song. Killing old song [{}]", bardsong);
LogSpellsDetail("[Bot::CastSpell] Casting a new spell/song while singing a song. Killing old song [{}]", bardsong);
bardsong = 0;
bardsong_target_id = 0;
bardsong_slot = EQ::spells::CastingSlot::Gem1;
@@ -7763,19 +7764,19 @@ bool Bot::IsImmuneToSpell(uint16 spell_id, Mob *caster) {
if(caster->IsBot()) {
if(spells[spell_id].target_type == ST_Undead) {
if((GetBodyType() != BT_SummonedUndead) && (GetBodyType() != BT_Undead) && (GetBodyType() != BT_Vampire)) {
LogSpells("Bot's target is not an undead");
LogSpellsModerate("[Bot::IsImmuneToSpell] Bot's target is not an undead");
return true;
}
}
if(spells[spell_id].target_type == ST_Summoned) {
if((GetBodyType() != BT_SummonedUndead) && (GetBodyType() != BT_Summoned) && (GetBodyType() != BT_Summoned2) && (GetBodyType() != BT_Summoned3)) {
LogSpells("Bot's target is not a summoned creature");
LogSpellsModerate("[Bot::IsImmuneToSpell] Bot's target is not a summoned creature");
return true;
}
}
}
LogSpells("No bot immunities to spell [{}] found", spell_id);
LogSpellsModerate("[Bot::IsImmuneToSpell] No bot immunities to spell [{}] found", spell_id);
}
}
@@ -7926,7 +7927,7 @@ bool Bot::DoFinishedSpellSingleTarget(uint16 spell_id, Mob* spellTarget, EQ::spe
if((spelltypeequal || spelltypetargetequal) || spelltypeclassequal || slotequal) {
if(((spells[thespell].effect_id[0] == 0) && (spells[thespell].base_value[0] < 0)) &&
(spellTarget->GetHP() < ((spells[thespell].base_value[0] * (-1)) + 100))) {
LogSpells("Bot::DoFinishedSpellSingleTarget - GroupBuffing failure");
LogSpells("[Bot::DoFinishedSpellSingleTarget] GroupBuffing failure");
return false;
}
@@ -9411,7 +9412,7 @@ bool Bot::CheckLoreConflict(const EQ::ItemData* item) {
bool EntityList::Bot_AICheckCloseBeneficialSpells(Bot* caster, uint8 iChance, float iRange, uint32 iSpellTypes) {
if((iSpellTypes & SPELL_TYPES_DETRIMENTAL) != 0) {
LogError("Error: detrimental spells requested from AICheckCloseBeneficialSpells!!");
LogError("[EntityList::Bot_AICheckCloseBeneficialSpells] detrimental spells requested");
return false;
}
@@ -9845,7 +9846,7 @@ void EntityList::ScanCloseClientMobs(std::unordered_map<uint16, Mob*>& close_mob
}
}
LogAIScanCloseModerate("Close Client Mob List Size [{}] for mob [{}]", close_mobs.size(), scanning_mob->GetCleanName());
LogAIScanCloseModerate("[EntityList::ScanCloseClientMobs] Close Client Mob List Size [{}] for mob [{}]", close_mobs.size(), scanning_mob->GetCleanName());
}
uint8 Bot::GetNumberNeedingHealedInGroup(uint8 hpr, bool includePets) {