fix(parsing): bail on suspicious maskBlockCount in CREATE_OBJECT blocks

When spline parsing consumes the wrong number of bytes, the subsequent
blockCount read lands on garbage data (e.g. 71 instead of ~5 for UNIT).
Previously the parser logged a warning but continued, reading garbage
mask/field data until hitting truncation. Now it returns false for
CREATE_OBJECT blocks with suspicious counts, letting the block loop
skip cleanly to the next entity.

Also downgrade ~44 diagnostic LOG_WARNING messages to LOG_DEBUG across
17 files (equipment, transport, DBC, heartbeat, chat, GO raypick, etc.)
to reduce log noise and make real warnings visible.
This commit is contained in:
Kelsi 2026-04-05 20:12:17 -07:00
parent e32f4fbff9
commit 069dd36698
18 changed files with 46 additions and 43 deletions

View file

@ -191,7 +191,7 @@ void ChatHandler::handleMessageChat(network::Packet& packet) {
LOG_WARNING("Failed to parse SMSG_MESSAGECHAT, size=", packet.getSize());
return;
}
LOG_WARNING("INCOMING CHAT: type=", static_cast<int>(data.type),
LOG_DEBUG("INCOMING CHAT: type=", static_cast<int>(data.type),
" (", getChatTypeString(data.type), ") sender=0x", std::hex, data.senderGuid, std::dec,
" '", data.senderName, "' msg='", data.message.substr(0, 60), "'");

View file

@ -985,7 +985,7 @@ bool EntityController::applyPlayerStatFields(const std::map<uint16_t, uint32_t>&
// 0 = not resting, 1 = REST_TYPE_IN_TAVERN, 2 = REST_TYPE_IN_CITY
uint8_t restStateByte = static_cast<uint8_t>((val >> 24) & 0xFF);
if (isCreate) {
LOG_WARNING("PLAYER_BYTES_2 (CREATE): raw=0x", std::hex, val, std::dec,
LOG_DEBUG("PLAYER_BYTES_2 (CREATE): raw=0x", std::hex, val, std::dec,
" bankBagSlots=", static_cast<int>(bankBagSlots));
bool wasResting = owner_.isRestingRef();
owner_.isRestingRef() = (restStateByte != 0);

View file

@ -133,7 +133,7 @@ void GameHandler::sendAuthSession() {
}
void GameHandler::handleAuthResponse(network::Packet& packet) {
LOG_WARNING("Handling SMSG_AUTH_RESPONSE, size=", packet.getSize());
LOG_DEBUG("Handling SMSG_AUTH_RESPONSE, size=", packet.getSize());
AuthResponseData response;
if (!AuthResponseParser::parse(packet, response)) {
@ -1940,12 +1940,12 @@ void GameHandler::interactWithNpc(uint64_t guid) {
}
void GameHandler::interactWithGameObject(uint64_t guid) {
LOG_WARNING("[GO-DIAG] interactWithGameObject called: guid=0x", std::hex, guid, std::dec);
if (guid == 0) { LOG_WARNING("[GO-DIAG] BLOCKED: guid==0"); return; }
if (!isInWorld()) { LOG_WARNING("[GO-DIAG] BLOCKED: not in world"); return; }
LOG_DEBUG("[GO-DIAG] interactWithGameObject called: guid=0x", std::hex, guid, std::dec);
if (guid == 0) { LOG_DEBUG("[GO-DIAG] BLOCKED: guid==0"); return; }
if (!isInWorld()) { LOG_DEBUG("[GO-DIAG] BLOCKED: not in world"); return; }
// Do not overlap an actual spell cast.
if (spellHandler_ && spellHandler_->isCasting() && spellHandler_->getCurrentCastSpellId() != 0) {
LOG_WARNING("[GO-DIAG] BLOCKED: already casting spellId=", spellHandler_->getCurrentCastSpellId());
LOG_DEBUG("[GO-DIAG] BLOCKED: already casting spellId=", spellHandler_->getCurrentCastSpellId());
return;
}
// Always clear melee intent before GO interactions.

View file

@ -2775,7 +2775,7 @@ void GameHandler::handlePacket(network::Packet& packet) {
++wardenPacketsAfterGate_;
}
if (preLogicalOp && isAuthCharPipelineOpcode(*preLogicalOp)) {
LOG_WARNING("AUTH/CHAR RX opcode=0x", std::hex, opcode, std::dec,
LOG_DEBUG("AUTH/CHAR RX opcode=0x", std::hex, opcode, std::dec,
" logical=", static_cast<uint32_t>(*preLogicalOp),
" state=", worldStateName(state),
" size=", packet.getSize());

View file

@ -2483,7 +2483,7 @@ void InventoryHandler::handleItemQueryResponse(network::Packet& packet) {
}
}
if (reemitCount > 0) {
LOG_WARNING("Re-emitted equipment for ", reemitCount, " players after resolving entry=", resolvedEntry);
LOG_DEBUG("Re-emitted equipment for ", reemitCount, " players after resolving entry=", resolvedEntry);
}
// Same for inspect-based entries
if (owner_.playerEquipmentCallbackRef()) {
@ -3117,11 +3117,11 @@ void InventoryHandler::updateOtherPlayerVisibleItems(uint64_t guid, const std::m
dump += buf;
}
}
LOG_WARNING("RAW FIELDS 270-340:", dump);
LOG_DEBUG("RAW FIELDS 270-340:", dump);
}
if (nonZero > 0) {
LOG_WARNING("updateOtherPlayerVisibleItems: guid=0x", std::hex, guid, std::dec,
LOG_DEBUG("updateOtherPlayerVisibleItems: guid=0x", std::hex, guid, std::dec,
" nonZero=", nonZero, " base=", base, " stride=", stride,
" head=", newEntries[0], " shoulders=", newEntries[2],
" chest=", newEntries[4], " legs=", newEntries[6],
@ -3182,7 +3182,7 @@ void InventoryHandler::emitOtherPlayerEquipment(uint64_t guid) {
resolved++;
}
LOG_WARNING("emitOtherPlayerEquipment: guid=0x", std::hex, guid, std::dec,
LOG_DEBUG("emitOtherPlayerEquipment: guid=0x", std::hex, guid, std::dec,
" entries=", (anyEntry ? "yes" : "none"),
" resolved=", resolved, " unresolved=", unresolved,
" head=", displayIds[0], " shoulders=", displayIds[2],
@ -3192,7 +3192,7 @@ void InventoryHandler::emitOtherPlayerEquipment(uint64_t guid) {
// Don't emit all-zero displayIds — that strips existing equipment for no reason.
// Wait until at least one item resolves before applying.
if (anyEntry && resolved == 0) {
LOG_WARNING("emitOtherPlayerEquipment: skipping all-zero emit (waiting for item queries)");
LOG_DEBUG("emitOtherPlayerEquipment: skipping all-zero emit (waiting for item queries)");
return;
}

View file

@ -632,7 +632,7 @@ void MovementHandler::sendMovement(Opcode opcode) {
// Periodic position audit — log every ~60 heartbeats (~30s) to trace position drift.
if (opcode == Opcode::MSG_MOVE_HEARTBEAT && ++heartbeatLogCount_ % 60 == 0) {
LOG_WARNING("HEARTBEAT #", heartbeatLogCount_, " canonical=(",
LOG_DEBUG("HEARTBEAT #", heartbeatLogCount_, " canonical=(",
movementInfo.x, ",", movementInfo.y, ",", movementInfo.z,
") server=(", wireInfo.x, ",", wireInfo.y, ",", wireInfo.z,
") flags=0x", std::hex, movementInfo.flags, std::dec);
@ -2551,7 +2551,7 @@ void MovementHandler::loadAreaTriggerDbc() {
owner_.areaTriggersRef().push_back(at);
}
LOG_WARNING("Loaded ", owner_.areaTriggersRef().size(), " area triggers from AreaTrigger.dbc");
LOG_DEBUG("Loaded ", owner_.areaTriggersRef().size(), " area triggers from AreaTrigger.dbc");
}
void MovementHandler::checkAreaTriggers() {

View file

@ -979,7 +979,7 @@ void SpellHandler::handleSpellGo(network::Packet& packet) {
}
}
LOG_WARNING("[GO-DIAG] SPELL_GO: spellId=", data.spellId,
LOG_DEBUG("[GO-DIAG] SPELL_GO: spellId=", data.spellId,
" casting=", casting_, " currentCast=", currentCastSpellId_,
" wasInTimedCast=", wasInTimedCast,
" lastGoGuid=0x", std::hex, owner_.lastInteractedGoGuidRef(),
@ -992,7 +992,7 @@ void SpellHandler::handleSpellGo(network::Packet& packet) {
// Gather node looting: re-send CMSG_LOOT now that the cast completed.
if (wasInTimedCast && owner_.lastInteractedGoGuidRef() != 0) {
LOG_WARNING("[GO-DIAG] Sending CMSG_LOOT for GO 0x", std::hex,
LOG_DEBUG("[GO-DIAG] Sending CMSG_LOOT for GO 0x", std::hex,
owner_.lastInteractedGoGuidRef(), std::dec);
owner_.lootTarget(owner_.lastInteractedGoGuidRef());
owner_.lastInteractedGoGuidRef() = 0;

View file

@ -887,7 +887,7 @@ bool TransportManager::loadTransportAnimationDBC(pipeline::AssetManager* assetMg
if (transportEntry >= 176080 && transportEntry <= 176085) {
size_t mid = sortedWaypoints.size() / 4; // ~quarter through
size_t mid2 = sortedWaypoints.size() / 2; // ~halfway
LOG_WARNING("DBC path entry=", transportEntry, " nPts=", sortedWaypoints.size(),
LOG_DEBUG("DBC path entry=", transportEntry, " nPts=", sortedWaypoints.size(),
" [0] t=", sortedWaypoints[0].first, " raw=(", sortedWaypoints[0].second.x, ",", sortedWaypoints[0].second.y, ",", sortedWaypoints[0].second.z, ")",
" [", mid, "] t=", sortedWaypoints[mid].first, " raw=(", sortedWaypoints[mid].second.x, ",", sortedWaypoints[mid].second.y, ",", sortedWaypoints[mid].second.z, ")",
" [", mid2, "] t=", sortedWaypoints[mid2].first, " raw=(", sortedWaypoints[mid2].second.x, ",", sortedWaypoints[mid2].second.y, ",", sortedWaypoints[mid2].second.z, ")");

View file

@ -1201,6 +1201,9 @@ bool UpdateObjectParser::parseUpdateFields(network::Packet& packet, UpdateBlock&
" updateFlags=0x", std::hex, block.updateFlags, std::dec,
" moveFlags=0x", std::hex, block.moveFlags, std::dec,
" readPos=", packet.getReadPos(), " size=", packet.getSize());
// Movement data likely consumed wrong number of bytes, causing blockCount
// to be read from a misaligned position. Bail out rather than reading garbage.
if (isCreateBlock) return false;
}
uint32_t fieldsCapacity = blockCount * 32;