fix: stabilize classic/turtle world session handling
Some checks failed
Build / Build (arm64) (push) Has been cancelled
Build / Build (x86-64) (push) Has been cancelled
Build / Build (macOS arm64) (push) Has been cancelled
Build / Build (windows-arm64) (push) Has been cancelled
Build / Build (windows-x86-64) (push) Has been cancelled
Security / CodeQL (C/C++) (push) Has been cancelled
Security / Semgrep (push) Has been cancelled
Security / Sanitizer Build (ASan/UBSan) (push) Has been cancelled

This commit is contained in:
Kelsi 2026-03-15 06:13:36 -07:00
parent 43ebae217c
commit f0a515ff9c
6 changed files with 522 additions and 179 deletions

View file

@ -2488,6 +2488,15 @@ private:
float pingInterval = 30.0f; // Ping interval (30 seconds) float pingInterval = 30.0f; // Ping interval (30 seconds)
float timeSinceLastMoveHeartbeat_ = 0.0f; // Periodic movement heartbeat to keep server position synced float timeSinceLastMoveHeartbeat_ = 0.0f; // Periodic movement heartbeat to keep server position synced
float moveHeartbeatInterval_ = 0.5f; 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) uint32_t lastLatency = 0; // Last measured latency (milliseconds)
std::chrono::steady_clock::time_point pingTimestamp_; // Time CMSG_PING was sent std::chrono::steady_clock::time_point pingTimestamp_; // Time CMSG_PING was sent
@ -2588,6 +2597,7 @@ private:
// ---- Phase 2: Combat ---- // ---- Phase 2: Combat ----
bool autoAttacking = false; bool autoAttacking = false;
bool autoAttackRequested_ = false; // local intent (CMSG_ATTACKSWING sent) bool autoAttackRequested_ = false; // local intent (CMSG_ATTACKSWING sent)
bool autoAttackRetryPending_ = false; // one-shot retry after local start or server stop
uint64_t autoAttackTarget = 0; uint64_t autoAttackTarget = 0;
bool autoAttackOutOfRange_ = false; bool autoAttackOutOfRange_ = false;
float autoAttackOutOfRangeTime_ = 0.0f; float autoAttackOutOfRangeTime_ = 0.0f;

View file

@ -14,6 +14,7 @@
#include <mutex> #include <mutex>
#include <atomic> #include <atomic>
#include <string> #include <string>
#include <array>
namespace wowee { namespace wowee {
namespace network { namespace network {
@ -90,6 +91,8 @@ private:
void startAsyncPump(); void startAsyncPump();
void stopAsyncPump(); void stopAsyncPump();
void closeSocketNoJoin(); 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; socket_t sockfd = INVALID_SOCK;
bool connected = false; bool connected = false;
@ -131,6 +134,14 @@ private:
std::chrono::steady_clock::time_point packetTraceUntil_{}; std::chrono::steady_clock::time_point packetTraceUntil_{};
std::string packetTraceReason_; 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<RecentPacketTrace> recentPacketHistory_;
// Packet callback // Packet callback
std::function<void(const Packet&)> packetCallback; std::function<void(const Packet&)> packetCallback;
}; };

View file

@ -1045,9 +1045,27 @@ void GameHandler::update(float deltaTime) {
const bool classicLikeCombatSync = const bool classicLikeCombatSync =
autoAttackRequested_ && (isClassicLikeExpansion() || isActiveExpansion("tbc")); autoAttackRequested_ && (isClassicLikeExpansion() || isActiveExpansion("tbc"));
const uint32_t locomotionFlags =
static_cast<uint32_t>(MovementFlags::FORWARD) |
static_cast<uint32_t>(MovementFlags::BACKWARD) |
static_cast<uint32_t>(MovementFlags::STRAFE_LEFT) |
static_cast<uint32_t>(MovementFlags::STRAFE_RIGHT) |
static_cast<uint32_t>(MovementFlags::TURN_LEFT) |
static_cast<uint32_t>(MovementFlags::TURN_RIGHT) |
static_cast<uint32_t>(MovementFlags::ASCENDING) |
static_cast<uint32_t>(MovementFlags::FALLING) |
static_cast<uint32_t>(MovementFlags::FALLINGFAR);
const bool classicLikeStationaryCombatSync =
classicLikeCombatSync &&
!onTaxiFlight_ &&
!taxiActivatePending_ &&
!taxiClientActive_ &&
(movementInfo.flags & locomotionFlags) == 0;
float heartbeatInterval = (onTaxiFlight_ || taxiActivatePending_ || taxiClientActive_) float heartbeatInterval = (onTaxiFlight_ || taxiActivatePending_ || taxiClientActive_)
? 0.25f ? 0.25f
: (classicLikeCombatSync ? 0.05f : moveHeartbeatInterval_); : (classicLikeStationaryCombatSync ? 0.75f
: (classicLikeCombatSync ? 0.20f
: moveHeartbeatInterval_));
if (timeSinceLastMoveHeartbeat_ >= heartbeatInterval) { if (timeSinceLastMoveHeartbeat_ >= heartbeatInterval) {
sendMovement(Opcode::MSG_MOVE_HEARTBEAT); sendMovement(Opcode::MSG_MOVE_HEARTBEAT);
timeSinceLastMoveHeartbeat_ = 0.0f; timeSinceLastMoveHeartbeat_ = 0.0f;
@ -1310,26 +1328,28 @@ void GameHandler::update(float deltaTime) {
autoAttackResendTimer_ += deltaTime; autoAttackResendTimer_ += deltaTime;
autoAttackFacingSyncTimer_ += deltaTime; autoAttackFacingSyncTimer_ += deltaTime;
// Re-request swing more aggressively until server confirms active loop. // Classic/Turtle servers do not tolerate steady attack-start
float resendInterval = 1.0f; // reissues well. Only retry once after local start or an
if (!autoAttacking || autoAttackOutOfRange_) { // explicit server-side attack stop while intent is still set.
resendInterval = classicLike ? 0.25f : 0.50f; const float resendInterval = classicLike ? 1.0f : 0.50f;
} if (!autoAttacking && !autoAttackOutOfRange_ && autoAttackRetryPending_ &&
if (autoAttackResendTimer_ >= resendInterval) { autoAttackResendTimer_ >= resendInterval) {
autoAttackResendTimer_ = 0.0f; autoAttackResendTimer_ = 0.0f;
autoAttackRetryPending_ = false;
auto pkt = AttackSwingPacket::build(autoAttackTarget); auto pkt = AttackSwingPacket::build(autoAttackTarget);
socket->send(pkt); socket->send(pkt);
} }
// Keep server-facing aligned with our current melee target. // Keep server-facing aligned while trying to acquire melee.
// Some vanilla-family realms become strict about front-arc checks unless // Once the server confirms auto-attack, rely on explicit
// the client sends explicit facing updates while stationary. // bad-facing feedback instead of periodic steady-state facing spam.
const float facingSyncInterval = classicLike ? 0.10f : 0.20f; const float facingSyncInterval = classicLike ? 0.25f : 0.20f;
if (autoAttackFacingSyncTimer_ >= facingSyncInterval) { const bool allowPeriodicFacingSync = !classicLike || !autoAttacking;
if (allowPeriodicFacingSync &&
autoAttackFacingSyncTimer_ >= facingSyncInterval) {
autoAttackFacingSyncTimer_ = 0.0f; autoAttackFacingSyncTimer_ = 0.0f;
float toTargetX = targetX - movementInfo.x; float toTargetX = targetX - movementInfo.x;
float toTargetY = targetY - movementInfo.y; float toTargetY = targetY - movementInfo.y;
bool sentMovement = false;
if (std::abs(toTargetX) > 0.01f || std::abs(toTargetY) > 0.01f) { if (std::abs(toTargetX) > 0.01f || std::abs(toTargetY) > 0.01f) {
float desired = std::atan2(-toTargetY, toTargetX); float desired = std::atan2(-toTargetY, toTargetX);
float diff = desired - movementInfo.orientation; float diff = desired - movementInfo.orientation;
@ -1339,20 +1359,7 @@ void GameHandler::update(float deltaTime) {
if (std::abs(diff) > facingThreshold) { if (std::abs(diff) > facingThreshold) {
movementInfo.orientation = desired; movementInfo.orientation = desired;
sendMovement(Opcode::MSG_MOVE_SET_FACING); 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."); addSystemChatMessage("Target is too far away.");
autoAttackRangeWarnCooldown_ = 1.25f; 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; break;
case Opcode::SMSG_ATTACKSWING_BADFACING: case Opcode::SMSG_ATTACKSWING_BADFACING:
if (autoAttackRequested_ && autoAttackTarget != 0) { 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) { if (std::abs(toTargetX) > 0.01f || std::abs(toTargetY) > 0.01f) {
movementInfo.orientation = std::atan2(-toTargetY, toTargetX); movementInfo.orientation = std::atan2(-toTargetY, toTargetX);
sendMovement(Opcode::MSG_MOVE_SET_FACING); sendMovement(Opcode::MSG_MOVE_SET_FACING);
sendMovement(Opcode::MSG_MOVE_HEARTBEAT);
} }
} }
if (socket) {
auto pkt = AttackSwingPacket::build(autoAttackTarget);
socket->send(pkt);
}
} }
break; break;
case Opcode::SMSG_ATTACKSWING_NOTSTANDING: case Opcode::SMSG_ATTACKSWING_NOTSTANDING:
@ -5361,6 +5348,7 @@ void GameHandler::handlePacket(network::Packet& packet) {
} }
// ---- Teleport / Transfer ---- // ---- Teleport / Transfer ----
case Opcode::MSG_MOVE_TELEPORT:
case Opcode::MSG_MOVE_TELEPORT_ACK: case Opcode::MSG_MOVE_TELEPORT_ACK:
handleTeleportAck(packet); handleTeleportAck(packet);
break; break;
@ -8968,7 +8956,7 @@ void GameHandler::handleLoginVerifyWorld(network::Packet& packet) {
// can close the session before our default 30s ping cadence fires. // can close the session before our default 30s ping cadence fires.
timeSinceLastPing = 0.0f; timeSinceLastPing = 0.0f;
if (socket) { 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(); sendPing();
} }
@ -10000,7 +9988,7 @@ void GameHandler::sendPing() {
// Increment sequence number // Increment sequence number
pingSequence++; pingSequence++;
LOG_WARNING("Sending CMSG_PING: sequence=", pingSequence, LOG_DEBUG("Sending CMSG_PING: sequence=", pingSequence,
" latencyHintMs=", lastLatency); " latencyHintMs=", lastLatency);
// Record send time for RTT measurement // Record send time for RTT measurement
@ -10051,7 +10039,7 @@ void GameHandler::sendMinimapPing(float wowX, float wowY) {
} }
void GameHandler::handlePong(network::Packet& packet) { void GameHandler::handlePong(network::Packet& packet) {
LOG_WARNING("Handling SMSG_PONG"); LOG_DEBUG("Handling SMSG_PONG");
PongData data; PongData data;
if (!PongParser::parse(packet, data)) { if (!PongParser::parse(packet, data)) {
@ -10071,7 +10059,7 @@ void GameHandler::handlePong(network::Packet& packet) {
lastLatency = static_cast<uint32_t>( lastLatency = static_cast<uint32_t>(
std::chrono::duration_cast<std::chrono::milliseconds>(rtt).count()); std::chrono::duration_cast<std::chrono::milliseconds>(rtt).count());
LOG_WARNING("SMSG_PONG acknowledged: sequence=", data.sequence, LOG_DEBUG("SMSG_PONG acknowledged: sequence=", data.sequence,
" latencyMs=", lastLatency); " latencyMs=", lastLatency);
} }
@ -10116,7 +10104,21 @@ void GameHandler::sendMovement(Opcode opcode) {
if (resurrectPending_ && !taxiAllowed) return; if (resurrectPending_ && !taxiAllowed) return;
// Always send a strictly increasing non-zero client movement clock value. // 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<uint32_t>::max();
if (std::abs(facingDelta) < 0.02f && sinceLastFacingMs < 200U) {
return;
}
}
// Update movement flags based on opcode // Update movement flags based on opcode
switch (opcode) { switch (opcode) {
@ -10190,6 +10192,7 @@ void GameHandler::sendMovement(Opcode opcode) {
break; break;
case Opcode::MSG_MOVE_HEARTBEAT: case Opcode::MSG_MOVE_HEARTBEAT:
// No flag changes — just sends current position // No flag changes — just sends current position
timeSinceLastMoveHeartbeat_ = 0.0f;
break; break;
case Opcode::MSG_MOVE_START_ASCEND: case Opcode::MSG_MOVE_START_ASCEND:
movementInfo.flags |= static_cast<uint32_t>(MovementFlags::ASCENDING); movementInfo.flags |= static_cast<uint32_t>(MovementFlags::ASCENDING);
@ -10206,6 +10209,11 @@ void GameHandler::sendMovement(Opcode opcode) {
break; 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 // Keep fallTime current: it must equal the elapsed milliseconds since FALLING
// was set, so the server can compute fall damage correctly. // was set, so the server can compute fall damage correctly.
if (isFalling_ && movementInfo.hasFlag(MovementFlags::FALLING)) { if (isFalling_ && movementInfo.hasFlag(MovementFlags::FALLING)) {
@ -10278,6 +10286,49 @@ void GameHandler::sendMovement(Opcode opcode) {
movementInfo.transportSeat = -1; movementInfo.transportSeat = -1;
} }
if (opcode == Opcode::MSG_MOVE_HEARTBEAT && isClassicLikeExpansion()) {
const uint32_t locomotionFlags =
static_cast<uint32_t>(MovementFlags::FORWARD) |
static_cast<uint32_t>(MovementFlags::BACKWARD) |
static_cast<uint32_t>(MovementFlags::STRAFE_LEFT) |
static_cast<uint32_t>(MovementFlags::STRAFE_RIGHT) |
static_cast<uint32_t>(MovementFlags::TURN_LEFT) |
static_cast<uint32_t>(MovementFlags::TURN_RIGHT) |
static_cast<uint32_t>(MovementFlags::ASCENDING) |
static_cast<uint32_t>(MovementFlags::FALLING) |
static_cast<uint32_t>(MovementFlags::FALLINGFAR) |
static_cast<uint32_t>(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<uint32_t>::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<uint32_t>::max();
if (sinceLastNonHeartbeatMoveMs < 350U) {
timeSinceLastMoveHeartbeat_ = 0.0f;
return;
}
}
LOG_DEBUG("Sending movement packet: opcode=0x", std::hex, LOG_DEBUG("Sending movement packet: opcode=0x", std::hex,
wireOpcode(opcode), std::dec, wireOpcode(opcode), std::dec,
(includeTransportInWire ? " ONTRANSPORT" : "")); (includeTransportInWire ? " ONTRANSPORT" : ""));
@ -10308,6 +10359,17 @@ void GameHandler::sendMovement(Opcode opcode) {
? packetParsers_->buildMovementPacket(opcode, wireInfo, playerGuid) ? packetParsers_->buildMovementPacket(opcode, wireInfo, playerGuid)
: MovementPacket::build(opcode, wireInfo, playerGuid); : MovementPacket::build(opcode, wireInfo, playerGuid);
socket->send(packet); 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() { void GameHandler::sanitizeMovementForTaxi() {
@ -14692,6 +14754,7 @@ void GameHandler::startAutoAttack(uint64_t targetGuid) {
} }
autoAttackRequested_ = true; autoAttackRequested_ = true;
autoAttackRetryPending_ = true;
// Keep combat animation/state server-authoritative. We only flip autoAttacking // Keep combat animation/state server-authoritative. We only flip autoAttacking
// on SMSG_ATTACKSTART where attackerGuid == playerGuid. // on SMSG_ATTACKSTART where attackerGuid == playerGuid.
autoAttacking = false; autoAttacking = false;
@ -14711,6 +14774,7 @@ void GameHandler::stopAutoAttack() {
if (!autoAttacking && !autoAttackRequested_) return; if (!autoAttacking && !autoAttackRequested_) return;
autoAttackRequested_ = false; autoAttackRequested_ = false;
autoAttacking = false; autoAttacking = false;
autoAttackRetryPending_ = false;
autoAttackTarget = 0; autoAttackTarget = 0;
autoAttackOutOfRange_ = false; autoAttackOutOfRange_ = false;
autoAttackOutOfRangeTime_ = 0.0f; autoAttackOutOfRangeTime_ = 0.0f;
@ -14805,6 +14869,7 @@ void GameHandler::handleAttackStart(network::Packet& packet) {
if (data.attackerGuid == playerGuid) { if (data.attackerGuid == playerGuid) {
autoAttackRequested_ = true; autoAttackRequested_ = true;
autoAttacking = true; autoAttacking = true;
autoAttackRetryPending_ = false;
autoAttackTarget = data.victimGuid; autoAttackTarget = data.victimGuid;
} else if (data.victimGuid == playerGuid && data.attackerGuid != 0) { } else if (data.victimGuid == playerGuid && data.attackerGuid != 0) {
hostileAttackers_.insert(data.attackerGuid); 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. // Keep intent, but clear server-confirmed active state until ATTACKSTART resumes.
if (data.attackerGuid == playerGuid) { if (data.attackerGuid == playerGuid) {
autoAttacking = false; autoAttacking = false;
autoAttackRetryPending_ = autoAttackRequested_;
autoAttackResendTimer_ = 0.0f;
LOG_DEBUG("SMSG_ATTACKSTOP received (keeping auto-attack intent)"); 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) { } else if (data.victimGuid == playerGuid) {
hostileAttackers_.erase(data.attackerGuid); hostileAttackers_.erase(data.attackerGuid);
} }

View file

@ -1,5 +1,8 @@
#include "game/packet_parsers.hpp" #include "game/packet_parsers.hpp"
#include "core/logger.hpp" #include "core/logger.hpp"
#include <cstdio>
#include <functional>
#include <string>
namespace wowee { namespace wowee {
namespace game { namespace game {
@ -22,6 +25,99 @@ bool hasFullPackedGuid(const network::Packet& packet) {
return packet.getSize() - packet.getReadPos() >= guidBytes; 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) { const char* updateTypeName(UpdateType type) {
switch (type) { switch (type) {
case UpdateType::VALUES: return "VALUES"; case UpdateType::VALUES: return "VALUES";
@ -53,6 +149,36 @@ namespace ClassicMoveFlags {
constexpr uint32_t SPLINE_ELEVATION = 0x04000000; // Same as TBC 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<uint32_t>(MovementFlags::ONTRANSPORT);
const uint32_t kInternalFalling =
static_cast<uint32_t>(MovementFlags::FALLING) |
static_cast<uint32_t>(MovementFlags::FALLINGFAR);
const uint32_t kClassicConflicts =
static_cast<uint32_t>(MovementFlags::ASCENDING) |
static_cast<uint32_t>(MovementFlags::CAN_FLY) |
static_cast<uint32_t>(MovementFlags::FLYING) |
static_cast<uint32_t>(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 // Classic parseMovementBlock
// Key differences from TBC: // Key differences from TBC:
@ -226,8 +352,10 @@ bool ClassicPacketParsers::parseMovementBlock(network::Packet& packet, UpdateBlo
// - Pitch: only SWIMMING (no ONTRANSPORT pitch) // - Pitch: only SWIMMING (no ONTRANSPORT pitch)
// ============================================================================ // ============================================================================
void ClassicPacketParsers::writeMovementPayload(network::Packet& packet, const MovementInfo& info) { void ClassicPacketParsers::writeMovementPayload(network::Packet& packet, const MovementInfo& info) {
const uint32_t wireFlags = classicWireMoveFlags(info.flags);
// Movement flags (uint32) // Movement flags (uint32)
packet.writeUInt32(info.flags); packet.writeUInt32(wireFlags);
// Classic: NO flags2 byte (TBC has u8, WotLK has u16) // 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<const uint8_t*>(&info.orientation), sizeof(float)); packet.writeBytes(reinterpret_cast<const uint8_t*>(&info.orientation), sizeof(float));
// Transport data (Classic ONTRANSPORT = 0x02000000, no timestamp) // Transport data (Classic ONTRANSPORT = 0x02000000, no timestamp)
if (info.flags & ClassicMoveFlags::ONTRANSPORT) { if (wireFlags & ClassicMoveFlags::ONTRANSPORT) {
// Packed transport GUID // Packed transport GUID
uint8_t transMask = 0; uint8_t transMask = 0;
uint8_t transGuidBytes[8]; uint8_t transGuidBytes[8];
@ -269,7 +397,7 @@ void ClassicPacketParsers::writeMovementPayload(network::Packet& packet, const M
} }
// Pitch (Classic: only SWIMMING) // Pitch (Classic: only SWIMMING)
if (info.flags & ClassicMoveFlags::SWIMMING) { if (wireFlags & ClassicMoveFlags::SWIMMING) {
packet.writeBytes(reinterpret_cast<const uint8_t*>(&info.pitch), sizeof(float)); packet.writeBytes(reinterpret_cast<const uint8_t*>(&info.pitch), sizeof(float));
} }
@ -277,7 +405,7 @@ void ClassicPacketParsers::writeMovementPayload(network::Packet& packet, const M
packet.writeUInt32(info.fallTime); packet.writeUInt32(info.fallTime);
// Jump data (Classic JUMPING = 0x2000) // Jump data (Classic JUMPING = 0x2000)
if (info.flags & ClassicMoveFlags::JUMPING) { if (wireFlags & ClassicMoveFlags::JUMPING) {
packet.writeBytes(reinterpret_cast<const uint8_t*>(&info.jumpVelocity), sizeof(float)); packet.writeBytes(reinterpret_cast<const uint8_t*>(&info.jumpVelocity), sizeof(float));
packet.writeBytes(reinterpret_cast<const uint8_t*>(&info.jumpSinAngle), sizeof(float)); packet.writeBytes(reinterpret_cast<const uint8_t*>(&info.jumpSinAngle), sizeof(float));
packet.writeBytes(reinterpret_cast<const uint8_t*>(&info.jumpCosAngle), sizeof(float)); packet.writeBytes(reinterpret_cast<const uint8_t*>(&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). // - castFlags is uint16 (NOT uint32 as in TBC/WotLK).
// - SpellCastTargets uses uint16 targetFlags (NOT uint32 as in TBC). // - 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) // + uint32(spellId) + uint16(castFlags) + uint32(castTime)
// + uint16(targetFlags) [+ PackedGuid(unitTarget) if TARGET_FLAG_UNIT] // + uint16(targetFlags) [+ PackedGuid(unitTarget) if TARGET_FLAG_UNIT]
// ============================================================================ // ============================================================================
@ -384,9 +512,10 @@ bool ClassicPacketParsers::parseSpellStart(network::Packet& packet, SpellStartDa
} }
data.casterUnit = UpdateObjectParser::readPackedGuid(packet); data.casterUnit = UpdateObjectParser::readPackedGuid(packet);
// uint8 castCount + uint32 spellId + uint16 castFlags + uint32 castTime = 11 bytes // Vanilla/Turtle SMSG_SPELL_START does not include castCount here.
if (rem() < 11) return false; // Layout after the two packed GUIDs is spellId(u32) + castFlags(u16) + castTime(u32).
data.castCount = packet.readUInt8(); if (rem() < 10) return false;
data.castCount = 0;
data.spellId = packet.readUInt32(); data.spellId = packet.readUInt32();
data.castFlags = packet.readUInt16(); // uint16 in Vanilla (uint32 in TBC/WotLK) data.castFlags = packet.readUInt16(); // uint16 in Vanilla (uint32 in TBC/WotLK)
data.castTime = packet.readUInt32(); data.castTime = packet.readUInt32();
@ -419,7 +548,7 @@ bool ClassicPacketParsers::parseSpellStart(network::Packet& packet, SpellStartDa
// - castFlags is uint16 (not uint32) // - castFlags is uint16 (not uint32)
// - Hit/miss target GUIDs are also PackedGuid in Vanilla // - 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) // + uint32(spellId) + uint16(castFlags)
// + uint8(hitCount) + [PackedGuid(hitTarget) × hitCount] // + uint8(hitCount) + [PackedGuid(hitTarget) × hitCount]
// + uint8(missCount) + [PackedGuid(missTarget) + uint8(missType)] × missCount // + 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(); }; auto rem = [&]() { return packet.getSize() - packet.getReadPos(); };
const size_t startPos = 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 (rem() < 2) return false;
if (!hasFullPackedGuid(packet)) return false; if (!hasFullPackedGuid(packet)) return false;
@ -437,15 +584,25 @@ bool ClassicPacketParsers::parseSpellGo(network::Packet& packet, SpellGoData& da
if (!hasFullPackedGuid(packet)) return false; if (!hasFullPackedGuid(packet)) return false;
data.casterUnit = UpdateObjectParser::readPackedGuid(packet); data.casterUnit = UpdateObjectParser::readPackedGuid(packet);
// uint8 castCount + uint32 spellId + uint16 castFlags = 7 bytes // Vanilla/Turtle SMSG_SPELL_GO does not include castCount here.
if (rem() < 7) return false; // Layout after the two packed GUIDs is spellId(u32) + castFlags(u16).
data.castCount = packet.readUInt8(); if (rem() < 6) return false;
data.castCount = 0;
data.spellId = packet.readUInt32(); data.spellId = packet.readUInt32();
data.castFlags = packet.readUInt16(); // uint16 in Vanilla (uint32 in TBC/WotLK) data.castFlags = packet.readUInt16(); // uint16 in Vanilla (uint32 in TBC/WotLK)
const size_t countsPos = packet.getReadPos();
uint64_t ignoredTargetGuid = 0;
std::function<bool(bool)> parseHitAndMissLists = [&](bool allowTargetsFallback) -> bool {
packet.setReadPos(countsPos);
data.hitTargets.clear();
data.missTargets.clear();
ignoredTargetGuid = 0;
// hitCount is mandatory in SMSG_SPELL_GO. Missing byte means truncation. // hitCount is mandatory in SMSG_SPELL_GO. Missing byte means truncation.
if (rem() < 1) { if (rem() < 1) {
LOG_WARNING("[Classic] Spell go: missing hitCount after fixed fields"); LOG_WARNING("[Classic] Spell go: missing hitCount after fixed fields");
traceFailure("missing_hit_count", packet.getReadPos());
packet.setReadPos(startPos); packet.setReadPos(startPos);
return false; return false;
} }
@ -453,97 +610,160 @@ bool ClassicPacketParsers::parseSpellGo(network::Packet& packet, SpellGoData& da
if (rawHitCount > 128) { if (rawHitCount > 128) {
LOG_WARNING("[Classic] Spell go: hitCount capped (requested=", (int)rawHitCount, ")"); LOG_WARNING("[Classic] Spell go: hitCount capped (requested=", (int)rawHitCount, ")");
} }
// Packed GUIDs are variable length, but each target needs at least 1 byte (mask). if (rem() < static_cast<size_t>(rawHitCount) + 1u) {
// Require the minimum bytes before entering per-target parsing loops.
if (rem() < static_cast<size_t>(rawHitCount) + 1u) { // +1 for mandatory missCount byte
static uint32_t badHitCountTrunc = 0; static uint32_t badHitCountTrunc = 0;
++badHitCountTrunc; ++badHitCountTrunc;
if (badHitCountTrunc <= 10 || (badHitCountTrunc % 100) == 0) { if (badHitCountTrunc <= 10 || (badHitCountTrunc % 100) == 0) {
LOG_WARNING("[Classic] Spell go: invalid hitCount/remaining (hits=", (int)rawHitCount, LOG_WARNING("[Classic] Spell go: invalid hitCount/remaining (hits=", (int)rawHitCount,
" remaining=", rem(), " occurrence=", badHitCountTrunc, ")"); " remaining=", rem(), " occurrence=", badHitCountTrunc, ")");
} }
traceFailure("invalid_hit_count", packet.getReadPos(), rawHitCount);
packet.setReadPos(startPos); packet.setReadPos(startPos);
return false; return false;
} }
const auto parseHitList = [&](bool usePackedGuids) -> bool {
packet.setReadPos(countsPos + 1); // after hitCount
data.hitTargets.clear();
const uint8_t storedHitLimit = std::min<uint8_t>(rawHitCount, 128); const uint8_t storedHitLimit = std::min<uint8_t>(rawHitCount, 128);
data.hitTargets.reserve(storedHitLimit); data.hitTargets.reserve(storedHitLimit);
bool truncatedTargets = false;
for (uint16_t i = 0; i < rawHitCount; ++i) { for (uint16_t i = 0; i < rawHitCount; ++i) {
uint64_t targetGuid = 0;
if (usePackedGuids) {
if (!hasFullPackedGuid(packet)) { if (!hasFullPackedGuid(packet)) {
LOG_WARNING("[Classic] Spell go: truncated hit targets at index ", i, return false;
"/", (int)rawHitCount); }
truncatedTargets = true; targetGuid = UpdateObjectParser::readPackedGuid(packet);
break; } else {
if (rem() < 8) {
return false;
}
targetGuid = packet.readUInt64();
} }
const uint64_t targetGuid = UpdateObjectParser::readPackedGuid(packet);
if (i < storedHitLimit) { if (i < storedHitLimit) {
data.hitTargets.push_back(targetGuid); data.hitTargets.push_back(targetGuid);
} }
} }
if (truncatedTargets) { data.hitCount = static_cast<uint8_t>(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); packet.setReadPos(startPos);
return false; return false;
} }
data.hitCount = static_cast<uint8_t>(data.hitTargets.size());
// missCount is mandatory in SMSG_SPELL_GO. Missing byte means truncation. std::function<bool(size_t, bool)> parseMissListFrom = [&](size_t missStartPos,
bool allowMidTargetsFallback) -> bool {
packet.setReadPos(missStartPos);
data.missTargets.clear();
if (rem() < 1) { if (rem() < 1) {
LOG_WARNING("[Classic] Spell go: missing missCount after hit target list"); LOG_WARNING("[Classic] Spell go: missing missCount after hit target list");
traceFailure("missing_miss_count", packet.getReadPos());
packet.setReadPos(startPos); packet.setReadPos(startPos);
return false; return false;
} }
const uint8_t rawMissCount = packet.readUInt8(); const uint8_t rawMissCount = packet.readUInt8();
if (rawMissCount > 128) { if (rawMissCount > 128) {
LOG_WARNING("[Classic] Spell go: missCount capped (requested=", (int)rawMissCount, ")"); LOG_WARNING("[Classic] Spell go: missCount capped (requested=", (int)rawMissCount, ")");
traceFailure("miss_count_capped", packet.getReadPos() - 1, rawMissCount);
} }
// Each miss entry needs at least packed-guid mask (1) + missType (1).
if (rem() < static_cast<size_t>(rawMissCount) * 2u) { if (rem() < static_cast<size_t>(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; static uint32_t badMissCountTrunc = 0;
++badMissCountTrunc; ++badMissCountTrunc;
if (badMissCountTrunc <= 10 || (badMissCountTrunc % 100) == 0) { if (badMissCountTrunc <= 10 || (badMissCountTrunc % 100) == 0) {
LOG_WARNING("[Classic] Spell go: invalid missCount/remaining (misses=", (int)rawMissCount, LOG_WARNING("[Classic] Spell go: invalid missCount/remaining (misses=", (int)rawMissCount,
" remaining=", rem(), " occurrence=", badMissCountTrunc, ")"); " remaining=", rem(), " occurrence=", badMissCountTrunc, ")");
} }
traceFailure("invalid_miss_count", packet.getReadPos(), rawMissCount);
packet.setReadPos(startPos); packet.setReadPos(startPos);
return false; return false;
} }
const uint8_t storedMissLimit = std::min<uint8_t>(rawMissCount, 128); const uint8_t storedMissLimit = std::min<uint8_t>(rawMissCount, 128);
data.missTargets.reserve(storedMissLimit); data.missTargets.reserve(storedMissLimit);
for (uint16_t i = 0; i < rawMissCount; ++i) { bool truncatedMissTargets = false;
const auto parseMissEntry = [&](SpellGoMissEntry& m, bool usePackedGuid) -> bool {
if (usePackedGuid) {
if (!hasFullPackedGuid(packet)) { 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, LOG_WARNING("[Classic] Spell go: truncated miss targets at index ", i,
"/", (int)rawMissCount); "/", (int)rawMissCount);
truncatedTargets = true; traceFailure("truncated_miss_target", packet.getReadPos(), i);
truncatedMissTargets = true;
break; break;
} }
SpellGoMissEntry m; }
m.targetGuid = UpdateObjectParser::readPackedGuid(packet);
if (rem() < 1) { if (rem() < 1) {
LOG_WARNING("[Classic] Spell go: missing missType at miss index ", i, LOG_WARNING("[Classic] Spell go: missing missType at miss index ", i,
"/", (int)rawMissCount); "/", (int)rawMissCount);
truncatedTargets = true; traceFailure("missing_miss_type", packet.getReadPos(), i);
truncatedMissTargets = true;
break; break;
} }
m.missType = packet.readUInt8(); m.missType = packet.readUInt8();
if (m.missType == 11) { if (m.missType == 11) {
if (rem() < 5) { if (rem() < 1) {
LOG_WARNING("[Classic] Spell go: truncated reflect payload at miss index ", i, LOG_WARNING("[Classic] Spell go: truncated reflect payload at miss index ", i,
"/", (int)rawMissCount); "/", (int)rawMissCount);
truncatedTargets = true; traceFailure("truncated_reflect", packet.getReadPos(), i);
truncatedMissTargets = true;
break; break;
} }
(void)packet.readUInt32();
(void)packet.readUInt8(); (void)packet.readUInt8();
} }
if (i < storedMissLimit) { if (i < storedMissLimit) {
data.missTargets.push_back(m); data.missTargets.push_back(m);
} }
} }
if (truncatedTargets) { if (truncatedMissTargets) {
packet.setReadPos(startPos); packet.setReadPos(startPos);
return false; return false;
} }
data.missCount = static_cast<uint8_t>(data.missTargets.size()); data.missCount = static_cast<uint8_t>(data.missTargets.size());
return true;
};
return parseMissListFrom(packet.getReadPos(), true);
};
if (!parseHitAndMissLists(true)) {
return false;
}
LOG_DEBUG("[Classic] Spell go: spell=", data.spellId, " hits=", (int)data.hitCount, LOG_DEBUG("[Classic] Spell go: spell=", data.spellId, " hits=", (int)data.hitCount,
" misses=", (int)data.missCount); " misses=", (int)data.missCount);

View file

@ -1883,15 +1883,16 @@ network::Packet RequestPlayedTimePacket::build(bool sendToChat) {
} }
bool PlayedTimeParser::parse(network::Packet& packet, PlayedTimeData& data) { bool PlayedTimeParser::parse(network::Packet& packet, PlayedTimeData& data) {
// Validate minimum packet size: totalTime(4) + levelTime(4) + triggerMsg(1) // Classic/Turtle may omit the trailing trigger-message byte and send only
if (packet.getSize() - packet.getReadPos() < 9) { // 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)"); LOG_WARNING("SMSG_PLAYED_TIME: packet too small (", packet.getSize(), " bytes)");
return false; return false;
} }
data.totalTimePlayed = packet.readUInt32(); data.totalTimePlayed = packet.readUInt32();
data.levelTimePlayed = 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); LOG_DEBUG("Parsed SMSG_PLAYED_TIME: total=", data.totalTimePlayed, " level=", data.levelTimePlayed);
return true; return true;
} }

View file

@ -25,6 +25,9 @@ constexpr int kMaxRecvCallsPerUpdate = 64;
constexpr size_t kMaxRecvBytesPerUpdate = 512 * 1024; constexpr size_t kMaxRecvBytesPerUpdate = 512 * 1024;
constexpr size_t kMaxQueuedPacketCallbacks = 4096; constexpr size_t kMaxQueuedPacketCallbacks = 4096;
constexpr int kAsyncPumpSleepMs = 2; 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() { inline int parsedPacketsBudgetPerUpdate() {
static int budget = []() { static int budget = []() {
@ -250,7 +253,7 @@ void WorldSocket::tracePacketsFor(std::chrono::milliseconds duration, const std:
packetTraceStart_ = std::chrono::steady_clock::now(); packetTraceStart_ = std::chrono::steady_clock::now();
packetTraceUntil_ = packetTraceStart_ + duration; packetTraceUntil_ = packetTraceStart_ + duration;
packetTraceReason_ = reason; packetTraceReason_ = reason;
LOG_WARNING("WS TRACE enabled: reason='", packetTraceReason_, LOG_DEBUG("WS TRACE enabled: reason='", packetTraceReason_,
"' durationMs=", duration.count()); "' durationMs=", duration.count());
} }
@ -267,6 +270,40 @@ void WorldSocket::closeSocketNoJoin() {
connected = false; 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<std::chrono::milliseconds>(
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) { void WorldSocket::send(const Packet& packet) {
static const bool kLogCharCreatePayload = envFlagEnabled("WOWEE_NET_LOG_CHAR_CREATE", false); static const bool kLogCharCreatePayload = envFlagEnabled("WOWEE_NET_LOG_CHAR_CREATE", false);
static const bool kLogSwapItemPackets = envFlagEnabled("WOWEE_NET_LOG_SWAP_ITEM", false); static const bool kLogSwapItemPackets = envFlagEnabled("WOWEE_NET_LOG_SWAP_ITEM", false);
@ -336,10 +373,11 @@ void WorldSocket::send(const Packet& packet) {
} }
const auto traceNow = std::chrono::steady_clock::now(); const auto traceNow = std::chrono::steady_clock::now();
recordRecentPacket(true, opcode, payloadLen);
if (packetTraceUntil_ > traceNow) { if (packetTraceUntil_ > traceNow) {
const auto elapsedMs = std::chrono::duration_cast<std::chrono::milliseconds>( const auto elapsedMs = std::chrono::duration_cast<std::chrono::milliseconds>(
traceNow - packetTraceStart_).count(); traceNow - packetTraceStart_).count();
LOG_WARNING("WS TRACE TX +", elapsedMs, "ms opcode=0x", LOG_DEBUG("WS TRACE TX +", elapsedMs, "ms opcode=0x",
std::hex, opcode, std::dec, std::hex, opcode, std::dec,
" logical=", opcodeNameForTrace(opcode), " logical=", opcodeNameForTrace(opcode),
" payload=", payloadLen, " payload=", payloadLen,
@ -572,6 +610,7 @@ void WorldSocket::pumpNetworkIO() {
} }
if (sawClose) { if (sawClose) {
dumpRecentPacketHistoryLocked("peer_closed", bufferedBytes());
LOG_INFO("World server connection closed (receivedAny=", receivedAny, LOG_INFO("World server connection closed (receivedAny=", receivedAny,
" buffered=", bufferedBytes(), ")"); " buffered=", bufferedBytes(), ")");
closeSocketNoJoin(); closeSocketNoJoin();
@ -673,11 +712,12 @@ void WorldSocket::tryParsePackets() {
" buffered=", (receiveBuffer.size() - parseOffset), " buffered=", (receiveBuffer.size() - parseOffset),
" enc=", encryptionEnabled ? "yes" : "no"); " enc=", encryptionEnabled ? "yes" : "no");
} }
recordRecentPacket(false, opcode, payloadLen);
const auto traceNow = std::chrono::steady_clock::now(); const auto traceNow = std::chrono::steady_clock::now();
if (packetTraceUntil_ > traceNow) { if (packetTraceUntil_ > traceNow) {
const auto elapsedMs = std::chrono::duration_cast<std::chrono::milliseconds>( const auto elapsedMs = std::chrono::duration_cast<std::chrono::milliseconds>(
traceNow - packetTraceStart_).count(); traceNow - packetTraceStart_).count();
LOG_WARNING("WS TRACE RX +", elapsedMs, "ms opcode=0x", LOG_DEBUG("WS TRACE RX +", elapsedMs, "ms opcode=0x",
std::hex, opcode, std::dec, std::hex, opcode, std::dec,
" logical=", opcodeNameForTrace(opcode), " logical=", opcodeNameForTrace(opcode),
" payload=", payloadLen, " payload=", payloadLen,