diff options
-rw-r--r-- | src/server/game/Entities/Player/Player.cpp | 537 |
1 files changed, 311 insertions, 226 deletions
diff --git a/src/server/game/Entities/Player/Player.cpp b/src/server/game/Entities/Player/Player.cpp index f25125da993..b37c6dbd5be 100644 --- a/src/server/game/Entities/Player/Player.cpp +++ b/src/server/game/Entities/Player/Player.cpp @@ -868,7 +868,8 @@ bool Player::Create(ObjectGuid::LowType guidlow, CharacterCreateInfo* createInfo bool Player::StoreNewItemInBestSlots(uint32 titem_id, uint32 titem_amount) { - TC_LOG_DEBUG("entities.player.items", "STORAGE: Creating initial item, itemId = %u, count = %u", titem_id, titem_amount); + TC_LOG_DEBUG("entities.player.items", "Player::StoreNewItemInBestSlots: Player '%s' (%s) creates initial item (ItemID: %u, Count: %u)", + GetName().c_str(), GetGUID().ToString().c_str(), titem_id, titem_amount); // attempt equip by one while (titem_amount > 0) @@ -897,7 +898,8 @@ bool Player::StoreNewItemInBestSlots(uint32 titem_id, uint32 titem_amount) } // item can't be added - TC_LOG_ERROR("entities.player.items", "STORAGE: Can't equip or store initial item %u for race %u class %u, error msg = %u", titem_id, getRace(), getClass(), msg); + TC_LOG_ERROR("entities.player.items", "Player::StoreNewItemInBestSlots: Player '%s' (%s) can't equip or store initial item (ItemID: %u, Race: %u, Class: %u, InventoryResult: %u)", + GetName().c_str(), GetGUID().ToString().c_str(), titem_id, getRace(), getClass(), msg); return false; } @@ -964,7 +966,8 @@ uint32 Player::EnvironmentalDamage(EnviromentalDamage type, uint32 damage) { if (type == DAMAGE_FALL) // DealDamage does not apply item durability loss from self-induced damage. { - TC_LOG_DEBUG("entities.player", "You have died from falling, losing 10 percent total armor durability."); + TC_LOG_DEBUG("entities.player", "Player::EnvironmentalDamage: Player '%s' (%s) fall to death, losing 10%% durability", + GetName().c_str(), GetGUID().ToString().c_str()); DurabilityLossAll(0.10f, false); // durability lost message WorldPacket data2(SMSG_DURABILITY_DAMAGE_DEATH, 0); @@ -1216,11 +1219,12 @@ void Player::Update(uint32 p_time) { //TC_LOG_FATAL("entities.player", "Player has m_pad %u during update!", m_pad); //if (m_spellModTakingSpell) - TC_LOG_FATAL("spells", "Player has m_spellModTakingSpell %u during update!", m_spellModTakingSpell->m_spellInfo->Id); + TC_LOG_FATAL("spells", "Player::Update: Player '%s' (%s) has m_spellModTakingSpell (SpellID: %u) during update!", + GetName().c_str(), GetGUID().ToString().c_str(), m_spellModTakingSpell->m_spellInfo->Id); m_spellModTakingSpell = nullptr; } - //used to implement delayed far teleports + //used to implement delayed far teleport SetCanDelayTeleport(true); Unit::Update(p_time); SetCanDelayTeleport(false); @@ -1442,7 +1446,7 @@ void Player::Update(uint32 p_time) { // m_nextSave reset in SaveToDB call SaveToDB(); - TC_LOG_DEBUG("entities.player", "Player '%s' (GUID: %u) saved", GetName().c_str(), GetGUID().GetCounter()); + TC_LOG_DEBUG("entities.player", "Player::Update: Player '%s' (%s) saved", GetName().c_str(), GetGUID().ToString().c_str()); } else m_nextSave -= p_time; @@ -1552,7 +1556,7 @@ void Player::setDeathState(DeathState s) { if (!cur) { - TC_LOG_ERROR("entities.player", "setDeathState: Attempted to kill a dead player %s(%d)", GetName().c_str(), GetGUID().GetCounter()); + TC_LOG_ERROR("entities.player", "Player::setDeathState: Attempt to kill a dead player '%s' (%s)", GetName().c_str(), GetGUID().ToString().c_str()); return; } @@ -1800,14 +1804,14 @@ bool Player::TeleportTo(uint32 mapid, float x, float y, float z, float orientati { if (!MapManager::IsValidMapCoord(mapid, x, y, z, orientation)) { - TC_LOG_ERROR("maps", "TeleportTo: invalid map (%d) or invalid coordinates (X: %f, Y: %f, Z: %f, O: %f) given when teleporting player (GUID: %u, name: %s, map: %d, X: %f, Y: %f, Z: %f, O: %f).", - mapid, x, y, z, orientation, GetGUID().GetCounter(), GetName().c_str(), GetMapId(), GetPositionX(), GetPositionY(), GetPositionZ(), GetOrientation()); + TC_LOG_ERROR("maps", "Player::TeleportTo: Invalid map (%d) or invalid coordinates (X: %f, Y: %f, Z: %f, O: %f) given when teleporting player '%s' (%s, MapID: %d, X: %f, Y: %f, Z: %f, O: %f).", + mapid, x, y, z, orientation, GetGUID().ToString().c_str(), GetName().c_str(), GetMapId(), GetPositionX(), GetPositionY(), GetPositionZ(), GetOrientation()); return false; } if (!GetSession()->HasPermission(rbac::RBAC_PERM_SKIP_CHECK_DISABLE_MAP) && DisableMgr::IsDisabledFor(DISABLE_TYPE_MAP, mapid, this)) { - TC_LOG_ERROR("maps", "Player (GUID: %u, name: %s) tried to enter a forbidden map %u", GetGUID().GetCounter(), GetName().c_str(), mapid); + TC_LOG_ERROR("maps", "Player::TeleportTo: Player '%s' (%s) tried to enter a forbidden map (MapID: %u)", GetGUID().ToString().c_str(), GetName().c_str(), mapid); SendTransferAborted(mapid, TRANSFER_ABORT_MAP_NOT_ALLOWED); return false; } @@ -1825,7 +1829,8 @@ bool Player::TeleportTo(uint32 mapid, float x, float y, float z, float orientati // client without expansion support if (GetSession()->Expansion() < mEntry->Expansion()) { - TC_LOG_DEBUG("maps", "Player %s using client without required expansion tried teleporting to non accessible map %u", GetName().c_str(), mapid); + TC_LOG_DEBUG("maps", "Player '%s' (%s) using client without required expansion tried teleport to non accessible map (MapID: %u)", + GetName().c_str(), GetGUID().ToString().c_str(), mapid); if (Transport* transport = GetTransport()) { @@ -1838,7 +1843,7 @@ bool Player::TeleportTo(uint32 mapid, float x, float y, float z, float orientati return false; // normal client can't teleport to this map... } else - TC_LOG_DEBUG("maps", "Player %s is being teleported to map %u", GetName().c_str(), mapid); + TC_LOG_DEBUG("maps", "Player %s (%s) is being teleported to map (MapID: %u)", GetName().c_str(), GetGUID().ToString().c_str(), mapid); if (m_vehicle) ExitVehicle(); @@ -1863,7 +1868,7 @@ bool Player::TeleportTo(uint32 mapid, float x, float y, float z, float orientati if (GetMapId() == mapid) { - //lets reset far teleport flag if it wasn't reset during chained teleports + //lets reset far teleport flag if it wasn't reset during chained teleport SetSemaphoreTeleportFar(false); //setup delayed teleport flag SetDelayedTeleportFlag(IsCanDelayTeleport()); @@ -2147,8 +2152,8 @@ void Player::RemoveFromWorld() { if (WorldObject* viewpoint = GetViewpoint()) { - TC_LOG_ERROR("entities.player", "Player %s has viewpoint %u %u when removed from world", - GetName().c_str(), viewpoint->GetEntry(), viewpoint->GetTypeId()); + TC_LOG_ERROR("entities.player", "Player::RemoveFromWorld: Player '%s' (%s) has viewpoint (Entry:%u, Type: %u) when removed from world", + GetName().c_str(), GetGUID().ToString().c_str(), viewpoint->GetEntry(), viewpoint->GetTypeId()); SetViewpoint(viewpoint, false); } } @@ -2474,8 +2479,8 @@ GameObject* Player::GetGameObjectIfCanInteractWith(ObjectGuid const& guid, Gameo if (go->IsWithinDistInMap(this, go->GetInteractionDistance())) return go; - TC_LOG_DEBUG("maps", "GetGameObjectIfCanInteractWith: GameObject '%s' [GUID: %u] is too far away from player %s [GUID: %u] to be used by him (distance=%f, maximal %f is allowed)", go->GetGOInfo()->name.c_str(), - go->GetGUID().GetCounter(), GetName().c_str(), GetGUID().GetCounter(), go->GetDistance(this), go->GetInteractionDistance()); + TC_LOG_DEBUG("maps", "Player::GetGameObjectIfCanInteractWith: GameObject '%s' (%s) is too far away from player '%s' (%s) to be used by him (Distance: %f, maximal 10 is allowed)", + go->GetGOInfo()->name.c_str(), go->GetGUID().ToString().c_str(), GetName().c_str(), GetGUID().ToString().c_str(), go->GetDistance(this)); } } @@ -3070,8 +3075,6 @@ void Player::SendInitialSpells() GetSpellHistory()->WritePacket<Player>(data); GetSession()->SendPacket(&data); - - TC_LOG_DEBUG("network", "CHARACTER: Sent Initial Spells"); } void Player::RemoveMail(uint32 id) @@ -3165,12 +3168,12 @@ bool Player::AddTalent(uint32 spellId, uint8 spec, bool learning) // do character spell book cleanup (all characters) if (!IsInWorld() && !learning) // spell load case { - TC_LOG_ERROR("spells", "Player::addSpell: Non-existing spell #%u requested from SpellStore. Deleting spell for all characters in `character_spell`.", spellId); + TC_LOG_ERROR("spells", "Player::AddTalent: Spell (ID: %u) does not exist. Deleting for all characters in `character_spell` and `character_talent`.", spellId); DeleteSpellFromAllPlayers(spellId); } else - TC_LOG_ERROR("spells", "Player::addSpell: Non-existing spell #%u requested from SpellStore.", spellId); + TC_LOG_ERROR("spells", "Player::AddTalent: Spell (ID: %u) does not exist", spellId); return false; } @@ -3180,12 +3183,12 @@ bool Player::AddTalent(uint32 spellId, uint8 spec, bool learning) // do character spell book cleanup (all characters) if (!IsInWorld() && !learning) // spell load case { - TC_LOG_ERROR("spells", "Player::addTalent: Broken spell #%u, learning this spell is not allowed. Deleting this spell for all characters in `character_talent`.", spellId); + TC_LOG_ERROR("spells", "Player::AddTalent: Spell (ID: %u) is invalid. Deleting for all characters in `character_spell` and `character_talent`.", spellId); DeleteSpellFromAllPlayers(spellId); } else - TC_LOG_ERROR("spells", "Player::addTalent: Broken spell #%u, learning this spell is not allowed.", spellId); + TC_LOG_ERROR("spells", "Player::AddTalent: Spell (ID: %u) is invalid", spellId); return false; } @@ -3230,12 +3233,12 @@ bool Player::AddSpell(uint32 spellId, bool active, bool learning, bool dependent // do character spell book cleanup (all characters) if (!IsInWorld() && !learning) // spell load case { - TC_LOG_ERROR("spells", "Player::addSpell: Non-existing spell #%u requested from SpellStore. Deleting for all characters in `character_spell`.", spellId); + TC_LOG_ERROR("spells", "Player::AddSpell: Spell (ID: %u) does not exist. deleting for all characters in `character_spell` and `character_talent`.", spellId); DeleteSpellFromAllPlayers(spellId); } else - TC_LOG_ERROR("spells", "Player::addSpell: Non-existing spell #%u requested from SpellStore.", spellId); + TC_LOG_ERROR("spells", "Player::AddSpell: Spell (ID: %u) does not exist", spellId); return false; } @@ -3245,12 +3248,12 @@ bool Player::AddSpell(uint32 spellId, bool active, bool learning, bool dependent // do character spell book cleanup (all characters) if (!IsInWorld() && !learning) // spell load case { - TC_LOG_ERROR("spells", "Player::addSpell: Broken spell #%u, learning this spell is not allowed. Deleting this spell for all characters in `character_spell`.", spellId); + TC_LOG_ERROR("spells", "Player::AddSpell: Spell (ID: %u) is invalid. deleting for all characters in `character_spell` and `character_talent`.", spellId); DeleteSpellFromAllPlayers(spellId); } else - TC_LOG_ERROR("spells", "Player::addSpell: Broken spell #%u, learning this spell is not allowed.", spellId); + TC_LOG_ERROR("spells", "Player::AddSpell: Spell (ID: %u) is invalid", spellId); return false; } @@ -4543,7 +4546,8 @@ void Player::DeleteFromDB(ObjectGuid playerguid, uint32 accountId, bool updateRe break; } default: - TC_LOG_ERROR("entities.player", "Player::DeleteFromDB: Unsupported delete method: %u.", charDelete_method); + TC_LOG_ERROR("entities.player", "Player::DeleteFromDB: Tried to delete player (%s) with unsupported delete method (%u).", + playerguid.ToString().c_str(), charDelete_method); return; } @@ -4572,11 +4576,11 @@ void Player::DeleteOldCharacters() * * @see Player::DeleteFromDB * - * @param keepDays overrite the config option by another amount of days + * @param keepDays overwrite the config option by another amount of days */ void Player::DeleteOldCharacters(uint32 keepDays) { - TC_LOG_INFO("entities.player", "Player::DeleteOldChars: Removing characters older than %u day(s)", keepDays); + TC_LOG_INFO("entities.player", "Player::DeleteOldCharacters: Deleting all characters which have been deleted %u days before...", keepDays); PreparedStatement* stmt = CharacterDatabase.GetPreparedStatement(CHAR_SEL_CHAR_OLD_CHARS); stmt->setUInt32(0, uint32(time(nullptr) - time_t(keepDays * DAY))); @@ -4584,7 +4588,7 @@ void Player::DeleteOldCharacters(uint32 keepDays) if (result) { - TC_LOG_DEBUG("entities.player", "Player::DeleteOldChars: " UI64FMTD " character(s) to remove", result->GetRowCount()); + TC_LOG_DEBUG("entities.player", "Player::DeleteOldCharacters: Found " UI64FMTD " character(s) to delete", result->GetRowCount()); do { Field* fields = result->Fetch(); @@ -4633,7 +4637,7 @@ void Player::BuildPlayerRepop() WorldLocation corpseLocation = GetCorpseLocation(); if (corpseLocation.GetMapId() == GetMapId()) { - TC_LOG_ERROR("entities.player", "BuildPlayerRepop: player %s(%d) already has a corpse", GetName().c_str(), GetGUID().GetCounter()); + TC_LOG_ERROR("entities.player", "Player::BuildPlayerRepop: Player '%s' (%s) already has a corpse", GetName().c_str(), GetGUID().ToString().c_str()); return; } @@ -4641,7 +4645,7 @@ void Player::BuildPlayerRepop() Corpse* corpse = CreateCorpse(); if (!corpse) { - TC_LOG_ERROR("entities.player", "Error creating corpse for Player %s [%u]", GetName().c_str(), GetGUID().GetCounter()); + TC_LOG_ERROR("entities.player", "Player::BuildPlayerRepop: Error creating corpse for player '%s' (%s)", GetName().c_str(), GetGUID().ToString().c_str()); return; } GetMap()->AddToMap(corpse); @@ -5043,7 +5047,8 @@ uint32 Player::DurabilityRepair(uint16 pos, bool cost, float discountMod, bool g DurabilityCostsEntry const* dcost = sDurabilityCostsStore.LookupEntry(ditemProto->ItemLevel); if (!dcost) { - TC_LOG_ERROR("entities.player.items", "RepairDurability: Wrong item level %u", ditemProto->ItemLevel); + TC_LOG_ERROR("entities.player.items", "Player::DurabilityRepair: Player '%s' (%s) tried to repair an item (ItemID: %u) with invalid item level %u", + GetName().c_str(), GetGUID().ToString().c_str(), ditemProto->ItemId, ditemProto->ItemLevel); return TotalCost; } @@ -5051,7 +5056,8 @@ uint32 Player::DurabilityRepair(uint16 pos, bool cost, float discountMod, bool g DurabilityQualityEntry const* dQualitymodEntry = sDurabilityQualityStore.LookupEntry(dQualitymodEntryId); if (!dQualitymodEntry) { - TC_LOG_ERROR("entities.player.items", "RepairDurability: Wrong dQualityModEntry %u", dQualitymodEntryId); + TC_LOG_ERROR("entities.player.items", "Player::DurabilityRepair: Player '%s' (%s) tried to repair an item (ItemID: %u) with invalid QualitymodEntry %u", + GetName().c_str(), GetGUID().ToString().c_str(), ditemProto->ItemId, dQualitymodEntryId); return TotalCost; } @@ -5067,7 +5073,8 @@ uint32 Player::DurabilityRepair(uint16 pos, bool cost, float discountMod, bool g { if (GetGuildId() == 0) { - TC_LOG_DEBUG("entities.player.items", "You are not member of a guild."); + TC_LOG_DEBUG("entities.player.items", "Player::DurabilityRepair: Player '%s' (%s) tried to repair item in a guild bank but is not member of a guild", + GetName().c_str(), GetGUID().ToString().c_str()); return TotalCost; } @@ -5082,7 +5089,8 @@ uint32 Player::DurabilityRepair(uint16 pos, bool cost, float discountMod, bool g } else if (!HasEnoughMoney(costs)) { - TC_LOG_DEBUG("entities.player.items", "You do not have enough money."); + TC_LOG_DEBUG("entities.player.items", "Player::DurabilityRepair: Player '%s' (%s) has not enough money to repair item", + GetName().c_str(), GetGUID().ToString().c_str()); return TotalCost; } else @@ -5184,7 +5192,7 @@ void Player::CleanupChannels() if (ChannelMgr* cMgr = ChannelMgr::forTeam(GetTeam())) cMgr->LeftChannel(ch->GetName()); // deleted channel if empty } - TC_LOG_DEBUG("chat.system", "Player %s: channels cleaned up!", GetName().c_str()); + TC_LOG_DEBUG("chat.system", "Player::CleanupChannels: Channels of player '%s' (%s) cleaned up.", GetName().c_str(), GetGUID().ToString().c_str()); } void Player::UpdateLocalChannels(uint32 newZone) @@ -5292,7 +5300,8 @@ void Player::HandleBaseModValue(BaseModGroup modGroup, BaseModType modType, floa { if (modGroup >= BASEMOD_END || modType >= MOD_END) { - TC_LOG_ERROR("spells", "ERROR in HandleBaseModValue(): Non-existing BaseModGroup or wrong BaseModType!"); + TC_LOG_ERROR("spells", "Player::HandleBaseModValue: Invalid BaseModGroup/BaseModType (%u/%u) for player '%s' (%s)", + modGroup, modType, GetName().c_str(), GetGUID().ToString().c_str()); return; } @@ -5318,7 +5327,8 @@ float Player::GetBaseModValue(BaseModGroup modGroup, BaseModType modType) const { if (modGroup >= BASEMOD_END || modType >= MOD_END) { - TC_LOG_ERROR("spells", "Attempt to access non-existing BaseModGroup or wrong BaseModType!"); + TC_LOG_ERROR("spells", "Player::GetBaseModValue: Invalid BaseModGroup/BaseModType (%u/%u) for player '%s' (%s)", + modGroup, modType, GetName().c_str(), GetGUID().ToString().c_str()); return 0.0f; } @@ -5332,7 +5342,8 @@ float Player::GetTotalBaseModValue(BaseModGroup modGroup) const { if (modGroup >= BASEMOD_END) { - TC_LOG_ERROR("spells", "Wrong BaseModGroup in GetTotalBaseModValue()!"); + TC_LOG_ERROR("spells", "Player::GetTotalBaseModValue: Invalid BaseModGroup (%u) for player '%s' (%s)", + modGroup, GetName().c_str(), GetGUID().ToString().c_str()); return 0.0f; } @@ -5704,7 +5715,8 @@ inline int SkillGainChance(uint32 SkillValue, uint32 GrayLevel, uint32 GreenLeve bool Player::UpdateCraftSkill(uint32 spellid) { - TC_LOG_DEBUG("entities.player.skills", "UpdateCraftSkill spellid %d", spellid); + TC_LOG_DEBUG("entities.player.skills", "Player::UpdateCraftSkill: Player '%s' (%s), SpellID: %d", + GetName().c_str(), GetGUID().ToString().c_str(), spellid); SkillLineAbilityMapBounds bounds = sSpellMgr->GetSkillLineAbilityMapBounds(spellid); @@ -5736,7 +5748,8 @@ bool Player::UpdateCraftSkill(uint32 spellid) bool Player::UpdateGatherSkill(uint32 SkillId, uint32 SkillValue, uint32 RedLevel, uint32 Multiplicator) { - TC_LOG_DEBUG("entities.player.skills", "UpdateGatherSkill(SkillId %d SkillLevel %d RedLevel %d)", SkillId, SkillValue, RedLevel); + TC_LOG_DEBUG("entities.player.skills", "Player::UpdateGatherSkill: Player '%s' (%s), SkillID: %u, SkillLevel: %u, RedLevel: %u)", + GetName().c_str(), GetGUID().ToString().c_str(), SkillId, SkillValue, RedLevel); uint32 gathering_skill_gain = sWorld->getIntConfig(CONFIG_SKILL_GAIN_GATHERING); @@ -5764,7 +5777,7 @@ bool Player::UpdateGatherSkill(uint32 SkillId, uint32 SkillValue, uint32 RedLeve bool Player::UpdateFishingSkill() { - TC_LOG_DEBUG("entities.player.skills", "UpdateFishingSkill"); + TC_LOG_DEBUG("entities.player.skills", "Player::UpdateFishingSkill: Player '%s' (%s)", GetName().c_str(), GetGUID().ToString().c_str()); uint32 SkillValue = GetPureSkillValue(SKILL_FISHING); @@ -5783,13 +5796,15 @@ static const size_t bonusSkillLevelsSize = sizeof(bonusSkillLevels) / sizeof(uin bool Player::UpdateSkillPro(uint16 SkillId, int32 Chance, uint32 step) { - TC_LOG_DEBUG("entities.player.skills", "UpdateSkillPro(SkillId %d, Chance %3.1f%%)", SkillId, Chance / 10.0f); + TC_LOG_DEBUG("entities.player.skills", "Player::UpdateSkillPro: Player '%s' (%s), SkillID: %u, Chance: %3.1f%%)", + GetName().c_str(), GetGUID().ToString().c_str(), SkillId, Chance / 10.0f); if (!SkillId) return false; if (Chance <= 0) // speedup in 0 chance case { - TC_LOG_DEBUG("entities.player.skills", "Player::UpdateSkillPro Chance=%3.1f%% missed", Chance / 10.0f); + TC_LOG_DEBUG("entities.player.skills", "Player::UpdateSkillPro: Player '%s' (%s), SkillID: %u, Chance: %3.1f%% missed", + GetName().c_str(), GetGUID().ToString().c_str(), SkillId, Chance / 10.0f); return false; } @@ -5828,11 +5843,13 @@ bool Player::UpdateSkillPro(uint16 SkillId, int32 Chance, uint32 step) } UpdateSkillEnchantments(SkillId, SkillValue, new_value); UpdateAchievementCriteria(ACHIEVEMENT_CRITERIA_TYPE_REACH_SKILL_LEVEL, SkillId); - TC_LOG_DEBUG("entities.player.skills", "Player::UpdateSkillPro Chance=%3.1f%% taken", Chance / 10.0f); + TC_LOG_DEBUG("entities.player.skills", "Player::UpdateSkillPro: Player '%s' (%s), SkillID: %u, Chance: %3.1f%% taken", + GetName().c_str(), GetGUID().ToString().c_str(), SkillId, Chance / 10.0f); return true; } - TC_LOG_DEBUG("entities.player.skills", "Player::UpdateSkillPro Chance=%3.1f%% missed", Chance / 10.0f); + TC_LOG_DEBUG("entities.player.skills", "Player::UpdateSkillPro: Player '%s' (%s), SkillID: %u, Chance: %3.1f%% missed", + GetName().c_str(), GetGUID().ToString().c_str(), SkillId, Chance / 10.0f); return false; } @@ -6066,7 +6083,8 @@ void Player::SetSkill(uint16 id, uint16 step, uint16 newVal, uint16 maxVal) SkillLineEntry const* pSkill = sSkillLineStore.LookupEntry(id); if (!pSkill) { - TC_LOG_ERROR("entities.player.skills", "Skill not found in SkillLineStore: skill #%u", id); + TC_LOG_ERROR("misc", "Player::SetSkill: Skill (SkillID: %u) not found in SkillLineStore for player '%s' (%s)", + id, GetName().c_str(), GetGUID().ToString().c_str()); return; } @@ -6248,20 +6266,22 @@ void Player::SendActionButtons(uint32 state) const } GetSession()->SendPacket(&data); - TC_LOG_DEBUG("network", "SMSG_ACTION_BUTTONS sent '%u' spec '%u' Sent", GetGUID().GetCounter(), m_activeSpec); + } bool Player::IsActionButtonDataValid(uint8 button, uint32 action, uint8 type) const { if (button >= MAX_ACTION_BUTTONS) { - TC_LOG_DEBUG("entities.player", "Action %u not added into button %u for player %s (GUID: %u): button must be < %u", action, button, GetName().c_str(), GetGUID().GetCounter(), MAX_ACTION_BUTTONS ); + TC_LOG_ERROR("entities.player", "Player::IsActionButtonDataValid: Action %u not added into button %u for player %s (%s): button must be < %u", + action, button, GetName().c_str(), GetGUID().ToString().c_str(), MAX_ACTION_BUTTONS); return false; } if (action >= MAX_ACTION_BUTTON_ACTION_VALUE) { - TC_LOG_DEBUG("entities.player", "Action %u not added into button %u for player %s (GUID: %u): action must be < %u", action, button, GetName().c_str(), GetGUID().GetCounter(), MAX_ACTION_BUTTON_ACTION_VALUE); + TC_LOG_ERROR("entities.player", "Player::IsActionButtonDataValid: Action %u not added into button %u for player %s (%s): action must be < %u", + action, button, GetName().c_str(), GetGUID().ToString().c_str(), MAX_ACTION_BUTTON_ACTION_VALUE); return false; } @@ -6270,20 +6290,23 @@ bool Player::IsActionButtonDataValid(uint8 button, uint32 action, uint8 type) co case ACTION_BUTTON_SPELL: if (!sSpellMgr->GetSpellInfo(action)) { - TC_LOG_DEBUG("entities.player", "Spell action %u not added into button %u for player %s (GUID: %u): spell does not exist", action, button, GetName().c_str(), GetGUID().GetCounter()); + TC_LOG_ERROR("entities.player", "Player::IsActionButtonDataValid: Spell action %u not added into button %u for player %s (%s): spell not exist", + action, button, GetName().c_str(), GetGUID().ToString().c_str()); return false; } if (!HasSpell(action)) { - TC_LOG_DEBUG("entities.player", "Spell action %u not added into button %u for player %s (GUID: %u): player does not know this spell", action, button, GetName().c_str(), GetGUID().GetCounter()); + TC_LOG_ERROR("entities.player", "Player::IsActionButtonDataValid: Spell action %u not added into button %u for player %s (%s): player don't known this spell", + action, button, GetName().c_str(), GetGUID().ToString().c_str()); return false; } break; case ACTION_BUTTON_ITEM: if (!sObjectMgr->GetItemTemplate(action)) { - TC_LOG_DEBUG("entities.player", "Item action %u not added into button %u for player %s (GUID: %u): item does not exist", action, button, GetName().c_str(), GetGUID().GetCounter()); + TC_LOG_ERROR("entities.player", "Player::IsActionButtonDataValid: Item action %u not added into button %u for player %s (%s): item not exist", + action, button, GetName().c_str(), GetGUID().ToString().c_str()); return false; } break; @@ -6293,7 +6316,7 @@ bool Player::IsActionButtonDataValid(uint8 button, uint32 action, uint8 type) co case ACTION_BUTTON_EQSET: break; default: - TC_LOG_DEBUG("entities.player", "Unknown action type %u", type); + TC_LOG_ERROR("entities.player", "Player::IsActionButtonDataValid: Unknown action type %u", type); return false; // other cases not checked at this moment } @@ -6311,7 +6334,8 @@ ActionButton* Player::addActionButton(uint8 button, uint32 action, uint8 type) // set data and update to CHANGED if not NEW ab.SetActionAndType(action, ActionButtonType(type)); - TC_LOG_DEBUG("entities.player", "Player '%u' Added Action '%u' (type %u) to Button '%u'", GetGUID().GetCounter(), action, type, button); + TC_LOG_DEBUG("entities.player", "Player::AddActionButton: Player '%s' (%s) added action '%u' (type %u) to button '%u'", + GetName().c_str(), GetGUID().ToString().c_str(), action, type, button); return &ab; } @@ -6326,7 +6350,8 @@ void Player::removeActionButton(uint8 button) else buttonItr->second.uState = ACTIONBUTTON_DELETED; // saved, will deleted at next save - TC_LOG_DEBUG("entities.player", "Action Button '%u' Removed from Player '%u'", button, GetGUID().GetCounter()); + TC_LOG_DEBUG("entities.player", "Player::RemoveActionButton: Player '%s' (%s) removed action button '%u'", + GetName().c_str(), GetGUID().ToString().c_str(), button); } ActionButton const* Player::GetActionButton(uint8 button) @@ -7224,7 +7249,8 @@ void Player::DuelComplete(DuelCompleteType type) if (!duel) return; - TC_LOG_DEBUG("entities.unit", "Duel Complete %s %s", GetName().c_str(), duel->opponent->GetName().c_str()); + TC_LOG_DEBUG("entities.unit", "Player::DuelComplete: Player '%s' (%s), Opponent: '%s' (%s)", + GetName().c_str(), GetGUID().ToString().c_str(), duel->opponent->GetName().c_str(), duel->opponent->GetGUID().ToString().c_str()); WorldPacket data(SMSG_DUEL_COMPLETE, (1)); data << (uint8)((type != DUEL_INTERRUPTED) ? 1 : 0); @@ -7348,7 +7374,7 @@ void Player::_ApplyItemMods(Item* item, uint8 slot, bool apply) if (item->IsBroken()) return; - TC_LOG_DEBUG("entities.player.items", "applying mods for item %u ", item->GetGUID().GetCounter()); + TC_LOG_DEBUG("entities.player.items", "Player::_ApplyItemMods: Applying mods for item %s", item->GetGUID().ToString().c_str()); uint8 attacktype = Player::GetAttackBySlot(slot); @@ -7366,7 +7392,7 @@ void Player::_ApplyItemMods(Item* item, uint8 slot, bool apply) ApplyItemEquipSpell(item, apply); ApplyEnchantment(item, apply); - TC_LOG_DEBUG("entities.player.items", "_ApplyItemMods complete."); + TC_LOG_DEBUG("entities.player.items", "Player::_ApplyItemMods: completed"); } void Player::_ApplyItemBonuses(ItemTemplate const* proto, uint8 slot, bool apply, bool only_level_scale /*= false*/) @@ -7845,7 +7871,8 @@ void Player::ApplyEquipSpell(SpellInfo const* spellInfo, Item* item, bool apply, return; } - TC_LOG_DEBUG("entities.player", "WORLD: cast %s Equip spellId - %i", (item ? "item" : "itemset"), spellInfo->Id); + TC_LOG_DEBUG("entities.player", "Player::ApplyEquipSpell: Player '%s' (%s) cast %s equip spell (ID: %i)", + GetName().c_str(), GetGUID().ToString().c_str(), (item ? "item" : "itemset"), spellInfo->Id); CastSpell(this, spellInfo, true, item); } @@ -7951,7 +7978,8 @@ void Player::CastItemCombatSpell(Unit* target, WeaponAttackType attType, uint32 SpellInfo const* spellInfo = sSpellMgr->GetSpellInfo(spellData.SpellId); if (!spellInfo) { - TC_LOG_ERROR("entities.player.items", "WORLD: Unknown item spellid %i", spellData.SpellId); + TC_LOG_ERROR("entities.player.items", "Player::CastItemCombatSpell: Player '%s' (%s) cast unknown item spell (ID: %i)", + GetName().c_str(), GetGUID().ToString().c_str(), spellData.SpellId); continue; } @@ -8006,8 +8034,8 @@ void Player::CastItemCombatSpell(Unit* target, WeaponAttackType attType, uint32 SpellInfo const* spellInfo = sSpellMgr->GetSpellInfo(pEnchant->spellid[s]); if (!spellInfo) { - TC_LOG_ERROR("entities.player.items", "Player::CastItemCombatSpell(GUID: %u, name: %s, enchant: %i): unknown spell %i is cast, ignoring...", - GetGUID().GetCounter(), GetName().c_str(), pEnchant->ID, pEnchant->spellid[s]); + TC_LOG_ERROR("entities.player.items", "Player::CastItemCombatSpell: Player '%s' (%s) cast unknown spell (EnchantID: %u, SpellID: %i), ignoring", + GetName().c_str(), GetGUID().ToString().c_str(), pEnchant->ID, pEnchant->spellid[s]); continue; } @@ -8080,7 +8108,7 @@ void Player::CastItemUseSpell(Item* item, SpellCastTargets const& targets, uint8 SpellInfo const* spellInfo = sSpellMgr->GetSpellInfo(spellData.SpellId); if (!spellInfo) { - TC_LOG_ERROR("entities.player", "Player::CastItemUseSpell: Item (Entry: %u) has wrong spell id %u, ignoring.", proto->ItemId, spellData.SpellId); + TC_LOG_ERROR("entities.player", "Player::CastItemUseSpell: Item (Entry: %u) has wrong spell id %u, ignoring", proto->ItemId, spellData.SpellId); continue; } @@ -8107,7 +8135,7 @@ void Player::CastItemUseSpell(Item* item, SpellCastTargets const& targets, uint8 SpellInfo const* spellInfo = sSpellMgr->GetSpellInfo(pEnchant->spellid[s]); if (!spellInfo) { - TC_LOG_ERROR("entities.player", "Player::CastItemUseSpell Enchant %i casts unknown spell %i.", pEnchant->ID, pEnchant->spellid[s]); + TC_LOG_ERROR("entities.player", "Player::CastItemUseSpell: Enchant %i, cast unknown spell %i", pEnchant->ID, pEnchant->spellid[s]); continue; } @@ -8341,10 +8369,10 @@ void Player::SendLoot(ObjectGuid guid, LootType loot_type) Loot* loot; PermissionTypes permission = ALL_PERMISSION; - TC_LOG_DEBUG("loot", "Player::SendLoot"); + TC_LOG_DEBUG("loot", "Player::SendLoot: Player: '%s' (%s), Loot: %s", + GetName().c_str(), GetGUID().ToString().c_str(), guid.ToString().c_str()); if (guid.IsGameObject()) { - TC_LOG_DEBUG("loot", "IS_GAMEOBJECT_GUID(guid)"); GameObject* go = GetMap()->GetGameObject(guid); // not check distance for GO in case owned GO (fishing bobber case, for example) @@ -9362,7 +9390,7 @@ uint32 Player::GetXPRestBonus(uint32 xp) SetRestBonus(GetRestBonus() - rested_bonus); - TC_LOG_DEBUG("entities.player", "GetXPRestBonus: Player %s (%u) gains %u xp (+%u Rested Bonus). Rested points=%f", GetName().c_str(), GetGUID().GetCounter(), xp+rested_bonus, rested_bonus, GetRestBonus()); + TC_LOG_DEBUG("entities.player", "Player::GetXPRestBonus: Player '%s' (%s) gain %u xp (+%u Rested Bonus). Rested points=%f", GetGUID().ToString().c_str(), GetName().c_str(), xp + rested_bonus, rested_bonus, GetRestBonus()); return rested_bonus; } @@ -10428,7 +10456,7 @@ InventoryResult Player::CanStoreItem_InInventorySlots(uint8 slot_begin, uint8 sl InventoryResult Player::CanStoreItem(uint8 bag, uint8 slot, ItemPosCountVec &dest, uint32 entry, uint32 count, Item* pItem, bool swap, uint32* no_space_count) const { - TC_LOG_DEBUG("entities.player.items", "STORAGE: CanStoreItem bag = %u, slot = %u, item = %u, count = %u", bag, slot, entry, count); + TC_LOG_DEBUG("entities.player.items", "Player::CanStoreItem: Bag: %u, Slot: %u, Item: %u, Count: %u", bag, slot, entry, count); ItemTemplate const* pProto = sObjectMgr->GetItemTemplate(entry); if (!pProto) @@ -10913,7 +10941,8 @@ InventoryResult Player::CanStoreItems(Item** items, int count, uint32* itemLimit if (!item) continue; - TC_LOG_DEBUG("entities.player.items", "STORAGE: CanStoreItems %i. item = %u, count = %u", k + 1, item->GetEntry(), item->GetCount()); + TC_LOG_DEBUG("entities.player.items", "Player::CanStoreItems: Player '%s' (%s), Index: %i ItemID: %u, Count: %u", + GetName().c_str(), GetGUID().ToString().c_str(), k + 1, item->GetEntry(), item->GetCount()); ItemTemplate const* pProto = item->GetTemplate(); // strange item @@ -11130,7 +11159,8 @@ InventoryResult Player::CanEquipItem(uint8 slot, uint16 &dest, Item* pItem, bool dest = 0; if (pItem) { - TC_LOG_DEBUG("entities.player.items", "STORAGE: CanEquipItem slot = %u, item = %u, count = %u", slot, pItem->GetEntry(), pItem->GetCount()); + TC_LOG_DEBUG("entities.player.items", "Player::CanEquipItem: Player '%s' (%s), Slot: %u, Item: %u, Count: %u", + GetName().c_str(), GetGUID().ToString().c_str(), slot, pItem->GetEntry(), pItem->GetCount()); ItemTemplate const* pProto = pItem->GetTemplate(); if (pProto) { @@ -11300,7 +11330,8 @@ InventoryResult Player::CanUnequipItem(uint16 pos, bool swap) const if (!pItem) return EQUIP_ERR_OK; - TC_LOG_DEBUG("entities.player.items", "STORAGE: CanUnequipItem slot = %u, item = %u, count = %u", pos, pItem->GetEntry(), pItem->GetCount()); + TC_LOG_DEBUG("entities.player.items", "Player::CanUnequipItem: Player '%s' (%s), Slot: %u, Item: %u, Count: %u", + GetName().c_str(), GetGUID().ToString().c_str(), pos, pItem->GetEntry(), pItem->GetCount()); ItemTemplate const* pProto = pItem->GetTemplate(); if (!pProto) @@ -11336,7 +11367,8 @@ InventoryResult Player::CanBankItem(uint8 bag, uint8 slot, ItemPosCountVec &dest uint32 count = pItem->GetCount(); - TC_LOG_DEBUG("entities.player.items", "STORAGE: CanBankItem bag = %u, slot = %u, item = %u, count = %u", bag, slot, pItem->GetEntry(), pItem->GetCount()); + TC_LOG_DEBUG("entities.player.items", "Player::CanBankItem: Player '%s' (%s), Bag: %u, Slot: %u, Item: %u, Count: %u", + GetName().c_str(), GetGUID().ToString().c_str(), bag, slot, pItem->GetEntry(), pItem->GetCount()); ItemTemplate const* pProto = pItem->GetTemplate(); if (!pProto) return swap ? EQUIP_ERR_ITEMS_CANT_BE_SWAPPED : EQUIP_ERR_ITEM_NOT_FOUND; @@ -11352,8 +11384,8 @@ InventoryResult Player::CanBankItem(uint8 bag, uint8 slot, ItemPosCountVec &dest uint8 pItemslot = pItem->GetSlot(); if (pItemslot >= CURRENCYTOKEN_SLOT_START && pItemslot < CURRENCYTOKEN_SLOT_END) { - TC_LOG_ERROR("entities.player", "Possible hacking attempt: Player %s [guid: %u] tried to move token [guid: %u, entry: %u] out of the currency bag!", - GetName().c_str(), GetGUID().GetCounter(), pItem->GetGUID().GetCounter(), pProto->ItemId); + TC_LOG_ERROR("entities.player", "Possible hacking attempt: Player %s (%s) tried to move token [%s entry: %u] out of the currency bag!", + GetName().c_str(), GetGUID().ToString().c_str(), pItem->GetGUID().ToString().c_str(), pProto->ItemId); return EQUIP_ERR_ITEMS_CANT_BE_SWAPPED; } @@ -11520,7 +11552,8 @@ InventoryResult Player::CanUseItem(Item* pItem, bool not_loading) const { if (pItem) { - TC_LOG_DEBUG("entities.player.items", "STORAGE: CanUseItem item = %u", pItem->GetEntry()); + TC_LOG_DEBUG("entities.player.items", "Player::CanUseItem: Player '%s' (%s), Item: %u", + GetName().c_str(), GetGUID().ToString().c_str(), pItem->GetEntry()); if (!IsAlive() && not_loading) return EQUIP_ERR_YOU_ARE_DEAD; @@ -11831,7 +11864,8 @@ Item* Player::_StoreItem(uint16 pos, Item* pItem, uint32 count, bool clone, bool uint8 bag = pos >> 8; uint8 slot = pos & 255; - TC_LOG_DEBUG("entities.player.items", "STORAGE: StoreItem bag = %u, slot = %u, item = %u, count = %u, guid = %u", bag, slot, pItem->GetEntry(), count, pItem->GetGUID().GetCounter()); + TC_LOG_DEBUG("entities.player.items", "Player::_StoreItem: Player '%s' (%s), Bag: %u, Slot: %u, Item: %u (%s), Count: %u", + GetName().c_str(), GetGUID().ToString().c_str(), bag, slot, pItem->GetEntry(), pItem->GetGUID().ToString().c_str(), count); Item* pItem2 = GetItemByPos(bag, slot); @@ -11977,7 +12011,8 @@ Item* Player::EquipItem(uint16 pos, Item* pItem, bool update) SpellInfo const* spellProto = sSpellMgr->GetSpellInfo(cooldownSpell); if (!spellProto) - TC_LOG_ERROR("entities.player", "Weapon switch cooldown spell %u could not be found in Spell.dbc", cooldownSpell); + TC_LOG_ERROR("entities.player", "Player::EquipItem: Weapon switch cooldown spell %u for player '%s' (%s) couldn't be found in Spell.dbc", + cooldownSpell, GetName().c_str(), GetGUID().ToString().c_str()); else { m_weaponChangeTimer = spellProto->StartRecoveryTime; @@ -12097,7 +12132,8 @@ void Player::VisualizeItem(uint8 slot, Item* pItem) if (pItem->GetTemplate()->Bonding == BIND_WHEN_EQUIPED || pItem->GetTemplate()->Bonding == BIND_WHEN_PICKED_UP || pItem->GetTemplate()->Bonding == BIND_QUEST_ITEM) pItem->SetBinding(true); - TC_LOG_DEBUG("entities.player.items", "STORAGE: EquipItem slot = %u, item = %u", slot, pItem->GetEntry()); + TC_LOG_DEBUG("entities.player.items", "Player::SetVisibleItemSlot: Player '%s' (%s), Slot: %u, Item: %u", + GetName().c_str(), GetGUID().ToString().c_str(), slot, pItem->GetEntry()); m_items[slot] = pItem; SetGuidValue(PLAYER_FIELD_INV_SLOT_HEAD + (slot * 2), pItem->GetGUID()); @@ -12127,7 +12163,8 @@ void Player::RemoveItem(uint8 bag, uint8 slot, bool update) Item* pItem = GetItemByPos(bag, slot); if (pItem) { - TC_LOG_DEBUG("entities.player.items", "STORAGE: RemoveItem bag = %u, slot = %u, item = %u", bag, slot, pItem->GetEntry()); + TC_LOG_DEBUG("entities.player.items", "Player::RemoveItem: Player '%s' (%s), Bag: %u, Slot: %u, Item: %u", + GetName().c_str(), GetGUID().ToString().c_str(), bag, slot, pItem->GetEntry()); RemoveEnchantmentDurations(pItem); RemoveItemDurations(pItem); @@ -12246,7 +12283,8 @@ void Player::DestroyItem(uint8 bag, uint8 slot, bool update) Item* pItem = GetItemByPos(bag, slot); if (pItem) { - TC_LOG_DEBUG("entities.player.items", "STORAGE: DestroyItem bag = %u, slot = %u, item = %u", bag, slot, pItem->GetEntry()); + TC_LOG_DEBUG("entities.player.items", "Player::DestroyItem: Player '%s' (%s), Bag: %u, Slot: %u, Item: %u", + GetName().c_str(), GetGUID().ToString().c_str(), bag, slot, pItem->GetEntry()); // Also remove all contained items if the item is a bag. // This if () prevents item saving crashes if the condition for a bag to be empty before being destroyed was bypassed somehow. if (pItem->IsNotEmptyBag()) @@ -12344,7 +12382,8 @@ void Player::DestroyItem(uint8 bag, uint8 slot, bool update) void Player::DestroyItemCount(uint32 itemEntry, uint32 count, bool update, bool unequip_check) { - TC_LOG_DEBUG("entities.player.items", "STORAGE: DestroyItemCount item = %u, count = %u", itemEntry, count); + TC_LOG_DEBUG("entities.player.items", "Player::DestroyItemCount: Player '%s' (%s), Item: %u, Count: %u", + GetName().c_str(), GetGUID().ToString().c_str(), itemEntry, count); uint32 remcount = 0; // in inventory @@ -12535,7 +12574,8 @@ void Player::DestroyItemCount(uint32 itemEntry, uint32 count, bool update, bool void Player::DestroyZoneLimitedItem(bool update, uint32 new_zone) { - TC_LOG_DEBUG("entities.player.items", "STORAGE: DestroyZoneLimitedItem in map %u and area %u", GetMapId(), new_zone); + TC_LOG_DEBUG("entities.player.items", "Player::DestroyZoneLimitedItem: In map %u and area %u for player '%s' (%s)", + GetMapId(), new_zone, GetName().c_str(), GetGUID().ToString().c_str()); // in inventory for (uint8 i = INVENTORY_SLOT_ITEM_START; i < INVENTORY_SLOT_ITEM_END; i++) @@ -12567,7 +12607,8 @@ void Player::DestroyConjuredItems(bool update) { // used when entering arena // destroys all conjured items - TC_LOG_DEBUG("entities.player.items", "STORAGE: DestroyConjuredItems"); + TC_LOG_DEBUG("entities.player.items", "Player::DestroyConjuredItems: Player '%s' (%s)", + GetName().c_str(), GetGUID().ToString().c_str()); // in inventory for (uint8 i = INVENTORY_SLOT_ITEM_START; i < INVENTORY_SLOT_ITEM_END; i++) @@ -12623,7 +12664,8 @@ void Player::DestroyItemCount(Item* pItem, uint32 &count, bool update) if (!pItem) return; - TC_LOG_DEBUG("entities.player.items", "STORAGE: DestroyItemCount item (GUID: %u, Entry: %u) count = %u", pItem->GetGUID().GetCounter(), pItem->GetEntry(), count); + TC_LOG_DEBUG("entities.player.items", "Player::DestroyItemCount: Player '%s' (%s), Item (%s, Entry: %u), Count: %u", + GetName().c_str(), GetGUID().ToString().c_str(), pItem->GetGUID().ToString().c_str(), pItem->GetEntry(), count); if (pItem->GetCount() <= count) { @@ -12686,7 +12728,8 @@ void Player::SplitItem(uint16 src, uint16 dst, uint32 count) return; } - TC_LOG_DEBUG("entities.player.items", "STORAGE: SplitItem bag = %u, slot = %u, item = %u, count = %u", dstbag, dstslot, pSrcItem->GetEntry(), count); + TC_LOG_DEBUG("entities.player.items", "Player::SplitItem: Player '%s' (%s), Bag: %u, Slot: %u, Item: %u, Count: %u", + GetName().c_str(), GetGUID().ToString().c_str(), dstbag, dstslot, pSrcItem->GetEntry(), count); Item* pNewItem = pSrcItem->CloneItem(count, this); if (!pNewItem) { @@ -12771,7 +12814,8 @@ void Player::SwapItem(uint16 src, uint16 dst) if (!pSrcItem) return; - TC_LOG_DEBUG("entities.player.items", "STORAGE: SwapItem bag = %u, slot = %u, item = %u", dstbag, dstslot, pSrcItem->GetEntry()); + TC_LOG_DEBUG("entities.player.items", "Player::SwapItem: Player '%s' (%s), Bag: %u, Slot: %u, Item: %u", + GetName().c_str(), GetGUID().ToString().c_str(), dstbag, dstslot, pSrcItem->GetEntry()); if (!IsAlive()) { @@ -13132,7 +13176,8 @@ void Player::AddItemToBuyBackSlot(Item* pItem) } RemoveItemFromBuyBackSlot(slot, true); - TC_LOG_DEBUG("entities.player.items", "STORAGE: AddItemToBuyBackSlot item = %u, slot = %u", pItem->GetEntry(), slot); + TC_LOG_DEBUG("entities.player.items", "Player::AddItemToBuyBackSlot: Player '%s' (%s), Item: %u, Slot: %u", + GetName().c_str(), GetGUID().ToString().c_str(), pItem->GetEntry(), slot); m_items[slot] = pItem; time_t base = time(nullptr); @@ -13154,7 +13199,8 @@ void Player::AddItemToBuyBackSlot(Item* pItem) Item* Player::GetItemFromBuyBackSlot(uint32 slot) { - TC_LOG_DEBUG("entities.player.items", "STORAGE: GetItemFromBuyBackSlot slot = %u", slot); + TC_LOG_DEBUG("entities.player.items", "Player::GetItemFromBuyBackSlot: Player '%s' (%s), Slot: %u", + GetName().c_str(), GetGUID().ToString().c_str(), slot); if (slot >= BUYBACK_SLOT_START && slot < BUYBACK_SLOT_END) return m_items[slot]; return nullptr; @@ -13162,7 +13208,8 @@ Item* Player::GetItemFromBuyBackSlot(uint32 slot) void Player::RemoveItemFromBuyBackSlot(uint32 slot, bool del) { - TC_LOG_DEBUG("entities.player.items", "STORAGE: RemoveItemFromBuyBackSlot slot = %u", slot); + TC_LOG_DEBUG("entities.player.items", "Player::RemoveItemFromBuyBackSlot: Player '%s' (%s), Slot: %u", + GetName().c_str(), GetGUID().ToString().c_str(), slot); if (slot >= BUYBACK_SLOT_START && slot < BUYBACK_SLOT_END) { Item* pItem = m_items[slot]; @@ -13188,7 +13235,7 @@ void Player::RemoveItemFromBuyBackSlot(uint32 slot, bool del) void Player::SendEquipError(InventoryResult msg, Item* pItem, Item* pItem2, uint32 itemid) const { - TC_LOG_DEBUG("network", "WORLD: Sent SMSG_INVENTORY_CHANGE_FAILURE (%u)", msg); + WorldPacket data(SMSG_INVENTORY_CHANGE_FAILURE, (msg == EQUIP_ERR_CANT_EQUIP_LEVEL_I ? 22 : 18)); data << uint8(msg); @@ -13231,7 +13278,6 @@ void Player::SendEquipError(InventoryResult msg, Item* pItem, Item* pItem2, uint void Player::SendBuyError(BuyResult msg, Creature* creature, uint32 item, uint32 param) const { - TC_LOG_DEBUG("network", "WORLD: Sent SMSG_BUY_FAILED"); WorldPacket data(SMSG_BUY_FAILED, (8+4+4+1)); data << uint64(creature ? creature->GetGUID() : ObjectGuid::Empty); data << uint32(item); @@ -13243,7 +13289,6 @@ void Player::SendBuyError(BuyResult msg, Creature* creature, uint32 item, uint32 void Player::SendSellError(SellResult msg, Creature* creature, ObjectGuid guid, uint32 param) const { - TC_LOG_DEBUG("network", "WORLD: Sent SMSG_SELL_ITEM"); WorldPacket data(SMSG_SELL_ITEM, (8+8+(param?4:0)+1)); // last check 2.0.10 data << uint64(creature ? creature->GetGUID() : ObjectGuid::Empty); data << uint64(guid); @@ -13313,7 +13358,8 @@ void Player::UpdateItemDuration(uint32 time, bool realtimeonly) if (m_itemDuration.empty()) return; - TC_LOG_DEBUG("entities.player.items", "Player::UpdateItemDuration(%u, %u)", time, realtimeonly); + TC_LOG_DEBUG("entities.player.items", "Player::UpdateItemDuration: Player '%s' (%s), Time: %u, RealTimeOnly: %u", + GetName().c_str(), GetGUID().ToString().c_str(), time, realtimeonly); for (ItemDurationList::const_iterator itr = m_itemDuration.begin(); itr != m_itemDuration.end();) { @@ -13795,7 +13841,8 @@ void Player::ApplyEnchantment(Item* item, EnchantmentSlot slot, bool apply, bool // nothing do.. break; default: - TC_LOG_ERROR("entities.player", "Unknown item enchantment (id = %d) display type: %d", enchant_id, enchant_display_type); + TC_LOG_ERROR("entities.player", "Player::ApplyEnchantment: Unknown item enchantment (ID: %u, DisplayType: %u) for player '%s' (%s)", + enchant_id, enchant_display_type, GetName().c_str(), GetGUID().ToString().c_str()); break; } /*switch (enchant_display_type)*/ } /*for*/ @@ -14129,7 +14176,8 @@ void Player::OnGossipSelect(WorldObject* source, uint32 gossipListId, uint32 men { if (gossipOptionId > GOSSIP_OPTION_QUESTGIVER) { - TC_LOG_ERROR("entities.player", "Player guid %u requested invalid gossip option for GameObject entry %u.", GetGUID().GetCounter(), source->GetEntry()); + TC_LOG_ERROR("entities.player", "Player '%s' (%s) requests invalid gossip option for GameObject (Entry: %u)", + GetName().c_str(), GetGUID().ToString().c_str(), source->GetEntry()); return; } } @@ -14233,7 +14281,8 @@ void Player::OnGossipSelect(WorldObject* source, uint32 gossipListId, uint32 men if (bgTypeId == BATTLEGROUND_TYPE_NONE) { - TC_LOG_ERROR("entities.player", "User (guid %u) requested battlegroundlist from an NPC who is not a battlemaster.", GetGUID().GetCounter()); + TC_LOG_ERROR("entities.player", "Player '%s' (%s) requested battlegroundlist from an invalid creature (%s)", + GetName().c_str(), GetGUID().ToString().c_str(), source->GetGUID().ToString().c_str()); return; } @@ -15106,7 +15155,8 @@ bool Player::SatisfyQuestSkill(Quest const* qInfo, bool msg) const if (msg) { SendCanTakeQuestResponse(INVALIDREASON_DONT_HAVE_REQ); - TC_LOG_DEBUG("misc", "SatisfyQuestSkill: Sent INVALIDREASON_DONT_HAVE_REQ (questId: %u) because player does not have required skill value.", qInfo->GetQuestId()); + TC_LOG_DEBUG("misc", "Player::SatisfyQuestSkill: Sent INVALIDREASON_DONT_HAVE_REQ (QuestID: %u) because player '%s' (%s) doesn't have the required skill value.", + qInfo->GetQuestId(), GetName().c_str(), GetGUID().ToString().c_str()); } return false; @@ -15122,7 +15172,8 @@ bool Player::SatisfyQuestLevel(Quest const* qInfo, bool msg) const if (msg) { SendCanTakeQuestResponse(INVALIDREASON_QUEST_FAILED_LOW_LEVEL); - TC_LOG_DEBUG("misc", "SatisfyQuestLevel: Sent INVALIDREASON_QUEST_FAILED_LOW_LEVEL (questId: %u) because player does not have required (min) level.", qInfo->GetQuestId()); + TC_LOG_DEBUG("misc", "Player::SatisfyQuestLevel: Sent INVALIDREASON_QUEST_FAILED_LOW_LEVEL (QuestID: %u) because player '%s' (%s) doesn't have the required (min) level.", + qInfo->GetQuestId(), GetName().c_str(), GetGUID().ToString().c_str()); } return false; } @@ -15132,7 +15183,8 @@ bool Player::SatisfyQuestLevel(Quest const* qInfo, bool msg) const if (msg) { SendCanTakeQuestResponse(INVALIDREASON_DONT_HAVE_REQ); // There doesn't seem to be a specific response for too high player level - TC_LOG_DEBUG("misc", "SatisfyQuestLevel: Sent INVALIDREASON_QUEST_FAILED_LOW_LEVEL (questId: %u) because player does not have required (max) level.", qInfo->GetQuestId()); + TC_LOG_DEBUG("misc", "Player::SatisfyQuestLevel: Sent INVALIDREASON_DONT_HAVE_REQ (QuestID: %u) because player '%s' (%s) doesn't have the required (max) level.", + qInfo->GetQuestId(), GetName().c_str(), GetGUID().ToString().c_str()); } return false; } @@ -15149,7 +15201,6 @@ bool Player::SatisfyQuestLog(bool msg) const { WorldPacket data(SMSG_QUESTLOG_FULL, 0); GetSession()->SendPacket(&data); - TC_LOG_DEBUG("network", "WORLD: Sent SMSG_QUESTLOG_FULL"); } return false; } @@ -15193,7 +15244,8 @@ bool Player::SatisfyQuestPreviousQuest(Quest const* qInfo, bool msg) if (msg) { SendCanTakeQuestResponse(INVALIDREASON_DONT_HAVE_REQ); - TC_LOG_DEBUG("misc", "SatisfyQuestPreviousQuest: Sent INVALIDREASON_DONT_HAVE_REQ (questId: %u) because player does not have the required quest(s) (1).", qInfo->GetQuestId()); + TC_LOG_DEBUG("misc", "Player::SatisfyQuestPreviousQuest: Sent INVALIDREASON_DONT_HAVE_REQ (QuestID: %u) because player '%s' (%s) doesn't have the required quest (1).", + qInfo->GetQuestId(), GetName().c_str(), GetGUID().ToString().c_str()); } return false; } @@ -15226,7 +15278,8 @@ bool Player::SatisfyQuestPreviousQuest(Quest const* qInfo, bool msg) if (msg) { SendCanTakeQuestResponse(INVALIDREASON_DONT_HAVE_REQ); - TC_LOG_DEBUG("misc", "SatisfyQuestPreviousQuest: Sent INVALIDREASON_DONT_HAVE_REQ (questId: %u) because player does not have the required quest(s) (2).", qInfo->GetQuestId()); + TC_LOG_DEBUG("misc", "Player::SatisfyQuestPreviousQuest: Sent INVALIDREASON_DONT_HAVE_REQ (QuestID: %u) because player '%s' (%s) doesn't have the required quest (2).", + qInfo->GetQuestId(), GetName().c_str(), GetGUID().ToString().c_str()); } return false; @@ -15242,7 +15295,8 @@ bool Player::SatisfyQuestPreviousQuest(Quest const* qInfo, bool msg) if (msg) { SendCanTakeQuestResponse(INVALIDREASON_DONT_HAVE_REQ); - TC_LOG_DEBUG("misc", "SatisfyQuestPreviousQuest: Sent INVALIDREASON_DONT_HAVE_REQ (questId: %u) because player does not have the required quest(s) (3).", qInfo->GetQuestId()); + TC_LOG_DEBUG("misc", "Player::SatisfyQuestPreviousQuest: Sent INVALIDREASON_DONT_HAVE_REQ (QuestID: %u) because player '%s' (%s) doesn't have required quest (3).", + qInfo->GetQuestId(), GetName().c_str(), GetGUID().ToString().c_str()); } return false; @@ -15260,7 +15314,8 @@ bool Player::SatisfyQuestClass(Quest const* qInfo, bool msg) const if (msg) { SendCanTakeQuestResponse(INVALIDREASON_DONT_HAVE_REQ); - TC_LOG_DEBUG("misc", "SatisfyQuestClass: Sent INVALIDREASON_DONT_HAVE_REQ (questId: %u) because player is not (one of) the required class(es).", qInfo->GetQuestId()); + TC_LOG_DEBUG("misc", "Player::SatisfyQuestClass: Sent INVALIDREASON_DONT_HAVE_REQ (QuestID: %u) because player '%s' (%s) doesn't have required class.", + qInfo->GetQuestId(), GetName().c_str(), GetGUID().ToString().c_str()); } return false; @@ -15279,7 +15334,8 @@ bool Player::SatisfyQuestRace(Quest const* qInfo, bool msg) const if (msg) { SendCanTakeQuestResponse(INVALIDREASON_QUEST_FAILED_WRONG_RACE); - TC_LOG_DEBUG("misc", "SatisfyQuestRace: Sent INVALIDREASON_QUEST_FAILED_WRONG_RACE (questId: %u) because player is not (one of) the required race(s).", qInfo->GetQuestId()); + TC_LOG_DEBUG("misc", "Player::SatisfyQuestRace: Sent INVALIDREASON_QUEST_FAILED_WRONG_RACE (QuestID: %u) because player '%s' (%s) doesn't have required race.", + qInfo->GetQuestId(), GetName().c_str(), GetGUID().ToString().c_str()); } return false; @@ -15295,7 +15351,8 @@ bool Player::SatisfyQuestReputation(Quest const* qInfo, bool msg) if (msg) { SendCanTakeQuestResponse(INVALIDREASON_DONT_HAVE_REQ); - TC_LOG_DEBUG("misc", "SatisfyQuestReputation: Sent INVALIDREASON_DONT_HAVE_REQ (questId: %u) because player does not have the required reputation (min).", qInfo->GetQuestId()); + TC_LOG_DEBUG("misc", "Player::SatisfyQuestReputation: Sent INVALIDREASON_DONT_HAVE_REQ (QuestID: %u) because player '%s' (%s) doesn't required reputation (min).", + qInfo->GetQuestId(), GetName().c_str(), GetGUID().ToString().c_str()); } return false; } @@ -15306,7 +15363,8 @@ bool Player::SatisfyQuestReputation(Quest const* qInfo, bool msg) if (msg) { SendCanTakeQuestResponse(INVALIDREASON_DONT_HAVE_REQ); - TC_LOG_DEBUG("misc", "SatisfyQuestReputation: Sent INVALIDREASON_DONT_HAVE_REQ (questId: %u) because player does not have the required reputation (max).", qInfo->GetQuestId()); + TC_LOG_DEBUG("misc", "SatisfyQuestReputation: Sent INVALIDREASON_DONT_HAVE_REQ (QuestID: %u) because player '%s' (%s) doesn't required reputation (max).", + qInfo->GetQuestId(), GetName().c_str(), GetGUID().ToString().c_str()); } return false; } @@ -15334,7 +15392,8 @@ bool Player::SatisfyQuestStatus(Quest const* qInfo, bool msg) const if (msg) { SendCanTakeQuestResponse(INVALIDREASON_QUEST_ALREADY_ON); - TC_LOG_DEBUG("misc", "SatisfyQuestStatus: Sent INVALIDREASON_QUEST_ALREADY_ON (questId: %u) because player quest status is not NONE.", qInfo->GetQuestId()); + TC_LOG_DEBUG("misc", "Player::SatisfyQuestStatus: Sent INVALIDREASON_QUEST_ALREADY_ON (QuestID: %u) because player '%s' (%s) quest status is not NONE.", + qInfo->GetQuestId(), GetName().c_str(), GetGUID().ToString().c_str()); } return false; } @@ -15348,7 +15407,8 @@ bool Player::SatisfyQuestConditions(Quest const* qInfo, bool msg) if (msg) { SendCanTakeQuestResponse(INVALIDREASON_DONT_HAVE_REQ); - TC_LOG_DEBUG("misc", "SatisfyQuestConditions: Sent INVALIDREASON_DONT_HAVE_REQ (questId: %u) because player does not meet the conditions.", qInfo->GetQuestId()); + TC_LOG_DEBUG("misc", "Player::SatisfyQuestConditions: Sent INVALIDREASON_DONT_HAVE_REQ (QuestID: %u) because player '%s' (%s) doesn't meet conditions.", + qInfo->GetQuestId(), GetName().c_str(), GetGUID().ToString().c_str()); } TC_LOG_DEBUG("condition", "Player::SatisfyQuestConditions: conditions not met for quest %u", qInfo->GetQuestId()); return false; @@ -15363,7 +15423,8 @@ bool Player::SatisfyQuestTimed(Quest const* qInfo, bool msg) const if (msg) { SendCanTakeQuestResponse(INVALIDREASON_QUEST_ONLY_ONE_TIMED); - TC_LOG_DEBUG("misc", "SatisfyQuestTimed: Sent INVALIDREASON_QUEST_ONLY_ONE_TIMED (questId: %u) because player is already on a timed quest.", qInfo->GetQuestId()); + TC_LOG_DEBUG("misc", "Player::SatisfyQuestTimed: Sent INVALIDREASON_QUEST_ONLY_ONE_TIMED (QuestID: %u) because player '%s' (%s) is already on a timed quest.", + qInfo->GetQuestId(), GetName().c_str(), GetGUID().ToString().c_str()); } return false; } @@ -15394,7 +15455,8 @@ bool Player::SatisfyQuestExclusiveGroup(Quest const* qInfo, bool msg) if (msg) { SendCanTakeQuestResponse(INVALIDREASON_DONT_HAVE_REQ); - TC_LOG_DEBUG("misc", "SatisfyQuestExclusiveGroup: Sent INVALIDREASON_DONT_HAVE_REQ (questId: %u) because player already did all daily quests in exclusive group.", qInfo->GetQuestId()); + TC_LOG_DEBUG("misc", "Player::SatisfyQuestExclusiveGroup: Sent INVALIDREASON_DONT_HAVE_REQ (QuestID: %u) because player '%s' (%s) already did daily quests in exclusive group.", + qInfo->GetQuestId(), GetName().c_str(), GetGUID().ToString().c_str()); } return false; @@ -15406,7 +15468,8 @@ bool Player::SatisfyQuestExclusiveGroup(Quest const* qInfo, bool msg) if (msg) { SendCanTakeQuestResponse(INVALIDREASON_DONT_HAVE_REQ); - TC_LOG_DEBUG("misc", "SatisfyQuestExclusiveGroup: Sent INVALIDREASON_DONT_HAVE_REQ (questId: %u) because player has already taken one or more quests in the exclusive group.", qInfo->GetQuestId()); + TC_LOG_DEBUG("misc", "Player::SatisfyQuestExclusiveGroup: Sent INVALIDREASON_DONT_HAVE_REQ (QuestID: %u) because player '%s' (%s) already did quest in exclusive group.", + qInfo->GetQuestId(), GetName().c_str(), GetGUID().ToString().c_str()); } return false; } @@ -15426,7 +15489,8 @@ bool Player::SatisfyQuestNextChain(Quest const* qInfo, bool msg) const if (msg) { SendCanTakeQuestResponse(INVALIDREASON_DONT_HAVE_REQ); - TC_LOG_DEBUG("misc", "SatisfyQuestNextChain: Sent INVALIDREASON_DONT_HAVE_REQ (questId: %u) because player already did or started next quest in chain.", qInfo->GetQuestId()); + TC_LOG_DEBUG("misc", "Player::SatisfyQuestNextChain: Sent INVALIDREASON_DONT_HAVE_REQ (QuestID: %u) because player '%s' (%s) already did or started next quest in chain.", + qInfo->GetQuestId(), GetName().c_str(), GetGUID().ToString().c_str()); } return false; } @@ -15453,7 +15517,8 @@ bool Player::SatisfyQuestPrevChain(Quest const* qInfo, bool msg) if (msg) { SendCanTakeQuestResponse(INVALIDREASON_DONT_HAVE_REQ); - TC_LOG_DEBUG("misc", "SatisfyQuestNextChain: Sent INVALIDREASON_DONT_HAVE_REQ (questId: %u) because player already did or started next quest in chain.", qInfo->GetQuestId()); + TC_LOG_DEBUG("misc", "Player::SatisfyQuestNextChain: Sent INVALIDREASON_DONT_HAVE_REQ (QuestID: %u) because player '%s' (%s) already did or started next quest in chain.", + qInfo->GetQuestId(), GetName().c_str(), GetGUID().ToString().c_str()); } return false; } @@ -16435,14 +16500,12 @@ void Player::SendQuestComplete(uint32 quest_id) const WorldPacket data(SMSG_QUESTUPDATE_COMPLETE, 4); data << uint32(quest_id); GetSession()->SendPacket(&data); - TC_LOG_DEBUG("network", "WORLD: Sent SMSG_QUESTUPDATE_COMPLETE quest = %u", quest_id); } } void Player::SendQuestReward(Quest const* quest, uint32 XP) const { uint32 questid = quest->GetQuestId(); - TC_LOG_DEBUG("network", "WORLD: Sent SMSG_QUESTGIVER_QUEST_COMPLETE quest = %u", questid); sGameEventMgr->HandleQuestComplete(questid); WorldPacket data(SMSG_QUESTGIVER_QUEST_COMPLETE, (4+4+4+4+4)); data << uint32(questid); @@ -16472,7 +16535,6 @@ void Player::SendQuestFailed(uint32 questId, InventoryResult reason) const data << uint32(questId); data << uint32(reason); // failed reason (valid reasons: 4, 16, 50, 17, 74, other values show default message) GetSession()->SendPacket(&data); - TC_LOG_DEBUG("network", "WORLD: Sent SMSG_QUESTGIVER_QUEST_FAILED"); } } @@ -16565,7 +16627,6 @@ void Player::SendQuestUpdateAddPlayer(Quest const* quest, uint16 old_count, uint ASSERT(old_count + add_count < 65536 && "player count store in 16 bits"); WorldPacket data(SMSG_QUESTUPDATE_ADD_PVP_KILL, (3*4)); - TC_LOG_DEBUG("network", "WORLD: Sent SMSG_QUESTUPDATE_ADD_PVP_KILL"); data << uint32(quest->GetQuestId()); data << uint32(old_count + add_count); data << uint32(quest->GetPlayersSlain()); @@ -16788,7 +16849,7 @@ bool Player::LoadFromDB(ObjectGuid guid, SQLQueryHolder *holder) { std::string name = "<unknown>"; sObjectMgr->GetPlayerNameByGUID(guid, name); - TC_LOG_ERROR("entities.player", "Player %s %s not found in table `characters`, can't load.", name.c_str(), guid.ToString().c_str()); + TC_LOG_ERROR("entities.player", "Player::LoadFromDB: Player '%s' (%s) not found in table `characters`, can't load. ", name.c_str(), guid.ToString().c_str()); return false; } @@ -16800,13 +16861,13 @@ bool Player::LoadFromDB(ObjectGuid guid, SQLQueryHolder *holder) // player should be able to load/delete character only with correct account! if (dbAccountId != GetSession()->GetAccountId()) { - TC_LOG_ERROR("entities.player", "Player %s attempts to load from wrong account (current: %u, should be: %u)", guid.ToString().c_str(), GetSession()->GetAccountId(), dbAccountId); + TC_LOG_ERROR("entities.player", "Player::LoadFromDB: Player (%s) loading from wrong account (is: %u, should be: %u)", guid.ToString().c_str(), GetSession()->GetAccountId(), dbAccountId); return false; } if (holder->GetPreparedResult(PLAYER_LOGIN_QUERY_LOAD_BANNED)) { - TC_LOG_ERROR("entities.player", "%s is banned, can't load.", guid.ToString().c_str()); + TC_LOG_ERROR("entities.player", "Player::LoadFromDB: Player (%s) is banned, can't load.", guid.ToString().c_str()); return false; } @@ -16832,7 +16893,7 @@ bool Player::LoadFromDB(ObjectGuid guid, SQLQueryHolder *holder) uint8 gender = fields[5].GetUInt8(); if (!IsValidGender(gender)) { - TC_LOG_ERROR("entities.player", "Player %s is the wrong gender (%u) and can't be loaded.", guid.ToString().c_str(), gender); + TC_LOG_ERROR("entities.player", "Player::LoadFromDB: Player (%s) has wrong gender (%u), can't load.", guid.ToString().c_str(), gender); return false; } @@ -16847,7 +16908,7 @@ bool Player::LoadFromDB(ObjectGuid guid, SQLQueryHolder *holder) PlayerInfo const* info = sObjectMgr->GetPlayerInfo(getRace(), getClass()); if (!info) { - TC_LOG_ERROR("entities.player", "Player %s has an invalid race/class combination (%u/%u) and can't be loaded.", guid.ToString().c_str(), getRace(), getClass()); + TC_LOG_ERROR("entities.player", "Player::LoadFromDB: Player (%s) has wrong race/class (%u/%u), can't load.", guid.ToString().c_str(), getRace(), getClass()); return false; } @@ -16882,7 +16943,7 @@ bool Player::LoadFromDB(ObjectGuid guid, SQLQueryHolder *holder) GetByteValue(PLAYER_BYTES_2, 0), // facial hair GetByteValue(PLAYER_BYTES, 0))) // skin color { - TC_LOG_ERROR("entities.player", "Player %s has wrong Appearance values (Hair/Skin/Color) and can't be loaded.", guid.ToString().c_str()); + TC_LOG_ERROR("entities.player", "Player::LoadFromDB: Player (%s) has wrong Appearance values (Hair/Skin/Color), can't load.", guid.ToString().c_str()); return false; } @@ -16908,7 +16969,7 @@ bool Player::LoadFromDB(ObjectGuid guid, SQLQueryHolder *holder) m_items[slot] = nullptr; } - TC_LOG_DEBUG("entities.player.loading", "Load Basic values of player %s: ", m_name.c_str()); + TC_LOG_DEBUG("entities.player.loading", "Player::LoadFromDB: Load Basic value of player '%s' is: ", m_name.c_str()); outDebugValues(); //Need to call it to initialize m_team (m_team can be calculated from race) @@ -16977,7 +17038,7 @@ bool Player::LoadFromDB(ObjectGuid guid, SQLQueryHolder *holder) MapEntry const* mapEntry = sMapStore.LookupEntry(mapId); if (!mapEntry || !IsPositionValid()) { - TC_LOG_ERROR("entities.player", "Player %s has invalid coordinates (MapId: %u X: %f Y: %f Z: %f O: %f). Teleporting player to default race/class location.", + TC_LOG_ERROR("entities.player", "Player::LoadFromDB: Player (%s) has invalid coordinates (MapId: %u X: %f Y: %f Z: %f O: %f). Teleport to default race/class locations.", guid.ToString().c_str(), mapId, GetPositionX(), GetPositionY(), GetPositionZ(), GetOrientation()); RelocateToHomebind(); } @@ -17018,7 +17079,7 @@ bool Player::LoadFromDB(ObjectGuid guid, SQLQueryHolder *holder) //if (mapId == MAPID_INVALID) -- code kept for reference if (int16(mapId) == int16(-1)) // Battleground Entry Point not found (???) { - TC_LOG_ERROR("entities.player", "Player %s was in BG in database, but BG was not found and entry point was invalid! Teleporting to default race/class locations.", + TC_LOG_ERROR("entities.player", "Player::LoadFromDB: Player (%s) was in BG in database, but BG was not found and entry point was invalid! Teleport to default race/class locations.", guid.ToString().c_str()); RelocateToHomebind(); } @@ -17050,7 +17111,7 @@ bool Player::LoadFromDB(ObjectGuid guid, SQLQueryHolder *holder) std::fabs(m_movementInfo.transport.pos.GetPositionY()) > 250.0f || std::fabs(m_movementInfo.transport.pos.GetPositionZ()) > 250.0f) { - TC_LOG_ERROR("entities.player", "Player %s has invalid transport coordinates (X: %f Y: %f Z: %f O: %f). Teleporting player to bind location.", + TC_LOG_ERROR("entities.player", "Player::LoadFromDB: Player (%s) has invalid transport coordinates (X: %f Y: %f Z: %f O: %f). Teleport to bind location.", guid.ToString().c_str(), x, y, z, o); m_movementInfo.transport.Reset(); @@ -17067,7 +17128,7 @@ bool Player::LoadFromDB(ObjectGuid guid, SQLQueryHolder *holder) } else { - TC_LOG_ERROR("entities.player", "Player %s has problems with transport guid (%u). Teleporting to bind location.", + TC_LOG_ERROR("entities.player", "Player::LoadFromDB: Player (%s) has problems with transport guid (" UI64FMTD "). Teleport to bind location.", guid.ToString().c_str(), transLowGUID); RelocateToHomebind(); @@ -17093,12 +17154,12 @@ bool Player::LoadFromDB(ObjectGuid guid, SQLQueryHolder *holder) if (!nodeEntry) // don't know taxi start node, teleport to homebind { - TC_LOG_ERROR("entities.player", "Character %u has wrong data in taxi destination list. Teleporting player to homebind.", GetGUID().GetCounter()); + TC_LOG_ERROR("entities.player", "Player::LoadFromDB: Player (%s) has wrong data in taxi destination list, teleport to homebind.", GetGUID().ToString().c_str()); RelocateToHomebind(); } else // has start node, teleport to it { - TC_LOG_ERROR("entities.player", "Character %u has too short taxi destination list. Teleporting player to original node.", GetGUID().GetCounter()); + TC_LOG_ERROR("entities.player", "Player::LoadFromDB: Player (%s) has too short taxi destination list, teleport to original node.", GetGUID().ToString().c_str()); mapId = nodeEntry->map_id; Relocate(nodeEntry->x, nodeEntry->y, nodeEntry->z, 0.0f); } @@ -17127,7 +17188,8 @@ bool Player::LoadFromDB(ObjectGuid guid, SQLQueryHolder *holder) { if (GetSession()->Expansion() < mapEntry->Expansion()) { - TC_LOG_DEBUG("entities.player.loading", "Player %s is using client without required expansion, tried to log in to inaccessible map %u.", GetName().c_str(), mapId); + TC_LOG_DEBUG("entities.player.loading", "Player::LoadFromDB: Player '%s' (%s) using client without required expansion tried login at non accessible map %u", + GetName().c_str(), GetGUID().ToString().c_str(), mapId); RelocateToHomebind(); } @@ -17196,7 +17258,7 @@ bool Player::LoadFromDB(ObjectGuid guid, SQLQueryHolder *holder) } else { - TC_LOG_ERROR("entities.player", "Player %s %s Map: %u, X: %f, Y: %f, Z: %f, O: %f. Areatrigger not found.", + TC_LOG_ERROR("entities.player", "Player::LoadFromDB: Player '%s' (%s) Map: %u, X: %f, Y: %f, Z: %f, O: %f. Areatrigger not found.", m_name.c_str(), guid.ToString().c_str(), mapId, GetPositionX(), GetPositionY(), GetPositionZ(), GetOrientation()); RelocateToHomebind(); map = nullptr; @@ -17210,7 +17272,7 @@ bool Player::LoadFromDB(ObjectGuid guid, SQLQueryHolder *holder) map = sMapMgr->CreateMap(mapId, this); if (!map) { - TC_LOG_ERROR("entities.player", "Player %s %s Map: %u, X: %f, Y: %f, Z: %f, O: %f. Invalid default map coordinates or instance couldn't be created.", + TC_LOG_ERROR("entities.player", "Player::LoadFromDB: Player '%s' (%s) Map: %u, X: %f, Y: %f, Z: %f, O: %f. Invalid default map coordinates or instance couldn't be created.", m_name.c_str(), guid.ToString().c_str(), mapId, GetPositionX(), GetPositionY(), GetPositionZ(), GetOrientation()); return false; } @@ -17257,7 +17319,8 @@ bool Player::LoadFromDB(ObjectGuid guid, SQLQueryHolder *holder) m_stableSlots = fields[32].GetUInt8(); if (m_stableSlots > MAX_PET_STABLES) { - TC_LOG_ERROR("entities.player", "Player can not have more than %u stable slots, but has %u in DB.", MAX_PET_STABLES, uint32(m_stableSlots)); + TC_LOG_ERROR("entities.player", "Player::LoadFromDB: Player (%s) can't have more stable slots than %u, but has %u in DB", + GetGUID().ToString().c_str(), MAX_PET_STABLES, uint32(m_stableSlots)); m_stableSlots = MAX_PET_STABLES; } @@ -17265,7 +17328,7 @@ bool Player::LoadFromDB(ObjectGuid guid, SQLQueryHolder *holder) if (HasAtLoginFlag(AT_LOGIN_RENAME)) { - TC_LOG_ERROR("entities.player", "Player (GUID: %u) tried to login while forced to rename, could not load player.", GetGUID().GetCounter()); + TC_LOG_ERROR("entities.player", "Player::LoadFromDB: Player (%s) tried to login while forced to rename, can't load.'", GetGUID().ToString().c_str()); return false; } @@ -17341,8 +17404,9 @@ bool Player::LoadFromDB(ObjectGuid guid, SQLQueryHolder *holder) // sanity check if (m_specsCount > MAX_TALENT_SPECS || m_activeSpec > MAX_TALENT_SPEC || m_specsCount < MIN_TALENT_SPECS) { + TC_LOG_ERROR("entities.player", "Player::LoadFromDB: Player %s (%s) has invalid SpecCount = %u and/or invalid ActiveSpec = %u.", + GetName().c_str(), GetGUID().ToString().c_str(), uint32(m_specsCount), uint32(m_activeSpec)); m_activeSpec = 0; - TC_LOG_ERROR("entities.player", "Player %s(GUID: %u) has SpecCount = %u and ActiveSpec = %u.", GetName().c_str(), GetGUID().GetCounter(), m_specsCount, m_activeSpec); } _LoadTalents(holder->GetPreparedResult(PLAYER_LOGIN_QUERY_LOAD_TALENTS)); @@ -17417,7 +17481,7 @@ bool Player::LoadFromDB(ObjectGuid guid, SQLQueryHolder *holder) SetPower(Powers(i), savedPower > GetMaxPower(Powers(i)) ? GetMaxPower(Powers(i)) : savedPower); } - TC_LOG_DEBUG("entities.player.loading", "The value of player %s after load item and aura is: ", m_name.c_str()); + TC_LOG_DEBUG("entities.player.loading", "Player::LoadFromDB: The value of player '%s' after load item and aura is: ", m_name.c_str()); outDebugValues(); // GM state @@ -17552,7 +17616,8 @@ void Player::_LoadActions(PreparedQueryResult result) ab->uState = ACTIONBUTTON_UNCHANGED; else { - TC_LOG_ERROR("entities.player", " ...at loading, and will also be deleted in DB."); + TC_LOG_ERROR("entities.player", "Player::_LoadActions: Player '%s' (%s) has an invalid action button (Button: %u, Action: %u, Type: %u). It will be deleted at next save.", + GetName().c_str(), GetGUID().ToString().c_str(), button, action, type); // Will be deleted in DB at next save (it can create data until save but marked as deleted). m_actionButtons[button].uState = ACTIONBUTTON_DELETED; @@ -17563,7 +17628,7 @@ void Player::_LoadActions(PreparedQueryResult result) void Player::_LoadAuras(PreparedQueryResult result, uint32 timediff) { - TC_LOG_DEBUG("entities.player.loading", "Loading auras for player %u.", GetGUID().GetCounter()); + TC_LOG_DEBUG("entities.player.loading", "Player::_LoadAuras: Loading auras for %s", GetGUID().ToString().c_str()); /* 0 1 2 3 4 5 6 7 8 9 10 QueryResult* result = CharacterDatabase.PQuery("SELECT casterGuid, spell, effectMask, recalculateMask, stackCount, amount0, amount1, amount2, base_amount0, base_amount1, base_amount2, @@ -17596,7 +17661,8 @@ void Player::_LoadAuras(PreparedQueryResult result, uint32 timediff) SpellInfo const* spellInfo = sSpellMgr->GetSpellInfo(spellid); if (!spellInfo) { - TC_LOG_ERROR("entities.player", "Unknown aura (spellid %u), ignored.", spellid); + TC_LOG_ERROR("entities.player", "Player::_LoadAuras: Player '%s' (%s) has an invalid aura (SpellID: %u), ignoring.", + GetName().c_str(), GetGUID().ToString().c_str(), spellid); continue; } @@ -17630,7 +17696,8 @@ void Player::_LoadAuras(PreparedQueryResult result, uint32 timediff) aura->SetLoadedState(maxduration, remaintime, remaincharges, stackcount, recalculatemask, &damage[0]); aura->ApplyForTargets(); - TC_LOG_DEBUG("entities.player", "Added aura spellid %u, effectmask %u.", spellInfo->Id, effmask); + TC_LOG_DEBUG("entities.player", "Player::_LoadAuras: Added aura (SpellID: %u, EffectMask: %u) to player '%s (%s)", + spellInfo->Id, effmask, GetName().c_str(), GetGUID().ToString().c_str()); } } while (result->NextRow()); @@ -17653,13 +17720,13 @@ void Player::_LoadGlyphAuras() continue; } else - TC_LOG_ERROR("entities.player", "Player %s has glyph with typeflags %u in slot with typeflags %u, removing.", m_name.c_str(), gp->TypeFlags, gs->TypeFlags); + TC_LOG_ERROR("entities.player", "Player::_LoadGlyphAuras: Player '%s' (%s) has glyph with typeflags %u in slot with typeflags %u, removing.", GetName().c_str(), GetGUID().ToString().c_str(), gp->TypeFlags, gs->TypeFlags); } else - TC_LOG_ERROR("entities.player", "Player %s has non-existing glyph slot entry %u on index %u.", m_name.c_str(), GetGlyphSlot(i), i); + TC_LOG_ERROR("entities.player", "Player::_LoadGlyphAuras: Player '%s' (%s) has not existing glyph slot entry %u on index %u", GetName().c_str(), GetGUID().ToString().c_str(), GetGlyphSlot(i), i); } else - TC_LOG_ERROR("entities.player", "Player %s has non-existing glyph entry %u on index %u.", m_name.c_str(), glyph, i); + TC_LOG_ERROR("entities.player", "Player::_LoadGlyphAuras: Player '%s' (%s) has not existing glyph entry %u on index %u", GetName().c_str(), GetGUID().ToString().c_str(), glyph, i); // On any error remove glyph SetGlyph(i, 0); @@ -17775,8 +17842,8 @@ void Player::_LoadInventory(PreparedQueryResult result, uint32 timeDiff) } else { - TC_LOG_ERROR("entities.player", "Player::_LoadInventory: player (GUID: %u, name: '%s') has item (GUID: %u, entry: %u) which doesnt have a valid bag (Bag GUID: %u, slot: %u). Possible cheat?", - GetGUID().GetCounter(), GetName().c_str(), item->GetGUID().GetCounter(), item->GetEntry(), bagGuid, slot); + TC_LOG_ERROR("entities.player", "Player::_LoadInventory: Player '%s' (%s) has item (%s, entry: %u) which doesnt have a valid bag (Bag %u, slot: %u). Possible cheat?", + GetName().c_str(), GetGUID().ToString().c_str(), item->GetGUID().ToString().c_str(), item->GetEntry(), bagGuid, slot); item->DeleteFromInventoryDB(trans); delete item; continue; @@ -17789,8 +17856,8 @@ void Player::_LoadInventory(PreparedQueryResult result, uint32 timeDiff) item->SetState(ITEM_UNCHANGED, this); else { - TC_LOG_ERROR("entities.player", "Player::_LoadInventory: player (GUID: %u, name: '%s') has item (GUID: %u, entry: %u) which can't be loaded into inventory (Bag GUID: %u, slot: %u) for reason %u. Item will be sent by mail.", - GetGUID().GetCounter(), GetName().c_str(), item->GetGUID().GetCounter(), item->GetEntry(), bagGuid, slot, err); + TC_LOG_ERROR("entities.player", "Player::_LoadInventory: Player '%s' (%s) has item (%s, entry: %u) which can't be loaded into inventory (Bag %u, slot: %u) by reason %u. Item will be sent by mail.", + GetName().c_str(), GetGUID().ToString().c_str(), item->GetGUID().ToString().c_str(), item->GetEntry(), bagGuid, slot, err); item->DeleteFromInventoryDB(trans); problematicItems.push_back(item); } @@ -17968,7 +18035,8 @@ void Player::_LoadMailedItems(Mail* mail) if (!proto) { - TC_LOG_ERROR("entities.player", "Player %u has an unknown item_template (ProtoType) in mailed items(GUID: %u template: %u) in mail (%u), deleted.", GetGUID().GetCounter(), itemGuid, itemTemplate, mail->messageID); + TC_LOG_ERROR("entities.player", "Player '%s' (%s) has unknown item_template in mailed items (GUID: %u, Entry: %u) in mail (%u), deleted.", + GetName().c_str(), GetGUID().ToString().c_str(), itemGuid, itemTemplate, mail->messageID); stmt = CharacterDatabase.GetPreparedStatement(CHAR_DEL_INVALID_MAIL_ITEM); stmt->setUInt32(0, itemGuid); @@ -17984,7 +18052,7 @@ void Player::_LoadMailedItems(Mail* mail) if (!item->LoadFromDB(itemGuid, ObjectGuid(HighGuid::Player, fields[13].GetUInt32()), fields, itemTemplate)) { - TC_LOG_ERROR("entities.player", "Player::_LoadMailedItems - Item in mail (%u) doesn't exist!!! - item guid: %u, deleted from mail.", mail->messageID, itemGuid); + TC_LOG_ERROR("entities.player", "Player::_LoadMailedItems: Item (GUID: " UI64FMTD ") in mail (%u) doesn't exist, deleted from mail.", itemGuid, mail->messageID); stmt = CharacterDatabase.GetPreparedStatement(CHAR_DEL_MAIL_ITEM); stmt->setUInt32(0, itemGuid); @@ -18047,7 +18115,7 @@ void Player::_LoadMail() if (m->mailTemplateId && !sMailTemplateStore.LookupEntry(m->mailTemplateId)) { - TC_LOG_ERROR("entities.player", "Player::_LoadMail - Mail (%u) contains a non-existing MailTemplateId (%u), removing at load.", m->messageID, m->mailTemplateId); + TC_LOG_ERROR("entities.player", "Player::_LoadMail: Mail (%u) has nonexistent MailTemplateId (%u), remove at load", m->messageID, m->mailTemplateId); m->mailTemplateId = 0; } @@ -18104,8 +18172,8 @@ void Player::_LoadQuestStatus(PreparedQueryResult result) else { questStatusData.Status = QUEST_STATUS_INCOMPLETE; - TC_LOG_ERROR("entities.player", "Player %s (GUID: %u) has invalid quest %d status (%u), replaced by QUEST_STATUS_INCOMPLETE(3).", - GetName().c_str(), GetGUID().GetCounter(), quest_id, qstatus); + TC_LOG_ERROR("entities.player", "Player::_LoadQuestStatus: Player '%s' (%s) has invalid quest %d status (%u), replaced by QUEST_STATUS_INCOMPLETE(3).", + GetName().c_str(), GetGUID().ToString().c_str(), quest_id, qstatus); } questStatusData.Explored = (fields[2].GetUInt8() > 0); @@ -18154,7 +18222,8 @@ void Player::_LoadQuestStatus(PreparedQueryResult result) ++slot; } - TC_LOG_DEBUG("entities.player.loading", "Quest status is {%u} for quest {%u} for player (GUID: %u)", questStatusData.Status, quest_id, GetGUID().GetCounter()); + + TC_LOG_DEBUG("entities.player.loading", "Player::_LoadQuestStatus: Quest status is {%u} for quest {%u} for player (%s)", questStatusData.Status, quest_id, GetGUID().ToString().c_str()); } } while (result->NextRow()); @@ -18244,7 +18313,8 @@ void Player::_LoadDailyQuestStatus(PreparedQueryResult result) SetUInt32Value(PLAYER_FIELD_DAILY_QUESTS_1+quest_daily_idx, quest_id); ++quest_daily_idx; - TC_LOG_DEBUG("entities.player.loading", "Daily quest (%u) cooldown for player (GUID: %u)", quest_id, GetGUID().GetCounter()); + TC_LOG_DEBUG("entities.player.loading", "Player::_LoadDailyQuestStatus: Loaded daily quest cooldown (QuestID: %u) for player '%s' (%s)", + quest_id, GetName().c_str(), GetGUID().ToString().c_str()); } while (result->NextRow()); } @@ -18267,7 +18337,9 @@ void Player::_LoadWeeklyQuestStatus(PreparedQueryResult result) continue; m_weeklyquests.insert(quest_id); - TC_LOG_DEBUG("entities.player.loading", "Weekly quest {%u} cooldown for player (GUID: %u)", quest_id, GetGUID().GetCounter()); + + TC_LOG_DEBUG("entities.player.loading", "Player::_LoadWeeklyQuestStatus: Loaded weekly quest cooldown (QuestID: %u) for player '%s' (%s)", + quest_id, GetName().c_str(), GetGUID().ToString().c_str()); } while (result->NextRow()); } @@ -18291,7 +18363,8 @@ void Player::_LoadSeasonalQuestStatus(PreparedQueryResult result) continue; m_seasonalquests[event_id].insert(quest_id); - TC_LOG_DEBUG("entities.player.loading", "Seasonal quest {%u} cooldown for player (GUID: %u)", quest_id, GetGUID().GetCounter()); + TC_LOG_DEBUG("entities.player.loading", "Player::_LoadSeasonalQuestStatus: Loaded seasonal quest cooldown (QuestID: %u) for player '%s' (%s)", + quest_id, GetName().c_str(), GetGUID().ToString().c_str()); } while (result->NextRow()); } @@ -18314,7 +18387,8 @@ void Player::_LoadMonthlyQuestStatus(PreparedQueryResult result) continue; m_monthlyquests.insert(quest_id); - TC_LOG_DEBUG("entities.player.loading", "Monthly quest {%u} cooldown for player (GUID: %u)", quest_id, GetGUID().GetCounter()); + TC_LOG_DEBUG("entities.player.loading", "Player::_LoadMonthlyQuestStatus: Loaded monthly quest cooldown (QuestID: %u) for player '%s' (%s)", + quest_id, GetName().c_str(), GetGUID().ToString().c_str()); } while (result->NextRow()); } @@ -18391,12 +18465,14 @@ void Player::_LoadBoundInstances(PreparedQueryResult result) if (!mapEntry || !mapEntry->IsDungeon()) { - TC_LOG_ERROR("entities.player", "_LoadBoundInstances: player %s(%d) has bind to a non-existing or non-dungeon map %d (%s).", GetName().c_str(), GetGUID().GetCounter(), mapId, mapname.c_str()); + TC_LOG_ERROR("entities.player", "Player::_LoadBoundInstances: Player '%s' (%s) has bind to not existed or not dungeon map %d (%s)", + GetName().c_str(), GetGUID().ToString().c_str(), mapId, mapname.c_str()); deleteInstance = true; } else if (difficulty >= MAX_DIFFICULTY) { - TC_LOG_ERROR("entities.player", "_LoadBoundInstances: player %s(%d) has a bind to a non-existing difficulty %d instance for map %u (%s)", GetName().c_str(), GetGUID().GetCounter(), difficulty, mapId, mapname.c_str()); + TC_LOG_ERROR("entities.player", "Player::_LoadBoundInstances: player '%s' (%s) has bind to not existed difficulty %d instance for map %u (%s)", + GetName().c_str(), GetGUID().ToString().c_str(), difficulty, mapId, mapname.c_str()); deleteInstance = true; } else @@ -18404,12 +18480,14 @@ void Player::_LoadBoundInstances(PreparedQueryResult result) MapDifficulty const* mapDiff = GetMapDifficultyData(mapId, Difficulty(difficulty)); if (!mapDiff) { - TC_LOG_ERROR("entities.player", "_LoadBoundInstances: player %s(%d) has a bind to a non-existing difficulty %d instance for map %u (%s).", GetName().c_str(), GetGUID().GetCounter(), difficulty, mapId, mapname.c_str()); + TC_LOG_ERROR("entities.player", "Player::_LoadBoundInstances: player '%s' (%s) has bind to not existed difficulty %d instance for map %u (%s)", + GetName().c_str(), GetGUID().ToString().c_str(), difficulty, mapId, mapname.c_str()); deleteInstance = true; } else if (!perm && group) { - TC_LOG_ERROR("entities.player", "_LoadBoundInstances: player %s(%d) is in group %d, but has a non-permanent character bind to map %d (%s), %d, %d.", GetName().c_str(), GetGUID().GetCounter(), group->GetLowGUID(), mapId, mapname.c_str(), instanceId, difficulty); + TC_LOG_ERROR("entities.player", "Player::_LoadBoundInstances: player '%s' (%s) is in group %s but has a non-permanent character bind to map %d (%s), %d, %d", + GetName().c_str(), GetGUID().ToString().c_str(), group->GetGUID().ToString().c_str(), mapId, mapname.c_str(), instanceId, difficulty); deleteInstance = true; } } @@ -18545,8 +18623,9 @@ InstancePlayerBind* Player::BindToInstance(InstanceSave* save, bool permanent, B bind.perm = permanent; bind.extendState = extendState; if (!load) - TC_LOG_DEBUG("maps", "Player::BindToInstance: %s(%d) is now bound to map %d, instance %d, difficulty %d", GetName().c_str(), GetGUID().GetCounter(), save->GetMapId(), save->GetInstanceId(), save->GetDifficulty()); - sScriptMgr->OnPlayerBindToInstance(this, save->GetDifficulty(), save->GetMapId(), permanent, uint8(extendState)); + TC_LOG_DEBUG("maps", "Player::BindToInstance: Player '%s' (%s) is now bound to map (ID: %d, Instance: %d, Difficulty: %d)", + GetName().c_str(), GetGUID().ToString().c_str(), save->GetMapId(), save->GetInstanceId(), save->GetDifficulty()); + sScriptMgr->OnPlayerBindToInstance(this, save->GetDifficulty(), save->GetMapId(), permanent, extendState); return &bind; } @@ -18807,7 +18886,8 @@ bool Player::_LoadHomeBind(PreparedQueryResult result) PlayerInfo const* info = sObjectMgr->GetPlayerInfo(getRace(), getClass()); if (!info) { - TC_LOG_ERROR("entities.player", "Player (Name %s) has incorrect race/class pair. Can't be loaded.", GetName().c_str()); + TC_LOG_ERROR("entities.player", "Player::_LoadHomeBind: Player '%s' (%s) has incorrect race/class (%u/%u) pair. Can't load.", + GetGUID().ToString().c_str(), GetName().c_str(), uint32(getRace()), uint32(getClass())); return false; } @@ -18855,8 +18935,8 @@ bool Player::_LoadHomeBind(PreparedQueryResult result) CharacterDatabase.Execute(stmt); } - TC_LOG_DEBUG("entities.player", "Setting player home position - mapid: %u, areaid: %u, X: %f, Y: %f, Z: %f", - m_homebindMapId, m_homebindAreaId, m_homebindX, m_homebindY, m_homebindZ); + TC_LOG_DEBUG("entities.player", "Player::_LoadHomeBind: Setting home position (MapID: %u, AreaID: %u, X: %f, Y: %f, Z: %f) of player '%s' (%s)", + m_homebindMapId, m_homebindAreaId, m_homebindX, m_homebindY, m_homebindZ, GetName().c_str(), GetGUID().ToString().c_str()); return true; } @@ -18880,7 +18960,7 @@ void Player::SaveToDB(bool create /*=false*/) // first save/honor gain after midnight will also update the player's honor fields UpdateHonorFields(); - TC_LOG_DEBUG("entities.unit", "The value of player %s at save: ", m_name.c_str()); + TC_LOG_DEBUG("entities.unit", "Player::SaveToDB: The value of player %s at save: ", m_name.c_str()); outDebugValues(); if (!create) @@ -19320,7 +19400,8 @@ void Player::_SaveInventory(SQLTransaction& trans) } else { - TC_LOG_ERROR("entities.player", "Can't find %s, but is in refundable storage for player %u ! Removing.", itr->ToString().c_str(), GetGUID().GetCounter()); + TC_LOG_ERROR("entities.player", "Player::_SaveInventory: Can't find item (%s) in refundable storage for player '%s' (%s), removing.", + itr->ToString().c_str(), GetName().c_str(), GetGUID().ToString().c_str()); m_refundableItems.erase(itr); } } @@ -19351,7 +19432,9 @@ void Player::_SaveInventory(SQLTransaction& trans) ObjectGuid::LowType bagTestGUID = 0; if (Item* test2 = GetItemByPos(INVENTORY_SLOT_BAG_0, item->GetBagSlot())) bagTestGUID = test2->GetGUID().GetCounter(); - TC_LOG_ERROR("entities.player", "Player(GUID: %u Name: %s)::_SaveInventory - the bag(%u) and slot(%u) values for the item with guid %u (state %d) are incorrect, the player doesn't have an item at that position!", lowGuid, GetName().c_str(), item->GetBagSlot(), item->GetSlot(), item->GetGUID().GetCounter(), (int32)item->GetState()); + + TC_LOG_ERROR("entities.player", "Player::_SaveInventory: Player '%s' (%s) has incorrect values (Bag: %u, Slot: %u) for the item (%s, State: %d). The player doesn't have an item at that position.", + GetName().c_str(), GetGUID().ToString().c_str(), item->GetBagSlot(), item->GetSlot(), item->GetGUID().ToString().c_str(), (int32)item->GetState()); // according to the test that was just performed nothing should be in this slot, delete stmt = CharacterDatabase.GetPreparedStatement(CHAR_DEL_CHAR_INVENTORY_BY_BAG_SLOT); stmt->setUInt32(0, bagTestGUID); @@ -19367,7 +19450,8 @@ void Player::_SaveInventory(SQLTransaction& trans) } else if (test != item) { - TC_LOG_ERROR("entities.player", "Player(GUID: %u Name: %s)::_SaveInventory - the bag(%u) and slot(%u) values for the item with guid %u are incorrect, the item with guid %u is there instead!", lowGuid, GetName().c_str(), item->GetBagSlot(), item->GetSlot(), item->GetGUID().GetCounter(), test->GetGUID().GetCounter()); + TC_LOG_ERROR("entities.player", "Player::_SaveInventory: Player '%s' (%s) has incorrect values (Bag: %u, Slot: %u) for the item (%s). %s is there instead!", + GetName().c_str(), GetGUID().ToString().c_str(), item->GetBagSlot(), item->GetSlot(), item->GetGUID().ToString().c_str(), test->GetGUID().ToString().c_str()); // save all changes to the item... if (item->GetState() != ITEM_NEW) // only for existing items, no duplicates item->SaveToDB(trans); @@ -20143,7 +20227,8 @@ void Player::RemovePet(Pet* pet, PetSaveMode mode, bool returnreagent) if (pet) { - TC_LOG_DEBUG("entities.pet", "RemovePet %u, %u, %u", pet->GetEntry(), mode, returnreagent); + TC_LOG_DEBUG("entities.pet", "Player::RemovePet: Player '%s' (%s), Pet (Entry: %u, Mode: %u, ReturnReagent: %u)", + GetName().c_str(), GetGUID().ToString().c_str(), pet->GetEntry(), mode, returnreagent); if (pet->m_removed) return; @@ -20237,10 +20322,10 @@ void Player::StopCastingCharm() if (GetCharmGUID()) { - TC_LOG_FATAL("entities.player", "Player %s (%s) is not able to uncharm unit (%s)!", GetName().c_str(), GetGUID().ToString().c_str(), GetCharmGUID().ToString().c_str()); - if (charm->GetCharmerGUID()) + TC_LOG_FATAL("entities.player", "Player::StopCastingCharm: Player '%s' (%s) is not able to uncharm unit (%s)", GetName().c_str(), GetGUID().ToString().c_str(), GetCharmGUID().ToString().c_str()); + if (!charm->GetCharmerGUID().IsEmpty()) { - TC_LOG_FATAL("entities.player", "Charmed unit has charmer %s", charm->GetCharmerGUID().ToString().c_str()); + TC_LOG_FATAL("entities.player", "Player::StopCastingCharm: Charmed unit has charmer %s", charm->GetCharmerGUID().ToString().c_str()); ABORT(); } @@ -20397,7 +20482,7 @@ void Player::PossessSpellInitialize() if (!charmInfo) { - TC_LOG_ERROR("entities.player", "Player::PossessSpellInitialize(): charm (%s) has no charminfo!", charm->GetGUID().ToString().c_str()); + TC_LOG_ERROR("entities.player", "Player::PossessSpellInitialize: charm (%s) has no charminfo!", charm->GetGUID().ToString().c_str()); return; } @@ -20444,7 +20529,8 @@ void Player::VehicleSpellInitialize() if (!sConditionMgr->IsObjectMeetingVehicleSpellConditions(vehicle->GetEntry(), spellId, this, vehicle)) { - TC_LOG_DEBUG("condition", "VehicleSpellInitialize: conditions not met for Vehicle entry %u spell %u", vehicle->ToCreature()->GetEntry(), spellId); + TC_LOG_DEBUG("condition", "Player::VehicleSpellInitialize: Player '%s' (%s) doesn't meet conditions for vehicle (Entry: %u, Spell: %u)", + GetName().c_str(), GetGUID().ToString().c_str(), vehicle->ToCreature()->GetEntry(), spellId); data << uint16(0) << uint8(0) << uint8(i+8); continue; } @@ -20474,7 +20560,8 @@ void Player::CharmSpellInitialize() CharmInfo* charmInfo = charm->GetCharmInfo(); if (!charmInfo) { - TC_LOG_ERROR("entities.player", "Player::CharmSpellInitialize(): the player's charm (%s) has no charminfo!", charm->GetGUID().ToString().c_str()); + TC_LOG_ERROR("entities.player", "Player::CharmSpellInitialize(): Player '%s' (%s) has a charm (%s) but no no charminfo!", + GetName().c_str(), GetGUID().ToString().c_str(), charm->GetGUID().ToString().c_str()); return; } @@ -20544,7 +20631,7 @@ bool Player::IsAffectedBySpellmod(SpellInfo const* spellInfo, SpellModifier* mod void Player::AddSpellMod(SpellModifier* mod, bool apply) { - TC_LOG_DEBUG("spells", "Player::AddSpellMod %d", mod->spellId); + TC_LOG_DEBUG("spells", "Player::AddSpellMod: Player '%s' (%s), SpellID: %d", GetName().c_str(), GetGUID().ToString().c_str(), mod->spellId); uint16 Opcode = (mod->type == SPELLMOD_FLAT) ? SMSG_SET_FLAT_SPELL_MODIFIER : SMSG_SET_PCT_SPELL_MODIFIER; int i = 0; @@ -21071,7 +21158,7 @@ void Player::ContinueTaxiFlight() const if (!sourceNode) return; - TC_LOG_DEBUG("entities.unit", "WORLD: Restart character %u taxi flight", GetGUID().GetCounter()); + TC_LOG_DEBUG("entities.unit", "Player::ContinueTaxiFlight: Restart %s taxi flight", GetGUID().ToString().c_str()); uint32 mountDisplayId = sObjectMgr->GetTaxiMountDisplayId(sourceNode, GetTeam(), true); if (!mountDisplayId) @@ -21173,7 +21260,7 @@ void Player::InitDisplayIds() PlayerInfo const* info = sObjectMgr->GetPlayerInfo(getRace(), getClass()); if (!info) { - TC_LOG_ERROR("entities.player", "Player %s (%s) has incorrect race/class pair. Can't init display ids.", GetName().c_str(), GetGUID().ToString().c_str()); + TC_LOG_ERROR("entities.player", "Player::InitDisplayIds: Player '%s' (%s) has incorrect race/class pair. Can't init display ids.", GetName().c_str(), GetGUID().ToString().c_str()); return; } @@ -21189,7 +21276,7 @@ void Player::InitDisplayIds() SetNativeDisplayId(info->displayId_m); break; default: - TC_LOG_ERROR("entities.player", "Player %s (%s) has invalid gender %u", GetName().c_str(), GetGUID().ToString().c_str(), gender); + TC_LOG_ERROR("entities.player", "Player::InitDisplayIds: Player '%s' (%s) has invalid gender %u", GetName().c_str(), GetGUID().ToString().c_str(), gender); } } @@ -21288,14 +21375,16 @@ bool Player::BuyItemFromVendorSlot(ObjectGuid vendorguid, uint32 vendorslot, uin Creature* creature = GetNPCIfCanInteractWith(vendorguid, UNIT_NPC_FLAG_VENDOR); if (!creature) { - TC_LOG_DEBUG("network", "WORLD: BuyItemFromVendor - %s not found or you can't interact with him.", vendorguid.ToString().c_str()); + TC_LOG_DEBUG("network", "Player::BuyItemFromVendorSlot: Vendor (%s) not found or player '%s' (%s) can't interact with him.", + vendorguid.ToString().c_str(), GetName().c_str(), GetGUID().ToString().c_str()); SendBuyError(BUY_ERR_DISTANCE_TOO_FAR, nullptr, item, 0); return false; } if (!sConditionMgr->IsObjectMeetingVendorItemConditions(creature->GetEntry(), item, this, creature)) { - TC_LOG_DEBUG("condition", "BuyItemFromVendor: conditions not met for creature entry %u item %u", creature->GetEntry(), item); + TC_LOG_DEBUG("condition", "Player::BuyItemFromVendorSlot: Player '%s' (%s) doesn't meed conditions for creature (Entry: %u, Item: %u)", + GetName().c_str(), GetGUID().ToString().c_str(), creature->GetEntry(), item); SendBuyError(BUY_ERR_CANT_FIND_ITEM, creature, item, 0); return false; } @@ -21342,13 +21431,14 @@ bool Player::BuyItemFromVendorSlot(ObjectGuid vendorguid, uint32 vendorslot, uin ItemExtendedCostEntry const* iece = sItemExtendedCostStore.LookupEntry(crItem->ExtendedCost); if (!iece) { - TC_LOG_ERROR("entities.player", "Item %u has wrong ExtendedCost field value %u", pProto->ItemId, crItem->ExtendedCost); + TC_LOG_ERROR("entities.player", "Player::BuyItemFromVendorSlot: Item %u has wrong ExtendedCost field value %u", pProto->ItemId, crItem->ExtendedCost); return false; } // honor points price if (GetHonorPoints() < (iece->reqhonorpoints * count)) { + TC_LOG_ERROR("entities.player", "Item %u have wrong ExtendedCost field value %u", pProto->ItemId, crItem->ExtendedCost); SendEquipError(EQUIP_ERR_NOT_ENOUGH_HONOR_POINTS, NULL, NULL); return false; } @@ -21385,7 +21475,8 @@ bool Player::BuyItemFromVendorSlot(ObjectGuid vendorguid, uint32 vendorslot, uin uint32 maxCount = MAX_MONEY_AMOUNT / pProto->BuyPrice; if ((uint32)count > maxCount) { - TC_LOG_ERROR("entities.player", "Player %s tried to buy %u item id %u, causing overflow.", GetName().c_str(), (uint32)count, pProto->ItemId); + TC_LOG_ERROR("entities.player", "Player::BuyItemFromVendorSlot: Player '%s' (%s) tried to buy item (ItemID: %u, Count: %u), causing overflow", + GetName().c_str(), GetGUID().ToString().c_str(), pProto->ItemId, (uint32)count); count = (uint8)maxCount; } price = pProto->BuyPrice * count; //it should not exceed MAX_MONEY_AMOUNT @@ -21479,7 +21570,8 @@ void Player::UpdateHomebindTime(uint32 time) data << uint32(m_HomebindTimer); data << uint32(1); GetSession()->SendPacket(&data); - TC_LOG_DEBUG("maps", "PLAYER: Player '%s' (GUID: %u) will be teleported to homebind in 60 seconds.", GetName().c_str(), GetGUID().GetCounter()); + TC_LOG_DEBUG("maps", "Player::UpdateHomebindTime: Player '%s' (%s) will be teleported to homebind in 60 seconds", + GetName().c_str(), GetGUID().ToString().c_str()); } } @@ -21661,7 +21753,8 @@ bool Player::EnchantmentFitsRequirements(uint32 enchantmentcondition, int8 slot) } } - TC_LOG_DEBUG("entities.player.items", "Checking Condition %u, there are %u Meta Gems, %u Red Gems, %u Yellow Gems and %u Blue Gems, Activate:%s", enchantmentcondition, curcount[0], curcount[1], curcount[2], curcount[3], activate ? "yes" : "no"); + TC_LOG_DEBUG("entities.player.items", "Player::EnchantmentFitsRequirements: Checking Condition %u, there are %u Meta Gems, %u Red Gems, %u Yellow Gems and %u Blue Gems, Activate:%s", + enchantmentcondition, curcount[0], curcount[1], curcount[2], curcount[3], activate ? "yes" : "no"); return activate; } @@ -21773,7 +21866,7 @@ void Player::SetBattlegroundEntryPoint() if (const WorldSafeLocsEntry* entry = sObjectMgr->GetClosestGraveYard(GetPositionX(), GetPositionY(), GetPositionZ(), GetMapId(), GetTeam())) m_bgData.joinPos = WorldLocation(entry->map_id, entry->x, entry->y, entry->z, 0.0f); else - TC_LOG_ERROR("entities.player", "SetBattlegroundEntryPoint: Dungeon map %u has no linked graveyard, setting home location as entry point.", GetMapId()); + TC_LOG_ERROR("entities.player", "Player::SetBattlegroundEntryPoint: Dungeon (MapID: %u) has no linked graveyard, setting home location as entry point.", GetMapId()); } // If new entry point is not BG or arena set it else if (!GetMap()->IsBattlegroundOrArena()) @@ -22566,7 +22659,8 @@ void Player::LearnCustomSpells() for (PlayerCreateInfoSpells::const_iterator itr = info->customSpells.begin(); itr != info->customSpells.end(); ++itr) { uint32 tspell = *itr; - TC_LOG_DEBUG("entities.player.loading", "PLAYER (Class: %u Race: %u): Adding initial spell, id = %u", uint32(getClass()), uint32(getRace()), tspell); + TC_LOG_DEBUG("entities.player.loading", "Player::LearnCustomSpells: Player '%s' (%s, Class: %u Race: %u): Adding initial spell (SpellID: %u)", + GetName().c_str(), GetGUID().ToString().c_str(), uint32(getClass()), uint32(getRace()), tspell); if (!IsInWorld()) // will send in INITIAL_SPELLS in list anyway at map add AddSpell(tspell, true, true, true, false); else // but send in normal spell in game learn case @@ -23244,7 +23338,7 @@ bool Player::HasItemFitToSpellRequirements(SpellInfo const* spellInfo, Item cons break; } default: - TC_LOG_ERROR("entities.player", "HasItemFitToSpellRequirements: Spell requirement not handled for item class %u", spellInfo->EquippedItemClass); + TC_LOG_ERROR("entities.player", "Player::HasItemFitToSpellRequirements: Not handled spell requirement for item class %u", spellInfo->EquippedItemClass); break; } @@ -23896,11 +23990,12 @@ void Player::SetViewpoint(WorldObject* target, bool apply) { if (apply) { - TC_LOG_DEBUG("maps", "Player::CreateViewpoint: Player %s created seer %u (TypeId: %u).", GetName().c_str(), target->GetEntry(), target->GetTypeId()); + TC_LOG_DEBUG("maps", "Player::CreateViewpoint: Player '%s' (%s) creates seer (Entry: %u, TypeId: %u).", + GetName().c_str(), GetGUID().ToString().c_str(), target->GetEntry(), target->GetTypeId()); if (!AddGuidValue(PLAYER_FARSIGHT, target->GetGUID())) { - TC_LOG_FATAL("entities.player", "Player::CreateViewpoint: Player %s cannot add new viewpoint!", GetName().c_str()); + TC_LOG_FATAL("entities.player", "Player::CreateViewpoint: Player '%s' (%s) cannot add new viewpoint!", GetName().c_str(), GetGUID().ToString().c_str()); return; } @@ -23916,7 +24011,7 @@ void Player::SetViewpoint(WorldObject* target, bool apply) if (!RemoveGuidValue(PLAYER_FARSIGHT, target->GetGUID())) { - TC_LOG_FATAL("entities.player", "Player::CreateViewpoint: Player %s cannot remove current viewpoint!", GetName().c_str()); + TC_LOG_FATAL("entities.player", "Player::CreateViewpoint: Player '%s' (%s) cannot remove current viewpoint!", GetName().c_str(), GetGUID().ToString().c_str()); return; } @@ -24437,8 +24532,8 @@ void Player::_LoadSkills(PreparedQueryResult result) SkillRaceClassInfoEntry const* rcEntry = GetSkillRaceClassInfo(skill, getRace(), getClass()); if (!rcEntry) { - TC_LOG_ERROR("entities.player", "Character: %s (GUID: %u Race: %u Class: %u) has skill %u not allowed for his race/class combination", - GetName().c_str(), GetGUID().GetCounter(), uint32(getRace()), uint32(getClass()), skill); + TC_LOG_ERROR("entities.player", "Player::_LoadSkills: Player '%s' (%s, Race: %u, Class: %u) has forbidden skill %u for his race/class combination", + GetName().c_str(), GetGUID().ToString().c_str(), uint32(getRace()), uint32(getClass()), skill); mSkillStatus.insert(SkillStatusMap::value_type(skill, SkillStatusData(0, SKILL_DELETED))); continue; @@ -24461,7 +24556,8 @@ void Player::_LoadSkills(PreparedQueryResult result) if (value == 0) { - TC_LOG_ERROR("entities.player", "Character %u has skill %u with value 0. Skill will be deleted.", GetGUID().GetCounter(), skill); + TC_LOG_ERROR("entities.player", "Player::_LoadSkills: Player '%s' (%s) has skill %u with value 0, deleted.", + GetName().c_str(), GetGUID().ToString().c_str(), skill); PreparedStatement* stmt = CharacterDatabase.GetPreparedStatement(CHAR_DEL_CHARACTER_SKILL); @@ -24498,7 +24594,8 @@ void Player::_LoadSkills(PreparedQueryResult result) if (count >= PLAYER_MAX_SKILLS) // client limit { - TC_LOG_ERROR("entities.player", "Character %u has more than %u skills.", GetGUID().GetCounter(), PLAYER_MAX_SKILLS); + TC_LOG_ERROR("entities.player", "Player::_LoadSkills: Player '%s' (%s) has more than %u skills.", + GetName().c_str(), GetGUID().ToString().c_str(), PLAYER_MAX_SKILLS); break; } } @@ -24765,30 +24862,13 @@ void Player::LearnTalent(uint32 talentId, uint32 talentRank) uint32 tTab = talentInfo->TalentTab; if (talentInfo->Row > 0) - { - uint32 numRows = sTalentStore.GetNumRows(); - for (uint32 i = 0; i < numRows; i++) // Loop through all talents. - { - // Someday, someone needs to revamp - const TalentEntry* tmpTalent = sTalentStore.LookupEntry(i); - if (tmpTalent) // the way talents are tracked - { + for (uint32 i = 0; i < sTalentStore.GetNumRows(); i++) // Loop through all talents. + if (const TalentEntry* tmpTalent = sTalentStore.LookupEntry(i)) // the way talents are tracked if (tmpTalent->TalentTab == tTab) - { for (uint8 rank = 0; rank < MAX_TALENT_RANK; rank++) - { if (tmpTalent->RankID[rank] != 0) - { if (HasSpell(tmpTalent->RankID[rank])) - { spentPoints += (rank + 1); - } - } - } - } - } - } - } // not have required min points spent in talent tree if (spentPoints < (talentInfo->Row * MAX_TALENT_RANK)) @@ -24798,7 +24878,7 @@ void Player::LearnTalent(uint32 talentId, uint32 talentRank) uint32 spellid = talentInfo->RankID[talentRank]; if (spellid == 0) { - TC_LOG_ERROR("entities.player", "Talent.dbc contains talent: %u Rank: %u spell id = 0", talentId, talentRank); + TC_LOG_ERROR("entities.player", "Player::LearnTalent: Talent.dbc has no spellInfo for talent: %u (spell id = 0)", talentId); return; } @@ -24810,7 +24890,7 @@ void Player::LearnTalent(uint32 talentId, uint32 talentRank) LearnSpell(spellid, false); AddTalent(spellid, m_activeSpec, true); - TC_LOG_DEBUG("entities.player", "TalentID: %u Rank: %u Spell: %u Spec: %u\n", talentId, talentRank, spellid, m_activeSpec); + TC_LOG_DEBUG("misc", "Player::LearnTalent: TalentID: %u Spell: %u Group: %u\n", talentId, spellid, uint32(m_activeSpec)); // update free talent points SetFreeTalentPoints(CurTalentPoints - (talentRank - curtalent_maxrank + 1)); @@ -25129,7 +25209,11 @@ void Player::BuildPetTalentsInfoData(WorldPacket* data) { TalentEntry const* talentInfo = sTalentStore.LookupEntry(talentId); if (!talentInfo) + { + TC_LOG_ERROR("entities.player", "Player::SendTalentsInfoData: Player '%s' (%s) has unknown talent id: %u", + GetName().c_str(), GetGUID().ToString().c_str(), talentId); continue; + } // skip another tab talents if (talentInfo->TalentTab != talentTabId) @@ -25262,7 +25346,8 @@ void Player::SetEquipmentSet(uint32 index, EquipmentSet eqset) if (!found) // something wrong... { - TC_LOG_ERROR("entities.player", "Player %s tried to save equipment set " UI64FMTD " (index %u), but that equipment set was not found!", GetName().c_str(), eqset.Guid, index); + TC_LOG_ERROR("entities.player", "Player::SetEquipmentSet: Player '%s' (%s) tried to save nonexistent equipment set " UI64FMTD " (index: %u)", + GetName().c_str(), GetGUID().ToString().c_str(), eqset.Guid, index); return; } } @@ -26205,7 +26290,7 @@ Pet* Player::SummonPet(uint32 entry, float x, float y, float z, float ang, PetTy pet->Relocate(x, y, z, ang); if (!pet->IsPositionValid()) { - TC_LOG_ERROR("misc", "Pet (guidlow %d, entry %d) not summoned. Suggested coordinates are not valid (X: %f Y: %f)", pet->GetGUID().GetCounter(), pet->GetEntry(), pet->GetPositionX(), pet->GetPositionY()); + TC_LOG_ERROR("misc", "Player::SummonPet: Pet (%s, Entry: %d) not summoned. Suggested coordinates aren't valid (X: %f Y: %f)", pet->GetGUID().ToString().c_str(), pet->GetEntry(), pet->GetPositionX(), pet->GetPositionY()); delete pet; return nullptr; } @@ -26214,7 +26299,7 @@ Pet* Player::SummonPet(uint32 entry, float x, float y, float z, float ang, PetTy uint32 pet_number = sObjectMgr->GeneratePetNumber(); if (!pet->Create(map->GenerateLowGuid<HighGuid::Pet>(), map, GetPhaseMask(), entry, pet_number)) { - TC_LOG_ERROR("misc", "No such creature entry %u", entry); + TC_LOG_ERROR("misc", "Player::SummonPet: No such creature entry %u", entry); delete pet; return nullptr; } |