diff --git a/include/game/game_handler.hpp b/include/game/game_handler.hpp index ec2e343e..72b25a59 100644 --- a/include/game/game_handler.hpp +++ b/include/game/game_handler.hpp @@ -2488,6 +2488,15 @@ private: float pingInterval = 30.0f; // Ping interval (30 seconds) float timeSinceLastMoveHeartbeat_ = 0.0f; // Periodic movement heartbeat to keep server position synced float moveHeartbeatInterval_ = 0.5f; + uint32_t lastHeartbeatSendTimeMs_ = 0; + float lastHeartbeatX_ = 0.0f; + float lastHeartbeatY_ = 0.0f; + float lastHeartbeatZ_ = 0.0f; + uint32_t lastHeartbeatFlags_ = 0; + uint64_t lastHeartbeatTransportGuid_ = 0; + uint32_t lastNonHeartbeatMoveSendTimeMs_ = 0; + uint32_t lastFacingSendTimeMs_ = 0; + float lastFacingSentOrientation_ = 0.0f; uint32_t lastLatency = 0; // Last measured latency (milliseconds) std::chrono::steady_clock::time_point pingTimestamp_; // Time CMSG_PING was sent @@ -2588,6 +2597,7 @@ private: // ---- Phase 2: Combat ---- bool autoAttacking = false; bool autoAttackRequested_ = false; // local intent (CMSG_ATTACKSWING sent) + bool autoAttackRetryPending_ = false; // one-shot retry after local start or server stop uint64_t autoAttackTarget = 0; bool autoAttackOutOfRange_ = false; float autoAttackOutOfRangeTime_ = 0.0f; diff --git a/include/network/world_socket.hpp b/include/network/world_socket.hpp index 4192195c..543e570f 100644 --- a/include/network/world_socket.hpp +++ b/include/network/world_socket.hpp @@ -14,6 +14,7 @@ #include #include #include +#include namespace wowee { namespace network { @@ -90,6 +91,8 @@ private: void startAsyncPump(); void stopAsyncPump(); void closeSocketNoJoin(); + void recordRecentPacket(bool outbound, uint16_t opcode, uint16_t payloadLen); + void dumpRecentPacketHistoryLocked(const char* reason, size_t bufferedBytes); socket_t sockfd = INVALID_SOCK; bool connected = false; @@ -131,6 +134,14 @@ private: std::chrono::steady_clock::time_point packetTraceUntil_{}; std::string packetTraceReason_; + struct RecentPacketTrace { + std::chrono::steady_clock::time_point when{}; + bool outbound = false; + uint16_t opcode = 0; + uint16_t payloadLen = 0; + }; + std::deque recentPacketHistory_; + // Packet callback std::function packetCallback; }; diff --git a/src/game/game_handler.cpp b/src/game/game_handler.cpp index fbdaf5c8..a7eb5cb7 100644 --- a/src/game/game_handler.cpp +++ b/src/game/game_handler.cpp @@ -1045,9 +1045,27 @@ void GameHandler::update(float deltaTime) { const bool classicLikeCombatSync = autoAttackRequested_ && (isClassicLikeExpansion() || isActiveExpansion("tbc")); + const uint32_t locomotionFlags = + static_cast(MovementFlags::FORWARD) | + static_cast(MovementFlags::BACKWARD) | + static_cast(MovementFlags::STRAFE_LEFT) | + static_cast(MovementFlags::STRAFE_RIGHT) | + static_cast(MovementFlags::TURN_LEFT) | + static_cast(MovementFlags::TURN_RIGHT) | + static_cast(MovementFlags::ASCENDING) | + static_cast(MovementFlags::FALLING) | + static_cast(MovementFlags::FALLINGFAR); + const bool classicLikeStationaryCombatSync = + classicLikeCombatSync && + !onTaxiFlight_ && + !taxiActivatePending_ && + !taxiClientActive_ && + (movementInfo.flags & locomotionFlags) == 0; float heartbeatInterval = (onTaxiFlight_ || taxiActivatePending_ || taxiClientActive_) ? 0.25f - : (classicLikeCombatSync ? 0.05f : moveHeartbeatInterval_); + : (classicLikeStationaryCombatSync ? 0.75f + : (classicLikeCombatSync ? 0.20f + : moveHeartbeatInterval_)); if (timeSinceLastMoveHeartbeat_ >= heartbeatInterval) { sendMovement(Opcode::MSG_MOVE_HEARTBEAT); timeSinceLastMoveHeartbeat_ = 0.0f; @@ -1310,26 +1328,28 @@ void GameHandler::update(float deltaTime) { autoAttackResendTimer_ += deltaTime; autoAttackFacingSyncTimer_ += deltaTime; - // Re-request swing more aggressively until server confirms active loop. - float resendInterval = 1.0f; - if (!autoAttacking || autoAttackOutOfRange_) { - resendInterval = classicLike ? 0.25f : 0.50f; - } - if (autoAttackResendTimer_ >= resendInterval) { + // Classic/Turtle servers do not tolerate steady attack-start + // reissues well. Only retry once after local start or an + // explicit server-side attack stop while intent is still set. + const float resendInterval = classicLike ? 1.0f : 0.50f; + if (!autoAttacking && !autoAttackOutOfRange_ && autoAttackRetryPending_ && + autoAttackResendTimer_ >= resendInterval) { autoAttackResendTimer_ = 0.0f; + autoAttackRetryPending_ = false; auto pkt = AttackSwingPacket::build(autoAttackTarget); socket->send(pkt); } - // Keep server-facing aligned with our current melee target. - // Some vanilla-family realms become strict about front-arc checks unless - // the client sends explicit facing updates while stationary. - const float facingSyncInterval = classicLike ? 0.10f : 0.20f; - if (autoAttackFacingSyncTimer_ >= facingSyncInterval) { + // Keep server-facing aligned while trying to acquire melee. + // Once the server confirms auto-attack, rely on explicit + // bad-facing feedback instead of periodic steady-state facing spam. + const float facingSyncInterval = classicLike ? 0.25f : 0.20f; + const bool allowPeriodicFacingSync = !classicLike || !autoAttacking; + if (allowPeriodicFacingSync && + autoAttackFacingSyncTimer_ >= facingSyncInterval) { autoAttackFacingSyncTimer_ = 0.0f; float toTargetX = targetX - movementInfo.x; float toTargetY = targetY - movementInfo.y; - bool sentMovement = false; if (std::abs(toTargetX) > 0.01f || std::abs(toTargetY) > 0.01f) { float desired = std::atan2(-toTargetY, toTargetX); float diff = desired - movementInfo.orientation; @@ -1339,20 +1359,7 @@ void GameHandler::update(float deltaTime) { if (std::abs(diff) > facingThreshold) { movementInfo.orientation = desired; sendMovement(Opcode::MSG_MOVE_SET_FACING); - // Follow facing update with a heartbeat to tighten server range/facing checks. - sendMovement(Opcode::MSG_MOVE_HEARTBEAT); - sentMovement = true; } - } else if (classicLike) { - // Keep stationary melee position/facing fresh for strict vanilla-family checks. - sendMovement(Opcode::MSG_MOVE_HEARTBEAT); - sentMovement = true; - } - - // Even when facing is already correct, keep position fresh while - // trying to connect melee hits so servers don't require a step. - if (!sentMovement && (!autoAttacking || autoAttackOutOfRange_)) { - sendMovement(Opcode::MSG_MOVE_HEARTBEAT); } } } @@ -3129,21 +3136,6 @@ void GameHandler::handlePacket(network::Packet& packet) { addSystemChatMessage("Target is too far away."); autoAttackRangeWarnCooldown_ = 1.25f; } - if (autoAttackRequested_ && autoAttackTarget != 0 && socket) { - // Avoid blind immediate resend loops when target is clearly out of melee range. - bool likelyInRange = true; - if (auto target = entityManager.getEntity(autoAttackTarget)) { - float dx = movementInfo.x - target->getLatestX(); - float dy = movementInfo.y - target->getLatestY(); - float dz = movementInfo.z - target->getLatestZ(); - float dist3d = std::sqrt(dx * dx + dy * dy + dz * dz); - likelyInRange = (dist3d <= 7.5f); - } - if (likelyInRange) { - auto pkt = AttackSwingPacket::build(autoAttackTarget); - socket->send(pkt); - } - } break; case Opcode::SMSG_ATTACKSWING_BADFACING: if (autoAttackRequested_ && autoAttackTarget != 0) { @@ -3154,13 +3146,8 @@ void GameHandler::handlePacket(network::Packet& packet) { if (std::abs(toTargetX) > 0.01f || std::abs(toTargetY) > 0.01f) { movementInfo.orientation = std::atan2(-toTargetY, toTargetX); sendMovement(Opcode::MSG_MOVE_SET_FACING); - sendMovement(Opcode::MSG_MOVE_HEARTBEAT); } } - if (socket) { - auto pkt = AttackSwingPacket::build(autoAttackTarget); - socket->send(pkt); - } } break; case Opcode::SMSG_ATTACKSWING_NOTSTANDING: @@ -5361,6 +5348,7 @@ void GameHandler::handlePacket(network::Packet& packet) { } // ---- Teleport / Transfer ---- + case Opcode::MSG_MOVE_TELEPORT: case Opcode::MSG_MOVE_TELEPORT_ACK: handleTeleportAck(packet); break; @@ -8968,7 +8956,7 @@ void GameHandler::handleLoginVerifyWorld(network::Packet& packet) { // can close the session before our default 30s ping cadence fires. timeSinceLastPing = 0.0f; if (socket) { - LOG_WARNING("World entry keepalive: sending immediate ping after LOGIN_VERIFY_WORLD"); + LOG_DEBUG("World entry keepalive: sending immediate ping after LOGIN_VERIFY_WORLD"); sendPing(); } @@ -10000,8 +9988,8 @@ void GameHandler::sendPing() { // Increment sequence number pingSequence++; - LOG_WARNING("Sending CMSG_PING: sequence=", pingSequence, - " latencyHintMs=", lastLatency); + LOG_DEBUG("Sending CMSG_PING: sequence=", pingSequence, + " latencyHintMs=", lastLatency); // Record send time for RTT measurement pingTimestamp_ = std::chrono::steady_clock::now(); @@ -10051,7 +10039,7 @@ void GameHandler::sendMinimapPing(float wowX, float wowY) { } void GameHandler::handlePong(network::Packet& packet) { - LOG_WARNING("Handling SMSG_PONG"); + LOG_DEBUG("Handling SMSG_PONG"); PongData data; if (!PongParser::parse(packet, data)) { @@ -10071,8 +10059,8 @@ void GameHandler::handlePong(network::Packet& packet) { lastLatency = static_cast( std::chrono::duration_cast(rtt).count()); - LOG_WARNING("SMSG_PONG acknowledged: sequence=", data.sequence, - " latencyMs=", lastLatency); + LOG_DEBUG("SMSG_PONG acknowledged: sequence=", data.sequence, + " latencyMs=", lastLatency); } uint32_t GameHandler::nextMovementTimestampMs() { @@ -10116,7 +10104,21 @@ void GameHandler::sendMovement(Opcode opcode) { if (resurrectPending_ && !taxiAllowed) return; // Always send a strictly increasing non-zero client movement clock value. - movementInfo.time = nextMovementTimestampMs(); + const uint32_t movementTime = nextMovementTimestampMs(); + movementInfo.time = movementTime; + + if (opcode == Opcode::MSG_MOVE_SET_FACING && + (isClassicLikeExpansion() || isActiveExpansion("tbc"))) { + const float facingDelta = core::coords::normalizeAngleRad( + movementInfo.orientation - lastFacingSentOrientation_); + const uint32_t sinceLastFacingMs = + lastFacingSendTimeMs_ != 0 && movementTime >= lastFacingSendTimeMs_ + ? (movementTime - lastFacingSendTimeMs_) + : std::numeric_limits::max(); + if (std::abs(facingDelta) < 0.02f && sinceLastFacingMs < 200U) { + return; + } + } // Update movement flags based on opcode switch (opcode) { @@ -10190,6 +10192,7 @@ void GameHandler::sendMovement(Opcode opcode) { break; case Opcode::MSG_MOVE_HEARTBEAT: // No flag changes — just sends current position + timeSinceLastMoveHeartbeat_ = 0.0f; break; case Opcode::MSG_MOVE_START_ASCEND: movementInfo.flags |= static_cast(MovementFlags::ASCENDING); @@ -10206,6 +10209,11 @@ void GameHandler::sendMovement(Opcode opcode) { break; } + if (opcode == Opcode::MSG_MOVE_SET_FACING) { + lastFacingSendTimeMs_ = movementInfo.time; + lastFacingSentOrientation_ = movementInfo.orientation; + } + // Keep fallTime current: it must equal the elapsed milliseconds since FALLING // was set, so the server can compute fall damage correctly. if (isFalling_ && movementInfo.hasFlag(MovementFlags::FALLING)) { @@ -10278,6 +10286,49 @@ void GameHandler::sendMovement(Opcode opcode) { movementInfo.transportSeat = -1; } + if (opcode == Opcode::MSG_MOVE_HEARTBEAT && isClassicLikeExpansion()) { + const uint32_t locomotionFlags = + static_cast(MovementFlags::FORWARD) | + static_cast(MovementFlags::BACKWARD) | + static_cast(MovementFlags::STRAFE_LEFT) | + static_cast(MovementFlags::STRAFE_RIGHT) | + static_cast(MovementFlags::TURN_LEFT) | + static_cast(MovementFlags::TURN_RIGHT) | + static_cast(MovementFlags::ASCENDING) | + static_cast(MovementFlags::FALLING) | + static_cast(MovementFlags::FALLINGFAR) | + static_cast(MovementFlags::SWIMMING); + const bool stationaryIdle = + !onTaxiFlight_ && + !taxiMountActive_ && + !taxiActivatePending_ && + !taxiClientActive_ && + !includeTransportInWire && + (movementInfo.flags & locomotionFlags) == 0; + const uint32_t sinceLastHeartbeatMs = + lastHeartbeatSendTimeMs_ != 0 && movementTime >= lastHeartbeatSendTimeMs_ + ? (movementTime - lastHeartbeatSendTimeMs_) + : std::numeric_limits::max(); + const bool unchangedState = + std::abs(movementInfo.x - lastHeartbeatX_) < 0.01f && + std::abs(movementInfo.y - lastHeartbeatY_) < 0.01f && + std::abs(movementInfo.z - lastHeartbeatZ_) < 0.01f && + movementInfo.flags == lastHeartbeatFlags_ && + movementInfo.transportGuid == lastHeartbeatTransportGuid_; + if (stationaryIdle && unchangedState && sinceLastHeartbeatMs < 1500U) { + timeSinceLastMoveHeartbeat_ = 0.0f; + return; + } + const uint32_t sinceLastNonHeartbeatMoveMs = + lastNonHeartbeatMoveSendTimeMs_ != 0 && movementTime >= lastNonHeartbeatMoveSendTimeMs_ + ? (movementTime - lastNonHeartbeatMoveSendTimeMs_) + : std::numeric_limits::max(); + if (sinceLastNonHeartbeatMoveMs < 350U) { + timeSinceLastMoveHeartbeat_ = 0.0f; + return; + } + } + LOG_DEBUG("Sending movement packet: opcode=0x", std::hex, wireOpcode(opcode), std::dec, (includeTransportInWire ? " ONTRANSPORT" : "")); @@ -10308,6 +10359,17 @@ void GameHandler::sendMovement(Opcode opcode) { ? packetParsers_->buildMovementPacket(opcode, wireInfo, playerGuid) : MovementPacket::build(opcode, wireInfo, playerGuid); socket->send(packet); + + if (opcode == Opcode::MSG_MOVE_HEARTBEAT) { + lastHeartbeatSendTimeMs_ = movementInfo.time; + lastHeartbeatX_ = movementInfo.x; + lastHeartbeatY_ = movementInfo.y; + lastHeartbeatZ_ = movementInfo.z; + lastHeartbeatFlags_ = movementInfo.flags; + lastHeartbeatTransportGuid_ = movementInfo.transportGuid; + } else { + lastNonHeartbeatMoveSendTimeMs_ = movementInfo.time; + } } void GameHandler::sanitizeMovementForTaxi() { @@ -14692,6 +14754,7 @@ void GameHandler::startAutoAttack(uint64_t targetGuid) { } autoAttackRequested_ = true; + autoAttackRetryPending_ = true; // Keep combat animation/state server-authoritative. We only flip autoAttacking // on SMSG_ATTACKSTART where attackerGuid == playerGuid. autoAttacking = false; @@ -14711,6 +14774,7 @@ void GameHandler::stopAutoAttack() { if (!autoAttacking && !autoAttackRequested_) return; autoAttackRequested_ = false; autoAttacking = false; + autoAttackRetryPending_ = false; autoAttackTarget = 0; autoAttackOutOfRange_ = false; autoAttackOutOfRangeTime_ = 0.0f; @@ -14805,6 +14869,7 @@ void GameHandler::handleAttackStart(network::Packet& packet) { if (data.attackerGuid == playerGuid) { autoAttackRequested_ = true; autoAttacking = true; + autoAttackRetryPending_ = false; autoAttackTarget = data.victimGuid; } else if (data.victimGuid == playerGuid && data.attackerGuid != 0) { hostileAttackers_.insert(data.attackerGuid); @@ -14842,13 +14907,9 @@ void GameHandler::handleAttackStop(network::Packet& packet) { // Keep intent, but clear server-confirmed active state until ATTACKSTART resumes. if (data.attackerGuid == playerGuid) { autoAttacking = false; + autoAttackRetryPending_ = autoAttackRequested_; + autoAttackResendTimer_ = 0.0f; LOG_DEBUG("SMSG_ATTACKSTOP received (keeping auto-attack intent)"); - if (autoAttackRequested_ && autoAttackTarget != 0 && socket) { - // Classic-family servers may emit transient ATTACKSTOP when range/facing jitters. - // Reassert melee intent immediately instead of waiting for periodic resend. - auto pkt = AttackSwingPacket::build(autoAttackTarget); - socket->send(pkt); - } } else if (data.victimGuid == playerGuid) { hostileAttackers_.erase(data.attackerGuid); } diff --git a/src/game/packet_parsers_classic.cpp b/src/game/packet_parsers_classic.cpp index 4cccc4a5..7b25d257 100644 --- a/src/game/packet_parsers_classic.cpp +++ b/src/game/packet_parsers_classic.cpp @@ -1,5 +1,8 @@ #include "game/packet_parsers.hpp" #include "core/logger.hpp" +#include +#include +#include namespace wowee { namespace game { @@ -22,6 +25,99 @@ bool hasFullPackedGuid(const network::Packet& packet) { return packet.getSize() - packet.getReadPos() >= guidBytes; } +std::string formatPacketBytes(const network::Packet& packet, size_t startPos) { + const auto& rawData = packet.getData(); + if (startPos >= rawData.size()) { + return {}; + } + + std::string hex; + hex.reserve((rawData.size() - startPos) * 3); + for (size_t i = startPos; i < rawData.size(); ++i) { + char buf[4]; + std::snprintf(buf, sizeof(buf), "%02x ", rawData[i]); + hex += buf; + } + if (!hex.empty()) { + hex.pop_back(); + } + return hex; +} + +bool skipClassicSpellCastTargets(network::Packet& packet, uint64_t* primaryTargetGuid = nullptr) { + if (packet.getSize() - packet.getReadPos() < 2) { + return false; + } + + const uint16_t targetFlags = packet.readUInt16(); + + const auto readPackedTargetGuid = [&](bool capture) -> bool { + if (!hasFullPackedGuid(packet)) { + return false; + } + const uint64_t guid = UpdateObjectParser::readPackedGuid(packet); + if (capture && primaryTargetGuid && *primaryTargetGuid == 0) { + *primaryTargetGuid = guid; + } + return true; + }; + + // Common Classic/Turtle SpellCastTargets payloads. + if ((targetFlags & 0x0002) != 0 && !readPackedTargetGuid(true)) { // UNIT + return false; + } + if ((targetFlags & 0x0004) != 0 && !readPackedTargetGuid(false)) { // UNIT_MINIPET/extra guid + return false; + } + if ((targetFlags & 0x0010) != 0 && !readPackedTargetGuid(false)) { // ITEM + return false; + } + if ((targetFlags & 0x0800) != 0 && !readPackedTargetGuid(true)) { // OBJECT + return false; + } + if ((targetFlags & 0x8000) != 0 && !readPackedTargetGuid(false)) { // CORPSE + return false; + } + + if ((targetFlags & 0x0020) != 0) { // SOURCE_LOCATION + if (packet.getSize() - packet.getReadPos() < 12) { + return false; + } + (void)packet.readFloat(); + (void)packet.readFloat(); + (void)packet.readFloat(); + } + if ((targetFlags & 0x0040) != 0) { // DEST_LOCATION + if (packet.getSize() - packet.getReadPos() < 12) { + return false; + } + (void)packet.readFloat(); + (void)packet.readFloat(); + (void)packet.readFloat(); + } + + if ((targetFlags & 0x1000) != 0) { // TRADE_ITEM + if (packet.getSize() - packet.getReadPos() < 1) { + return false; + } + (void)packet.readUInt8(); + } + + if ((targetFlags & 0x2000) != 0) { // STRING + const auto& rawData = packet.getData(); + size_t pos = packet.getReadPos(); + while (pos < rawData.size() && rawData[pos] != 0) { + ++pos; + } + if (pos >= rawData.size()) { + return false; + } + packet.setReadPos(pos + 1); + } + + return true; +} + const char* updateTypeName(UpdateType type) { switch (type) { case UpdateType::VALUES: return "VALUES"; @@ -53,6 +149,36 @@ namespace ClassicMoveFlags { constexpr uint32_t SPLINE_ELEVATION = 0x04000000; // Same as TBC } +uint32_t classicWireMoveFlags(uint32_t internalFlags) { + uint32_t wireFlags = internalFlags; + + // Internal movement state is tracked with WotLK-era bits. Classic/Turtle + // movement packets still use the older transport/jump flag layout. + const uint32_t kInternalOnTransport = static_cast(MovementFlags::ONTRANSPORT); + const uint32_t kInternalFalling = + static_cast(MovementFlags::FALLING) | + static_cast(MovementFlags::FALLINGFAR); + const uint32_t kClassicConflicts = + static_cast(MovementFlags::ASCENDING) | + static_cast(MovementFlags::CAN_FLY) | + static_cast(MovementFlags::FLYING) | + static_cast(MovementFlags::HOVER); + + wireFlags &= ~kClassicConflicts; + + if ((internalFlags & kInternalOnTransport) != 0) { + wireFlags &= ~kInternalOnTransport; + wireFlags |= ClassicMoveFlags::ONTRANSPORT; + } + + if ((internalFlags & kInternalFalling) != 0) { + wireFlags &= ~kInternalFalling; + wireFlags |= ClassicMoveFlags::JUMPING; + } + + return wireFlags; +} + // ============================================================================ // Classic parseMovementBlock // Key differences from TBC: @@ -226,8 +352,10 @@ bool ClassicPacketParsers::parseMovementBlock(network::Packet& packet, UpdateBlo // - Pitch: only SWIMMING (no ONTRANSPORT pitch) // ============================================================================ void ClassicPacketParsers::writeMovementPayload(network::Packet& packet, const MovementInfo& info) { + const uint32_t wireFlags = classicWireMoveFlags(info.flags); + // Movement flags (uint32) - packet.writeUInt32(info.flags); + packet.writeUInt32(wireFlags); // Classic: NO flags2 byte (TBC has u8, WotLK has u16) @@ -241,7 +369,7 @@ void ClassicPacketParsers::writeMovementPayload(network::Packet& packet, const M packet.writeBytes(reinterpret_cast(&info.orientation), sizeof(float)); // Transport data (Classic ONTRANSPORT = 0x02000000, no timestamp) - if (info.flags & ClassicMoveFlags::ONTRANSPORT) { + if (wireFlags & ClassicMoveFlags::ONTRANSPORT) { // Packed transport GUID uint8_t transMask = 0; uint8_t transGuidBytes[8]; @@ -269,7 +397,7 @@ void ClassicPacketParsers::writeMovementPayload(network::Packet& packet, const M } // Pitch (Classic: only SWIMMING) - if (info.flags & ClassicMoveFlags::SWIMMING) { + if (wireFlags & ClassicMoveFlags::SWIMMING) { packet.writeBytes(reinterpret_cast(&info.pitch), sizeof(float)); } @@ -277,7 +405,7 @@ void ClassicPacketParsers::writeMovementPayload(network::Packet& packet, const M packet.writeUInt32(info.fallTime); // Jump data (Classic JUMPING = 0x2000) - if (info.flags & ClassicMoveFlags::JUMPING) { + if (wireFlags & ClassicMoveFlags::JUMPING) { packet.writeBytes(reinterpret_cast(&info.jumpVelocity), sizeof(float)); packet.writeBytes(reinterpret_cast(&info.jumpSinAngle), sizeof(float)); packet.writeBytes(reinterpret_cast(&info.jumpCosAngle), sizeof(float)); @@ -362,7 +490,7 @@ network::Packet ClassicPacketParsers::buildUseItem(uint8_t bagIndex, uint8_t slo // - castFlags is uint16 (NOT uint32 as in TBC/WotLK). // - SpellCastTargets uses uint16 targetFlags (NOT uint32 as in TBC). // -// Format: PackedGuid(casterObj) + PackedGuid(casterUnit) + uint8(castCount) +// Format: PackedGuid(casterObj) + PackedGuid(casterUnit) // + uint32(spellId) + uint16(castFlags) + uint32(castTime) // + uint16(targetFlags) [+ PackedGuid(unitTarget) if TARGET_FLAG_UNIT] // ============================================================================ @@ -384,9 +512,10 @@ bool ClassicPacketParsers::parseSpellStart(network::Packet& packet, SpellStartDa } data.casterUnit = UpdateObjectParser::readPackedGuid(packet); - // uint8 castCount + uint32 spellId + uint16 castFlags + uint32 castTime = 11 bytes - if (rem() < 11) return false; - data.castCount = packet.readUInt8(); + // Vanilla/Turtle SMSG_SPELL_START does not include castCount here. + // Layout after the two packed GUIDs is spellId(u32) + castFlags(u16) + castTime(u32). + if (rem() < 10) return false; + data.castCount = 0; data.spellId = packet.readUInt32(); data.castFlags = packet.readUInt16(); // uint16 in Vanilla (uint32 in TBC/WotLK) data.castTime = packet.readUInt32(); @@ -419,7 +548,7 @@ bool ClassicPacketParsers::parseSpellStart(network::Packet& packet, SpellStartDa // - castFlags is uint16 (not uint32) // - Hit/miss target GUIDs are also PackedGuid in Vanilla // -// Format: PackedGuid(casterObj) + PackedGuid(casterUnit) + uint8(castCount) +// Format: PackedGuid(casterObj) + PackedGuid(casterUnit) // + uint32(spellId) + uint16(castFlags) // + uint8(hitCount) + [PackedGuid(hitTarget) × hitCount] // + uint8(missCount) + [PackedGuid(missTarget) + uint8(missType)] × missCount @@ -430,6 +559,24 @@ bool ClassicPacketParsers::parseSpellGo(network::Packet& packet, SpellGoData& da auto rem = [&]() { return packet.getSize() - packet.getReadPos(); }; const size_t startPos = packet.getReadPos(); + const bool traceSmallSpellGo = (packet.getSize() - startPos) <= 48; + const auto traceFailure = [&](const char* stage, size_t pos, uint32_t value = 0) { + if (!traceSmallSpellGo) { + return; + } + static uint32_t smallSpellGoTraceCount = 0; + ++smallSpellGoTraceCount; + if (smallSpellGoTraceCount > 12 && (smallSpellGoTraceCount % 50) != 0) { + return; + } + LOG_WARNING("[Classic] Spell go trace: stage=", stage, + " pos=", pos, + " size=", packet.getSize() - startPos, + " spell=", data.spellId, + " castFlags=0x", std::hex, data.castFlags, std::dec, + " value=", value, + " bytes=[", formatPacketBytes(packet, startPos), "]"); + }; if (rem() < 2) return false; if (!hasFullPackedGuid(packet)) return false; @@ -437,113 +584,186 @@ bool ClassicPacketParsers::parseSpellGo(network::Packet& packet, SpellGoData& da if (!hasFullPackedGuid(packet)) return false; data.casterUnit = UpdateObjectParser::readPackedGuid(packet); - // uint8 castCount + uint32 spellId + uint16 castFlags = 7 bytes - if (rem() < 7) return false; - data.castCount = packet.readUInt8(); + // Vanilla/Turtle SMSG_SPELL_GO does not include castCount here. + // Layout after the two packed GUIDs is spellId(u32) + castFlags(u16). + if (rem() < 6) return false; + data.castCount = 0; data.spellId = packet.readUInt32(); data.castFlags = packet.readUInt16(); // uint16 in Vanilla (uint32 in TBC/WotLK) - // hitCount is mandatory in SMSG_SPELL_GO. Missing byte means truncation. - if (rem() < 1) { - LOG_WARNING("[Classic] Spell go: missing hitCount after fixed fields"); - packet.setReadPos(startPos); - return false; - } - const uint8_t rawHitCount = packet.readUInt8(); - if (rawHitCount > 128) { - LOG_WARNING("[Classic] Spell go: hitCount capped (requested=", (int)rawHitCount, ")"); - } - // Packed GUIDs are variable length, but each target needs at least 1 byte (mask). - // Require the minimum bytes before entering per-target parsing loops. - if (rem() < static_cast(rawHitCount) + 1u) { // +1 for mandatory missCount byte - static uint32_t badHitCountTrunc = 0; - ++badHitCountTrunc; - if (badHitCountTrunc <= 10 || (badHitCountTrunc % 100) == 0) { - LOG_WARNING("[Classic] Spell go: invalid hitCount/remaining (hits=", (int)rawHitCount, - " remaining=", rem(), " occurrence=", badHitCountTrunc, ")"); - } - packet.setReadPos(startPos); - return false; - } - const uint8_t storedHitLimit = std::min(rawHitCount, 128); - data.hitTargets.reserve(storedHitLimit); - bool truncatedTargets = false; - for (uint16_t i = 0; i < rawHitCount; ++i) { - if (!hasFullPackedGuid(packet)) { - LOG_WARNING("[Classic] Spell go: truncated hit targets at index ", i, - "/", (int)rawHitCount); - truncatedTargets = true; - break; - } - const uint64_t targetGuid = UpdateObjectParser::readPackedGuid(packet); - if (i < storedHitLimit) { - data.hitTargets.push_back(targetGuid); - } - } - if (truncatedTargets) { - packet.setReadPos(startPos); - return false; - } - data.hitCount = static_cast(data.hitTargets.size()); + const size_t countsPos = packet.getReadPos(); + uint64_t ignoredTargetGuid = 0; + std::function parseHitAndMissLists = [&](bool allowTargetsFallback) -> bool { + packet.setReadPos(countsPos); + data.hitTargets.clear(); + data.missTargets.clear(); + ignoredTargetGuid = 0; - // missCount is mandatory in SMSG_SPELL_GO. Missing byte means truncation. - if (rem() < 1) { - LOG_WARNING("[Classic] Spell go: missing missCount after hit target list"); - packet.setReadPos(startPos); - return false; - } - const uint8_t rawMissCount = packet.readUInt8(); - if (rawMissCount > 128) { - LOG_WARNING("[Classic] Spell go: missCount capped (requested=", (int)rawMissCount, ")"); - } - // Each miss entry needs at least packed-guid mask (1) + missType (1). - if (rem() < static_cast(rawMissCount) * 2u) { - static uint32_t badMissCountTrunc = 0; - ++badMissCountTrunc; - if (badMissCountTrunc <= 10 || (badMissCountTrunc % 100) == 0) { - LOG_WARNING("[Classic] Spell go: invalid missCount/remaining (misses=", (int)rawMissCount, - " remaining=", rem(), " occurrence=", badMissCountTrunc, ")"); - } - packet.setReadPos(startPos); - return false; - } - const uint8_t storedMissLimit = std::min(rawMissCount, 128); - data.missTargets.reserve(storedMissLimit); - for (uint16_t i = 0; i < rawMissCount; ++i) { - if (!hasFullPackedGuid(packet)) { - LOG_WARNING("[Classic] Spell go: truncated miss targets at index ", i, - "/", (int)rawMissCount); - truncatedTargets = true; - break; - } - SpellGoMissEntry m; - m.targetGuid = UpdateObjectParser::readPackedGuid(packet); + // hitCount is mandatory in SMSG_SPELL_GO. Missing byte means truncation. if (rem() < 1) { - LOG_WARNING("[Classic] Spell go: missing missType at miss index ", i, - "/", (int)rawMissCount); - truncatedTargets = true; - break; + LOG_WARNING("[Classic] Spell go: missing hitCount after fixed fields"); + traceFailure("missing_hit_count", packet.getReadPos()); + packet.setReadPos(startPos); + return false; } - m.missType = packet.readUInt8(); - if (m.missType == 11) { - if (rem() < 5) { - LOG_WARNING("[Classic] Spell go: truncated reflect payload at miss index ", i, - "/", (int)rawMissCount); - truncatedTargets = true; - break; + const uint8_t rawHitCount = packet.readUInt8(); + if (rawHitCount > 128) { + LOG_WARNING("[Classic] Spell go: hitCount capped (requested=", (int)rawHitCount, ")"); + } + if (rem() < static_cast(rawHitCount) + 1u) { + static uint32_t badHitCountTrunc = 0; + ++badHitCountTrunc; + if (badHitCountTrunc <= 10 || (badHitCountTrunc % 100) == 0) { + LOG_WARNING("[Classic] Spell go: invalid hitCount/remaining (hits=", (int)rawHitCount, + " remaining=", rem(), " occurrence=", badHitCountTrunc, ")"); } - (void)packet.readUInt32(); - (void)packet.readUInt8(); + traceFailure("invalid_hit_count", packet.getReadPos(), rawHitCount); + packet.setReadPos(startPos); + return false; } - if (i < storedMissLimit) { - data.missTargets.push_back(m); + + const auto parseHitList = [&](bool usePackedGuids) -> bool { + packet.setReadPos(countsPos + 1); // after hitCount + data.hitTargets.clear(); + const uint8_t storedHitLimit = std::min(rawHitCount, 128); + data.hitTargets.reserve(storedHitLimit); + for (uint16_t i = 0; i < rawHitCount; ++i) { + uint64_t targetGuid = 0; + if (usePackedGuids) { + if (!hasFullPackedGuid(packet)) { + return false; + } + targetGuid = UpdateObjectParser::readPackedGuid(packet); + } else { + if (rem() < 8) { + return false; + } + targetGuid = packet.readUInt64(); + } + if (i < storedHitLimit) { + data.hitTargets.push_back(targetGuid); + } + } + data.hitCount = static_cast(data.hitTargets.size()); + return true; + }; + + if (!parseHitList(false) && !parseHitList(true)) { + LOG_WARNING("[Classic] Spell go: truncated hit targets at index 0/", (int)rawHitCount); + traceFailure("truncated_hit_target", packet.getReadPos(), rawHitCount); + packet.setReadPos(startPos); + return false; } - } - if (truncatedTargets) { - packet.setReadPos(startPos); + + std::function parseMissListFrom = [&](size_t missStartPos, + bool allowMidTargetsFallback) -> bool { + packet.setReadPos(missStartPos); + data.missTargets.clear(); + + if (rem() < 1) { + LOG_WARNING("[Classic] Spell go: missing missCount after hit target list"); + traceFailure("missing_miss_count", packet.getReadPos()); + packet.setReadPos(startPos); + return false; + } + const uint8_t rawMissCount = packet.readUInt8(); + if (rawMissCount > 128) { + LOG_WARNING("[Classic] Spell go: missCount capped (requested=", (int)rawMissCount, ")"); + traceFailure("miss_count_capped", packet.getReadPos() - 1, rawMissCount); + } + if (rem() < static_cast(rawMissCount) * 2u) { + if (allowMidTargetsFallback) { + packet.setReadPos(missStartPos); + if (skipClassicSpellCastTargets(packet, &ignoredTargetGuid)) { + traceFailure("mid_targets_fallback", missStartPos, ignoredTargetGuid != 0 ? 1u : 0u); + return parseMissListFrom(packet.getReadPos(), false); + } + } + if (allowTargetsFallback) { + packet.setReadPos(countsPos); + if (skipClassicSpellCastTargets(packet, &ignoredTargetGuid)) { + traceFailure("pre_targets_fallback", countsPos, ignoredTargetGuid != 0 ? 1u : 0u); + return parseHitAndMissLists(false); + } + } + + static uint32_t badMissCountTrunc = 0; + ++badMissCountTrunc; + if (badMissCountTrunc <= 10 || (badMissCountTrunc % 100) == 0) { + LOG_WARNING("[Classic] Spell go: invalid missCount/remaining (misses=", (int)rawMissCount, + " remaining=", rem(), " occurrence=", badMissCountTrunc, ")"); + } + traceFailure("invalid_miss_count", packet.getReadPos(), rawMissCount); + packet.setReadPos(startPos); + return false; + } + + const uint8_t storedMissLimit = std::min(rawMissCount, 128); + data.missTargets.reserve(storedMissLimit); + bool truncatedMissTargets = false; + const auto parseMissEntry = [&](SpellGoMissEntry& m, bool usePackedGuid) -> bool { + if (usePackedGuid) { + if (!hasFullPackedGuid(packet)) { + return false; + } + m.targetGuid = UpdateObjectParser::readPackedGuid(packet); + } else { + if (rem() < 8) { + return false; + } + m.targetGuid = packet.readUInt64(); + } + return true; + }; + for (uint16_t i = 0; i < rawMissCount; ++i) { + SpellGoMissEntry m; + const size_t missEntryPos = packet.getReadPos(); + if (!parseMissEntry(m, false)) { + packet.setReadPos(missEntryPos); + if (!parseMissEntry(m, true)) { + LOG_WARNING("[Classic] Spell go: truncated miss targets at index ", i, + "/", (int)rawMissCount); + traceFailure("truncated_miss_target", packet.getReadPos(), i); + truncatedMissTargets = true; + break; + } + } + if (rem() < 1) { + LOG_WARNING("[Classic] Spell go: missing missType at miss index ", i, + "/", (int)rawMissCount); + traceFailure("missing_miss_type", packet.getReadPos(), i); + truncatedMissTargets = true; + break; + } + m.missType = packet.readUInt8(); + if (m.missType == 11) { + if (rem() < 1) { + LOG_WARNING("[Classic] Spell go: truncated reflect payload at miss index ", i, + "/", (int)rawMissCount); + traceFailure("truncated_reflect", packet.getReadPos(), i); + truncatedMissTargets = true; + break; + } + (void)packet.readUInt8(); + } + if (i < storedMissLimit) { + data.missTargets.push_back(m); + } + } + if (truncatedMissTargets) { + packet.setReadPos(startPos); + return false; + } + data.missCount = static_cast(data.missTargets.size()); + return true; + }; + + return parseMissListFrom(packet.getReadPos(), true); + }; + + if (!parseHitAndMissLists(true)) { return false; } - data.missCount = static_cast(data.missTargets.size()); LOG_DEBUG("[Classic] Spell go: spell=", data.spellId, " hits=", (int)data.hitCount, " misses=", (int)data.missCount); diff --git a/src/game/world_packets.cpp b/src/game/world_packets.cpp index 2f8d5deb..5a9804a1 100644 --- a/src/game/world_packets.cpp +++ b/src/game/world_packets.cpp @@ -1883,15 +1883,16 @@ network::Packet RequestPlayedTimePacket::build(bool sendToChat) { } bool PlayedTimeParser::parse(network::Packet& packet, PlayedTimeData& data) { - // Validate minimum packet size: totalTime(4) + levelTime(4) + triggerMsg(1) - if (packet.getSize() - packet.getReadPos() < 9) { + // Classic/Turtle may omit the trailing trigger-message byte and send only + // totalTime(4) + levelTime(4). Later expansions append triggerMsg(1). + if (packet.getSize() - packet.getReadPos() < 8) { LOG_WARNING("SMSG_PLAYED_TIME: packet too small (", packet.getSize(), " bytes)"); return false; } data.totalTimePlayed = packet.readUInt32(); data.levelTimePlayed = packet.readUInt32(); - data.triggerMessage = packet.readUInt8() != 0; + data.triggerMessage = (packet.getSize() - packet.getReadPos() >= 1) && (packet.readUInt8() != 0); LOG_DEBUG("Parsed SMSG_PLAYED_TIME: total=", data.totalTimePlayed, " level=", data.levelTimePlayed); return true; } diff --git a/src/network/world_socket.cpp b/src/network/world_socket.cpp index e84d7426..40cf2251 100644 --- a/src/network/world_socket.cpp +++ b/src/network/world_socket.cpp @@ -25,6 +25,9 @@ constexpr int kMaxRecvCallsPerUpdate = 64; constexpr size_t kMaxRecvBytesPerUpdate = 512 * 1024; constexpr size_t kMaxQueuedPacketCallbacks = 4096; constexpr int kAsyncPumpSleepMs = 2; +constexpr size_t kRecentPacketHistoryLimit = 96; +constexpr auto kRecentPacketHistoryWindow = std::chrono::seconds(15); +constexpr const char* kCloseTraceEnv = "WOWEE_NET_CLOSE_TRACE"; inline int parsedPacketsBudgetPerUpdate() { static int budget = []() { @@ -250,8 +253,8 @@ void WorldSocket::tracePacketsFor(std::chrono::milliseconds duration, const std: packetTraceStart_ = std::chrono::steady_clock::now(); packetTraceUntil_ = packetTraceStart_ + duration; packetTraceReason_ = reason; - LOG_WARNING("WS TRACE enabled: reason='", packetTraceReason_, - "' durationMs=", duration.count()); + LOG_DEBUG("WS TRACE enabled: reason='", packetTraceReason_, + "' durationMs=", duration.count()); } bool WorldSocket::isConnected() const { @@ -267,6 +270,40 @@ void WorldSocket::closeSocketNoJoin() { connected = false; } +void WorldSocket::recordRecentPacket(bool outbound, uint16_t opcode, uint16_t payloadLen) { + const auto now = std::chrono::steady_clock::now(); + recentPacketHistory_.push_back(RecentPacketTrace{now, outbound, opcode, payloadLen}); + while (!recentPacketHistory_.empty() && + (recentPacketHistory_.size() > kRecentPacketHistoryLimit || + (now - recentPacketHistory_.front().when) > kRecentPacketHistoryWindow)) { + recentPacketHistory_.pop_front(); + } +} + +void WorldSocket::dumpRecentPacketHistoryLocked(const char* reason, size_t bufferedBytes) { + static const bool closeTraceEnabled = envFlagEnabled(kCloseTraceEnv, false); + if (!closeTraceEnabled) return; + + if (recentPacketHistory_.empty()) { + LOG_DEBUG("WS CLOSE TRACE reason='", reason, "' buffered=", bufferedBytes, + " no recent packet history"); + return; + } + + const auto lastWhen = recentPacketHistory_.back().when; + LOG_DEBUG("WS CLOSE TRACE reason='", reason, "' buffered=", bufferedBytes, + " recentPackets=", recentPacketHistory_.size()); + for (const auto& entry : recentPacketHistory_) { + const auto ageMs = std::chrono::duration_cast( + lastWhen - entry.when).count(); + LOG_DEBUG("WS CLOSE TRACE ", entry.outbound ? "TX" : "RX", + " -", ageMs, "ms opcode=0x", + std::hex, entry.opcode, std::dec, + " logical=", opcodeNameForTrace(entry.opcode), + " payload=", entry.payloadLen); + } +} + void WorldSocket::send(const Packet& packet) { static const bool kLogCharCreatePayload = envFlagEnabled("WOWEE_NET_LOG_CHAR_CREATE", false); static const bool kLogSwapItemPackets = envFlagEnabled("WOWEE_NET_LOG_SWAP_ITEM", false); @@ -336,14 +373,15 @@ void WorldSocket::send(const Packet& packet) { } const auto traceNow = std::chrono::steady_clock::now(); + recordRecentPacket(true, opcode, payloadLen); if (packetTraceUntil_ > traceNow) { const auto elapsedMs = std::chrono::duration_cast( traceNow - packetTraceStart_).count(); - LOG_WARNING("WS TRACE TX +", elapsedMs, "ms opcode=0x", - std::hex, opcode, std::dec, - " logical=", opcodeNameForTrace(opcode), - " payload=", payloadLen, - " reason='", packetTraceReason_, "'"); + LOG_DEBUG("WS TRACE TX +", elapsedMs, "ms opcode=0x", + std::hex, opcode, std::dec, + " logical=", opcodeNameForTrace(opcode), + " payload=", payloadLen, + " reason='", packetTraceReason_, "'"); } // WotLK 3.3.5 CMSG header (6 bytes total): @@ -572,6 +610,7 @@ void WorldSocket::pumpNetworkIO() { } if (sawClose) { + dumpRecentPacketHistoryLocked("peer_closed", bufferedBytes()); LOG_INFO("World server connection closed (receivedAny=", receivedAny, " buffered=", bufferedBytes(), ")"); closeSocketNoJoin(); @@ -673,15 +712,16 @@ void WorldSocket::tryParsePackets() { " buffered=", (receiveBuffer.size() - parseOffset), " enc=", encryptionEnabled ? "yes" : "no"); } + recordRecentPacket(false, opcode, payloadLen); const auto traceNow = std::chrono::steady_clock::now(); if (packetTraceUntil_ > traceNow) { const auto elapsedMs = std::chrono::duration_cast( traceNow - packetTraceStart_).count(); - LOG_WARNING("WS TRACE RX +", elapsedMs, "ms opcode=0x", - std::hex, opcode, std::dec, - " logical=", opcodeNameForTrace(opcode), - " payload=", payloadLen, - " reason='", packetTraceReason_, "'"); + LOG_DEBUG("WS TRACE RX +", elapsedMs, "ms opcode=0x", + std::hex, opcode, std::dec, + " logical=", opcodeNameForTrace(opcode), + " payload=", payloadLen, + " reason='", packetTraceReason_, "'"); } if ((receiveBuffer.size() - parseOffset) < totalSize) {