[Performance] Reworked how all log calls are made in the source, see changelog.txt for more details

This commit is contained in:
Akkadius
2017-04-01 03:51:46 -05:00
parent 93a6efa95f
commit 7aa1d243b0
131 changed files with 3126 additions and 3066 deletions
+42 -42
View File
@@ -1150,7 +1150,7 @@ int32 Bot::acmod() {
else
return (65 + ((agility - 300) / 21));
#if EQDEBUG >= 11
Log.Out(Logs::General, Logs::Error, "Error in Bot::acmod(): Agility: %i, Level: %i",agility,level);
Log(Logs::General, Logs::Error, "Error in Bot::acmod(): Agility: %i, Level: %i",agility,level);
#endif
return 0;
}
@@ -1890,7 +1890,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())) {
Log.Out(Logs::Detail, Logs::Combat, "Bot Archery attack canceled. Timer not up. Attack %d, ranged %d", attack_timer.GetRemainingTime(), ranged_timer.GetRemainingTime());
Log(Logs::Detail, Logs::Combat, "Bot Archery attack canceled. Timer not up. Attack %d, ranged %d", attack_timer.GetRemainingTime(), ranged_timer.GetRemainingTime());
Message(0, "Error: Timer not up. Attack %d, ranged %d", attack_timer.GetRemainingTime(), ranged_timer.GetRemainingTime());
return;
}
@@ -1908,7 +1908,7 @@ void Bot::BotRangedAttack(Mob* other) {
if(!RangeWeapon || !Ammo)
return;
Log.Out(Logs::Detail, Logs::Combat, "Shooting %s with bow %s (%d) and arrow %s (%d)", other->GetCleanName(), RangeWeapon->Name, RangeWeapon->ID, Ammo->Name, Ammo->ID);
Log(Logs::Detail, Logs::Combat, "Shooting %s with bow %s (%d) and arrow %s (%d)", other->GetCleanName(), RangeWeapon->Name, RangeWeapon->ID, Ammo->Name, Ammo->ID);
if(!IsAttackAllowed(other) || IsCasting() || DivineAura() || IsStunned() || IsMezzed() || (GetAppearance() == eaDead))
return;
@@ -1918,21 +1918,21 @@ void Bot::BotRangedAttack(Mob* other) {
//break invis when you attack
if(invisible) {
Log.Out(Logs::Detail, Logs::Combat, "Removing invisibility due to melee attack.");
Log(Logs::Detail, Logs::Combat, "Removing invisibility due to melee attack.");
BuffFadeByEffect(SE_Invisibility);
BuffFadeByEffect(SE_Invisibility2);
invisible = false;
}
if(invisible_undead) {
Log.Out(Logs::Detail, Logs::Combat, "Removing invisibility vs. undead due to melee attack.");
Log(Logs::Detail, Logs::Combat, "Removing invisibility vs. undead due to melee attack.");
BuffFadeByEffect(SE_InvisVsUndead);
BuffFadeByEffect(SE_InvisVsUndead2);
invisible_undead = false;
}
if(invisible_animals) {
Log.Out(Logs::Detail, Logs::Combat, "Removing invisibility vs. animals due to melee attack.");
Log(Logs::Detail, Logs::Combat, "Removing invisibility vs. animals due to melee attack.");
BuffFadeByEffect(SE_InvisVsAnimals);
invisible_animals = false;
}
@@ -2138,7 +2138,7 @@ void Bot::AI_Process() {
Mob* delete_me = HealRotationTarget();
if (AIHealRotation(HealRotationTarget(), UseHealRotationFastHeals())) {
#if (EQDEBUG >= 12)
Log.Out(Logs::General, Logs::Error, "Bot::AI_Process() - Casting succeeded (m: %s, t: %s) : AdvHR(true)", GetCleanName(), ((delete_me) ? (delete_me->GetCleanName()) : ("nullptr")));
Log(Logs::General, Logs::Error, "Bot::AI_Process() - Casting succeeded (m: %s, t: %s) : AdvHR(true)", GetCleanName(), ((delete_me) ? (delete_me->GetCleanName()) : ("nullptr")));
#endif
m_member_of_heal_rotation->SetMemberIsCasting(this);
m_member_of_heal_rotation->UpdateTargetHealingStats(HealRotationTarget());
@@ -2146,7 +2146,7 @@ void Bot::AI_Process() {
}
else {
#if (EQDEBUG >= 12)
Log.Out(Logs::General, Logs::Error, "Bot::AI_Process() - Casting failed (m: %s, t: %s) : AdvHR(false)", GetCleanName(), ((delete_me) ? (delete_me->GetCleanName()) : ("nullptr")));
Log(Logs::General, Logs::Error, "Bot::AI_Process() - Casting failed (m: %s, t: %s) : AdvHR(false)", GetCleanName(), ((delete_me) ? (delete_me->GetCleanName()) : ("nullptr")));
#endif
m_member_of_heal_rotation->SetMemberIsCasting(this, false);
AdvanceHealRotation(false);
@@ -2163,7 +2163,7 @@ void Bot::AI_Process() {
SetHasBeenSummoned(false);
} else if(!IsRooted()) {
if(GetTarget() && GetTarget()->GetHateTop() && GetTarget()->GetHateTop() != this) {
Log.Out(Logs::Detail, Logs::AI, "Returning to location prior to being summoned.");
Log(Logs::Detail, Logs::AI, "Returning to location prior to being summoned.");
CalculateNewPosition2(m_PreSummonLocation.x, m_PreSummonLocation.y, m_PreSummonLocation.z, GetBotRunspeed());
SetHeading(CalculateHeadingToTarget(m_PreSummonLocation.x, m_PreSummonLocation.y));
return;
@@ -2498,7 +2498,7 @@ void Bot::AI_Process() {
if (AI_movement_timer->Check()) {
if(!IsRooted()) {
Log.Out(Logs::Detail, Logs::AI, "Pursuing %s while engaged.", GetTarget()->GetCleanName());
Log(Logs::Detail, Logs::AI, "Pursuing %s while engaged.", GetTarget()->GetCleanName());
CalculateNewPosition2(GetTarget()->GetX(), GetTarget()->GetY(), GetTarget()->GetZ(), GetBotRunspeed());
return;
}
@@ -2746,7 +2746,7 @@ void Bot::PetAIProcess() {
else if (botPet->GetTarget() && botPet->GetAIMovementTimer()->Check()) {
botPet->SetRunAnimSpeed(0);
if(!botPet->IsRooted()) {
Log.Out(Logs::Detail, Logs::AI, "Pursuing %s while engaged.", botPet->GetTarget()->GetCleanName());
Log(Logs::Detail, Logs::AI, "Pursuing %s while engaged.", botPet->GetTarget()->GetCleanName());
botPet->CalculateNewPosition2(botPet->GetTarget()->GetX(), botPet->GetTarget()->GetY(), botPet->GetTarget()->GetZ(), botPet->GetOwner()->GetRunspeed());
return;
} else {
@@ -3813,7 +3813,7 @@ void Bot::Damage(Mob *from, int32 damage, uint16 spell_id, EQEmu::skills::SkillT
//handle EVENT_ATTACK. Resets after we have not been attacked for 12 seconds
if(attacked_timer.Check()) {
Log.Out(Logs::Detail, Logs::Combat, "Triggering EVENT_ATTACK due to attack by %s", from->GetName());
Log(Logs::Detail, Logs::Combat, "Triggering EVENT_ATTACK due to attack by %s", from->GetName());
parse->EventNPC(EVENT_ATTACK, this, from, "", 0);
}
@@ -3821,7 +3821,7 @@ void Bot::Damage(Mob *from, int32 damage, uint16 spell_id, EQEmu::skills::SkillT
// if spell is lifetap add hp to the caster
if (spell_id != SPELL_UNKNOWN && IsLifetapSpell(spell_id)) {
int healed = GetActSpellHealing(spell_id, damage);
Log.Out(Logs::Detail, Logs::Combat, "Applying lifetap heal of %d to %s", healed, GetCleanName());
Log(Logs::Detail, Logs::Combat, "Applying lifetap heal of %d to %s", healed, GetCleanName());
HealDamage(healed);
entity_list.MessageClose(this, true, 300, MT_Spells, "%s beams a smile at %s", GetCleanName(), from->GetCleanName() );
}
@@ -3857,13 +3857,13 @@ void Bot::AddToHateList(Mob* other, uint32 hate, int32 damage, bool iYellForHelp
bool Bot::Attack(Mob* other, int Hand, bool FromRiposte, bool IsStrikethrough, bool IsFromSpell, ExtraAttackOptions *opts) {
if (!other) {
SetTarget(nullptr);
Log.Out(Logs::General, Logs::Error, "A null Mob object was passed to Bot::Attack for evaluation!");
Log(Logs::General, Logs::Error, "A null Mob object was passed to Bot::Attack for evaluation!");
return false;
}
if ((GetHP() <= 0) || (GetAppearance() == eaDead)) {
SetTarget(nullptr);
Log.Out(Logs::Detail, Logs::Combat, "Attempted to attack %s while unconscious or, otherwise, appearing dead", other->GetCleanName());
Log(Logs::Detail, Logs::Combat, "Attempted to attack %s while unconscious or, otherwise, appearing dead", other->GetCleanName());
return false;
}
@@ -3875,20 +3875,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.
Log.Out(Logs::Detail, Logs::Combat, "Attacking %s with hand %d %s", other->GetCleanName(), Hand, (FromRiposte ? "(this is a riposte)" : ""));
Log(Logs::Detail, Logs::Combat, "Attacking %s with hand %d %s", other->GetCleanName(), Hand, (FromRiposte ? "(this is a riposte)" : ""));
if ((IsCasting() && (GetClass() != BARD) && !IsFromSpell) || (!IsAttackAllowed(other))) {
if(this->GetOwnerID())
entity_list.MessageClose(this, 1, 200, 10, "%s says, '%s is not a legal target master.'", this->GetCleanName(), this->GetTarget()->GetCleanName());
if(other) {
RemoveFromHateList(other);
Log.Out(Logs::Detail, Logs::Combat, "I am not allowed to attack %s", other->GetCleanName());
Log(Logs::Detail, Logs::Combat, "I am not allowed to attack %s", other->GetCleanName());
}
return false;
}
if(DivineAura()) {//cant attack while invulnerable
Log.Out(Logs::Detail, Logs::Combat, "Attack canceled, Divine Aura is in effect.");
Log(Logs::Detail, Logs::Combat, "Attack canceled, Divine Aura is in effect.");
return false;
}
@@ -3906,19 +3906,19 @@ bool Bot::Attack(Mob* other, int Hand, bool FromRiposte, bool IsStrikethrough, b
if(weapon != nullptr) {
if (!weapon->IsWeapon()) {
Log.Out(Logs::Detail, Logs::Combat, "Attack canceled, Item %s (%d) is not a weapon.", weapon->GetItem()->Name, weapon->GetID());
Log(Logs::Detail, Logs::Combat, "Attack canceled, Item %s (%d) is not a weapon.", weapon->GetItem()->Name, weapon->GetID());
return false;
}
Log.Out(Logs::Detail, Logs::Combat, "Attacking with weapon: %s (%d)", weapon->GetItem()->Name, weapon->GetID());
Log(Logs::Detail, Logs::Combat, "Attacking with weapon: %s (%d)", weapon->GetItem()->Name, weapon->GetID());
}
else
Log.Out(Logs::Detail, Logs::Combat, "Attacking without a weapon.");
Log(Logs::Detail, Logs::Combat, "Attacking without a weapon.");
// calculate attack_skill and skillinuse depending on hand and weapon
// also send Packet to near clients
DamageHitInfo my_hit;
AttackAnimation(my_hit.skill, Hand, weapon);
Log.Out(Logs::Detail, Logs::Combat, "Attacking with %s in slot %d using skill %d", weapon?weapon->GetItem()->Name:"Fist", Hand, my_hit.skill);
Log(Logs::Detail, Logs::Combat, "Attacking with %s in slot %d using skill %d", weapon?weapon->GetItem()->Name:"Fist", Hand, my_hit.skill);
// Now figure out damage
my_hit.damage_done = 1;
@@ -3966,7 +3966,7 @@ bool Bot::Attack(Mob* other, int Hand, bool FromRiposte, bool IsStrikethrough, b
}
}
Log.Out(Logs::Detail, Logs::Combat, "Damage calculated: base %d min damage %d skill %d", my_hit.base_damage, my_hit.min_damage, my_hit.skill);
Log(Logs::Detail, Logs::Combat, "Damage calculated: base %d min damage %d skill %d", my_hit.base_damage, my_hit.min_damage, my_hit.skill);
int hit_chance_bonus = 0;
my_hit.offense = offense(my_hit.skill);
@@ -3984,7 +3984,7 @@ bool Bot::Attack(Mob* other, int Hand, bool FromRiposte, bool IsStrikethrough, b
DoAttack(other, my_hit, opts);
Log.Out(Logs::Detail, Logs::Combat, "Final damage after all reductions: %d", my_hit.damage_done);
Log(Logs::Detail, Logs::Combat, "Final damage after all reductions: %d", my_hit.damage_done);
} else {
my_hit.damage_done = DMG_INVULNERABLE;
}
@@ -4595,7 +4595,7 @@ int32 Bot::CalcBotFocusEffect(BotfocusType bottype, uint16 focus_id, uint16 spel
return 0;
break;
default:
Log.Out(Logs::General, Logs::Normal, "CalcFocusEffect: unknown limit spelltype %d", focus_spell.base[i]);
Log(Logs::General, Logs::Normal, "CalcFocusEffect: unknown limit spelltype %d", focus_spell.base[i]);
}
break;
@@ -4809,7 +4809,7 @@ int32 Bot::CalcBotFocusEffect(BotfocusType bottype, uint16 focus_id, uint16 spel
break;
}
default:
Log.Out(Logs::General, Logs::Spells, "CalcFocusEffect: unknown effectid %d", focus_spell.effectid[i]);
Log(Logs::General, Logs::Spells, "CalcFocusEffect: unknown effectid %d", focus_spell.effectid[i]);
break;
}
}
@@ -4849,7 +4849,7 @@ float Bot::GetProcChances(float ProcBonus, uint16 hand) {
ProcChance += (ProcChance * ProcBonus / 100.0f);
}
Log.Out(Logs::Detail, Logs::Combat, "Proc chance %.2f (%.2f from bonuses)", ProcChance, ProcBonus);
Log(Logs::Detail, Logs::Combat, "Proc chance %.2f (%.2f from bonuses)", ProcChance, ProcBonus);
return ProcChance;
}
@@ -4903,13 +4903,13 @@ bool Bot::TryFinishingBlow(Mob *defender, int &damage)
int fb_damage = aabonuses.FinishingBlow[1];
int levelreq = aabonuses.FinishingBlowLvl[0];
if (defender->GetLevel() <= levelreq && (chance >= zone->random.Int(1, 1000))) {
Log.Out(Logs::Detail, Logs::Combat, "Landed a finishing blow: levelreq at %d, other level %d",
Log(Logs::Detail, Logs::Combat, "Landed a finishing blow: levelreq at %d, other level %d",
levelreq, defender->GetLevel());
entity_list.MessageClose_StringID(this, false, 200, MT_CritMelee, FINISHING_BLOW, GetName());
damage = fb_damage;
return true;
} else {
Log.Out(Logs::Detail, Logs::Combat, "FAILED a finishing blow: levelreq at %d, other level %d",
Log(Logs::Detail, Logs::Combat, "FAILED a finishing blow: levelreq at %d, other level %d",
levelreq, defender->GetLevel());
return false;
}
@@ -4918,14 +4918,14 @@ bool Bot::TryFinishingBlow(Mob *defender, int &damage)
}
void Bot::DoRiposte(Mob* defender) {
Log.Out(Logs::Detail, Logs::Combat, "Preforming a riposte");
Log(Logs::Detail, Logs::Combat, "Preforming a riposte");
if (!defender)
return;
defender->Attack(this, EQEmu::inventory::slotPrimary, true);
int32 DoubleRipChance = (defender->GetAABonuses().GiveDoubleRiposte[0] + defender->GetSpellBonuses().GiveDoubleRiposte[0] + defender->GetItemBonuses().GiveDoubleRiposte[0]);
if(DoubleRipChance && (DoubleRipChance >= zone->random.Int(0, 100))) {
Log.Out(Logs::Detail, Logs::Combat, "Preforming a double riposte (%d percent chance)", DoubleRipChance);
Log(Logs::Detail, Logs::Combat, "Preforming a double riposte (%d percent chance)", DoubleRipChance);
defender->Attack(this, EQEmu::inventory::slotPrimary, true);
}
@@ -5548,7 +5548,7 @@ int32 Bot::CalcMaxMana() {
break;
}
default: {
Log.Out(Logs::General, Logs::None, "Invalid Class '%c' in CalcMaxMana", GetCasterClass());
Log(Logs::General, Logs::None, "Invalid Class '%c' in CalcMaxMana", GetCasterClass());
max_mana = 0;
break;
}
@@ -5976,14 +5976,14 @@ bool Bot::CastSpell(uint16 spell_id, uint16 target_id, EQEmu::CastingSlot slot,
uint32* oSpellWillFinish, uint32 item_slot, int16 *resist_adjust, uint32 aa_id) {
bool Result = false;
if(zone && !zone->IsSpellBlocked(spell_id, glm::vec3(GetPosition()))) {
Log.Out(Logs::Detail, Logs::Spells, "CastSpell called for spell %s (%d) on entity %d, slot %d, time %d, mana %d, from item slot %d", spells[spell_id].name, spell_id, target_id, slot, cast_time, mana_cost, (item_slot==0xFFFFFFFF)?999:item_slot);
Log(Logs::Detail, Logs::Spells, "CastSpell called for spell %s (%d) on entity %d, slot %d, time %d, mana %d, from item slot %d", spells[spell_id].name, spell_id, target_id, slot, cast_time, mana_cost, (item_slot==0xFFFFFFFF)?999:item_slot);
if(casting_spell_id == spell_id)
ZeroCastingVars();
if(GetClass() != BARD) {
if(!IsValidSpell(spell_id) || casting_spell_id || delaytimer || spellend_timer.Enabled() || IsStunned() || IsFeared() || IsMezzed() || (IsSilenced() && !IsDiscipline(spell_id)) || (IsAmnesiad() && IsDiscipline(spell_id))) {
Log.Out(Logs::Detail, Logs::Spells, "Spell casting canceled: not able to cast now. Valid? %d, casting %d, waiting? %d, spellend? %d, stunned? %d, feared? %d, mezed? %d, silenced? %d", IsValidSpell(spell_id), casting_spell_id, delaytimer, spellend_timer.Enabled(), IsStunned(), IsFeared(), IsMezzed(), IsSilenced() );
Log(Logs::Detail, Logs::Spells, "Spell casting canceled: not able to cast now. Valid? %d, casting %d, waiting? %d, spellend? %d, stunned? %d, feared? %d, mezed? %d, silenced? %d", IsValidSpell(spell_id), casting_spell_id, delaytimer, spellend_timer.Enabled(), IsStunned(), IsFeared(), IsMezzed(), IsSilenced() );
if(IsSilenced() && !IsDiscipline(spell_id))
Message_StringID(13, SILENCED_STRING);
@@ -6007,7 +6007,7 @@ bool Bot::CastSpell(uint16 spell_id, uint16 target_id, EQEmu::CastingSlot slot,
}
if(DivineAura()) {
Log.Out(Logs::Detail, Logs::Spells, "Spell casting canceled: cannot cast while Divine Aura is in effect.");
Log(Logs::Detail, Logs::Spells, "Spell casting canceled: cannot cast while Divine Aura is in effect.");
InterruptSpell(173, 0x121, false);
return false;
}
@@ -6017,13 +6017,13 @@ bool Bot::CastSpell(uint16 spell_id, uint16 target_id, EQEmu::CastingSlot slot,
InterruptSpell(fizzle_msg, 0x121, spell_id);
uint32 use_mana = ((spells[spell_id].mana) / 4);
Log.Out(Logs::Detail, Logs::Spells, "Spell casting canceled: fizzled. %d mana has been consumed", use_mana);
Log(Logs::Detail, Logs::Spells, "Spell casting canceled: fizzled. %d mana has been consumed", use_mana);
SetMana(GetMana() - use_mana);
return false;
}
if (HasActiveSong()) {
Log.Out(Logs::Detail, Logs::Spells, "Casting a new spell/song while singing a song. Killing old song %d.", bardsong);
Log(Logs::Detail, Logs::Spells, "Casting a new spell/song while singing a song. Killing old song %d.", bardsong);
bardsong = 0;
bardsong_target_id = 0;
bardsong_slot = EQEmu::CastingSlot::Gem1;
@@ -6137,19 +6137,19 @@ bool Bot::IsImmuneToSpell(uint16 spell_id, Mob *caster) {
if(caster->IsBot()) {
if(spells[spell_id].targettype == ST_Undead) {
if((GetBodyType() != BT_SummonedUndead) && (GetBodyType() != BT_Undead) && (GetBodyType() != BT_Vampire)) {
Log.Out(Logs::Detail, Logs::Spells, "Bot's target is not an undead.");
Log(Logs::Detail, Logs::Spells, "Bot's target is not an undead.");
return true;
}
}
if(spells[spell_id].targettype == ST_Summoned) {
if((GetBodyType() != BT_SummonedUndead) && (GetBodyType() != BT_Summoned) && (GetBodyType() != BT_Summoned2) && (GetBodyType() != BT_Summoned3)) {
Log.Out(Logs::Detail, Logs::Spells, "Bot's target is not a summoned creature.");
Log(Logs::Detail, Logs::Spells, "Bot's target is not a summoned creature.");
return true;
}
}
}
Log.Out(Logs::Detail, Logs::Spells, "No bot immunities to spell %d found.", spell_id);
Log(Logs::Detail, Logs::Spells, "No bot immunities to spell %d found.", spell_id);
}
}
@@ -6300,7 +6300,7 @@ bool Bot::DoFinishedSpellSingleTarget(uint16 spell_id, Mob* spellTarget, EQEmu::
if((spelltypeequal || spelltypetargetequal) || spelltypeclassequal || slotequal) {
if(((spells[thespell].effectid[0] == 0) && (spells[thespell].base[0] < 0)) &&
(spellTarget->GetHP() < ((spells[thespell].base[0] * (-1)) + 100))) {
Log.Out(Logs::General, Logs::Spells, "Bot::DoFinishedSpellSingleTarget - GroupBuffing failure");
Log(Logs::General, Logs::Spells, "Bot::DoFinishedSpellSingleTarget - GroupBuffing failure");
return false;
}
@@ -7807,7 +7807,7 @@ bool Bot::CheckLoreConflict(const EQEmu::ItemData* item) {
bool EntityList::Bot_AICheckCloseBeneficialSpells(Bot* caster, uint8 iChance, float iRange, uint32 iSpellTypes) {
if((iSpellTypes&SpellTypes_Detrimental) != 0) {
Log.Out(Logs::General, Logs::Error, "Error: detrimental spells requested from AICheckCloseBeneficialSpells!!");
Log(Logs::General, Logs::Error, "Error: detrimental spells requested from AICheckCloseBeneficialSpells!!");
return false;
}