Harden runtime against stutter-inducing log floods and missing display IDs

- Re-gate M2 glow diagnostics behind WOWEE_M2_GLOW_DIAG and DEBUG

- Deduplicate missing/failed texture warnings in asset and M2 texture loaders

- Deduplicate unhandled opcode warnings by state/opcode key in non-IN_WORLD phases

- Throttle malformed spline point-count warnings across world/classic/tbc parsers

- Ignore suspiciously huge display IDs from malformed packets with throttled warning

- Add nearest-known displayId model fallback cache for missing creature display mappings

- Clear display fallback caches on expansion reload and logout
This commit is contained in:
Kelsi 2026-02-21 04:05:53 -08:00
parent 602f8265de
commit f78a28deda
8 changed files with 124 additions and 36 deletions

View file

@ -184,6 +184,8 @@ private:
std::unordered_map<uint32_t, uint32_t> displayIdModelCache_; // displayId → modelId (model caching) std::unordered_map<uint32_t, uint32_t> displayIdModelCache_; // displayId → modelId (model caching)
mutable std::unordered_set<uint32_t> warnedMissingDisplayDataIds_; // displayIds already warned mutable std::unordered_set<uint32_t> warnedMissingDisplayDataIds_; // displayIds already warned
mutable std::unordered_set<uint32_t> warnedMissingModelPathIds_; // modelIds/displayIds already warned mutable std::unordered_set<uint32_t> warnedMissingModelPathIds_; // modelIds/displayIds already warned
mutable std::unordered_map<uint32_t, std::string> missingDisplayFallbackPathCache_; // missing displayId -> fallback model path
mutable std::unordered_set<uint32_t> warnedMissingDisplayFallbackIds_; // displayIds logged for fallback usage
uint32_t nextCreatureModelId_ = 5000; // Model IDs for online creatures uint32_t nextCreatureModelId_ = 5000; // Model IDs for online creatures
uint32_t gryphonDisplayId_ = 0; uint32_t gryphonDisplayId_ = 0;
uint32_t wyvernDisplayId_ = 0; uint32_t wyvernDisplayId_ = 0;

View file

@ -496,6 +496,8 @@ void Application::reloadExpansionData() {
creatureModelIds_.clear(); creatureModelIds_.clear();
creatureRenderPosCache_.clear(); creatureRenderPosCache_.clear();
nonRenderableCreatureDisplayIds_.clear(); nonRenderableCreatureDisplayIds_.clear();
missingDisplayFallbackPathCache_.clear();
warnedMissingDisplayFallbackIds_.clear();
buildCreatureDisplayLookups(); buildCreatureDisplayLookups();
} }
@ -510,6 +512,8 @@ void Application::logoutToLogin() {
wasAutoAttacking_ = false; wasAutoAttacking_ = false;
loadedMapId_ = 0xFFFFFFFF; loadedMapId_ = 0xFFFFFFFF;
nonRenderableCreatureDisplayIds_.clear(); nonRenderableCreatureDisplayIds_.clear();
missingDisplayFallbackPathCache_.clear();
warnedMissingDisplayFallbackIds_.clear();
world.reset(); world.reset();
if (renderer) { if (renderer) {
// Remove old player model so it doesn't persist into next session // Remove old player model so it doesn't persist into next session
@ -3480,6 +3484,15 @@ std::string Application::getModelPathForDisplayId(uint32_t displayId) const {
auto itData = displayDataMap_.find(displayId); auto itData = displayDataMap_.find(displayId);
if (itData == displayDataMap_.end()) { if (itData == displayDataMap_.end()) {
if (displayId > 1000000u) {
static uint32_t suspiciousDisplayIdDrops = 0;
++suspiciousDisplayIdDrops;
if (suspiciousDisplayIdDrops <= 3 || (suspiciousDisplayIdDrops % 100) == 0) {
LOG_WARNING("Skipping suspicious displayId ", displayId,
" (likely malformed movement/update parse)");
}
return "";
}
// Some sources (e.g., taxi nodes) may provide a modelId directly. // Some sources (e.g., taxi nodes) may provide a modelId directly.
auto itPath = modelIdToPath_.find(displayId); auto itPath = modelIdToPath_.find(displayId);
if (itPath != modelIdToPath_.end()) { if (itPath != modelIdToPath_.end()) {
@ -3487,6 +3500,40 @@ std::string Application::getModelPathForDisplayId(uint32_t displayId) const {
} }
if (displayId == 30412) return "Creature\\Gryphon\\Gryphon.m2"; if (displayId == 30412) return "Creature\\Gryphon\\Gryphon.m2";
if (displayId == 30413) return "Creature\\Wyvern\\Wyvern.m2"; if (displayId == 30413) return "Creature\\Wyvern\\Wyvern.m2";
auto itCachedFallback = missingDisplayFallbackPathCache_.find(displayId);
if (itCachedFallback != missingDisplayFallbackPathCache_.end()) {
return itCachedFallback->second;
}
uint32_t bestDisplayId = 0;
uint32_t bestDelta = std::numeric_limits<uint32_t>::max();
std::string bestPath;
for (const auto& [candidateDisplayId, candidateData] : displayDataMap_) {
auto itCandidatePath = modelIdToPath_.find(candidateData.modelId);
if (itCandidatePath == modelIdToPath_.end() || itCandidatePath->second.empty()) {
continue;
}
uint32_t delta = (candidateDisplayId > displayId)
? (candidateDisplayId - displayId)
: (displayId - candidateDisplayId);
if (delta < bestDelta) {
bestDelta = delta;
bestDisplayId = candidateDisplayId;
bestPath = itCandidatePath->second;
if (delta == 0) break;
}
}
if (!bestPath.empty()) {
missingDisplayFallbackPathCache_[displayId] = bestPath;
if (warnedMissingDisplayFallbackIds_.insert(displayId).second) {
LOG_WARNING("No display data for displayId ", displayId,
" — using nearest fallback displayId ", bestDisplayId,
" (delta=", bestDelta, ") path=", bestPath);
}
return bestPath;
}
if (warnedMissingDisplayDataIds_.insert(displayId).second) { if (warnedMissingDisplayDataIds_.insert(displayId).second) {
LOG_WARNING("No display data for displayId ", displayId, LOG_WARNING("No display data for displayId ", displayId,
" (displayDataMap_ has ", displayDataMap_.size(), " entries)"); " (displayDataMap_ has ", displayDataMap_.size(), " entries)");

View file

@ -2823,19 +2823,24 @@ void GameHandler::handlePacket(network::Packet& packet) {
// In pre-world states we need full visibility (char create/login handshakes). // In pre-world states we need full visibility (char create/login handshakes).
// In-world we keep de-duplication to avoid heavy log I/O in busy areas. // In-world we keep de-duplication to avoid heavy log I/O in busy areas.
if (state != WorldState::IN_WORLD) { if (state != WorldState::IN_WORLD) {
LOG_WARNING("Unhandled world opcode: 0x", std::hex, opcode, std::dec, static std::unordered_set<uint32_t> loggedUnhandledByState;
" state=", static_cast<int>(state), const uint32_t key = (static_cast<uint32_t>(static_cast<uint8_t>(state)) << 16) |
" size=", packet.getSize()); static_cast<uint32_t>(opcode);
const auto& data = packet.getData(); if (loggedUnhandledByState.insert(key).second) {
std::string hex; LOG_WARNING("Unhandled world opcode: 0x", std::hex, opcode, std::dec,
size_t limit = std::min<size_t>(data.size(), 48); " state=", static_cast<int>(state),
hex.reserve(limit * 3); " size=", packet.getSize());
for (size_t i = 0; i < limit; ++i) { const auto& data = packet.getData();
char b[4]; std::string hex;
snprintf(b, sizeof(b), "%02x ", data[i]); size_t limit = std::min<size_t>(data.size(), 48);
hex += b; hex.reserve(limit * 3);
for (size_t i = 0; i < limit; ++i) {
char b[4];
snprintf(b, sizeof(b), "%02x ", data[i]);
hex += b;
}
LOG_INFO("Unhandled opcode payload hex (first ", limit, " bytes): ", hex);
} }
LOG_INFO("Unhandled opcode payload hex (first ", limit, " bytes): ", hex);
} else { } else {
static std::unordered_set<uint16_t> loggedUnhandledOpcodes; static std::unordered_set<uint16_t> loggedUnhandledOpcodes;
if (loggedUnhandledOpcodes.insert(static_cast<uint16_t>(opcode)).second) { if (loggedUnhandledOpcodes.insert(static_cast<uint16_t>(opcode)).second) {

View file

@ -126,7 +126,12 @@ bool ClassicPacketParsers::parseMovementBlock(network::Packet& packet, UpdateBlo
uint32_t pointCount = packet.readUInt32(); uint32_t pointCount = packet.readUInt32();
if (pointCount > 256) { if (pointCount > 256) {
LOG_WARNING(" [Classic] Spline pointCount=", pointCount, " exceeds max, capping"); static uint32_t badClassicSplineCount = 0;
++badClassicSplineCount;
if (badClassicSplineCount <= 5 || (badClassicSplineCount % 100) == 0) {
LOG_WARNING(" [Classic] Spline pointCount=", pointCount,
" exceeds max, capping (occurrence=", badClassicSplineCount, ")");
}
pointCount = 0; pointCount = 0;
} }
for (uint32_t i = 0; i < pointCount; i++) { for (uint32_t i = 0; i < pointCount; i++) {
@ -1135,7 +1140,12 @@ bool TurtlePacketParsers::parseMovementBlock(network::Packet& packet, UpdateBloc
uint32_t pointCount = packet.readUInt32(); uint32_t pointCount = packet.readUInt32();
if (pointCount > 256) { if (pointCount > 256) {
LOG_WARNING(" [Turtle] Spline pointCount=", pointCount, " exceeds max, capping"); static uint32_t badTurtleSplineCount = 0;
++badTurtleSplineCount;
if (badTurtleSplineCount <= 5 || (badTurtleSplineCount % 100) == 0) {
LOG_WARNING(" [Turtle] Spline pointCount=", pointCount,
" exceeds max, capping (occurrence=", badTurtleSplineCount, ")");
}
pointCount = 0; pointCount = 0;
} }
for (uint32_t i = 0; i < pointCount; i++) { for (uint32_t i = 0; i < pointCount; i++) {

View file

@ -140,7 +140,12 @@ bool TbcPacketParsers::parseMovementBlock(network::Packet& packet, UpdateBlock&
uint32_t pointCount = packet.readUInt32(); uint32_t pointCount = packet.readUInt32();
if (pointCount > 256) { if (pointCount > 256) {
LOG_WARNING(" [TBC] Spline pointCount=", pointCount, " exceeds max, capping"); static uint32_t badTbcSplineCount = 0;
++badTbcSplineCount;
if (badTbcSplineCount <= 5 || (badTbcSplineCount % 100) == 0) {
LOG_WARNING(" [TBC] Spline pointCount=", pointCount,
" exceeds max, capping (occurrence=", badTbcSplineCount, ")");
}
pointCount = 0; pointCount = 0;
} }
for (uint32_t i = 0; i < pointCount; i++) { for (uint32_t i = 0; i < pointCount; i++) {

View file

@ -911,8 +911,14 @@ bool UpdateObjectParser::parseMovementBlock(network::Packet& packet, UpdateBlock
uint32_t pointCount = packet.readUInt32(); uint32_t pointCount = packet.readUInt32();
if (pointCount > 256) { if (pointCount > 256) {
LOG_WARNING(" Spline pointCount=", pointCount, " exceeds maximum, capping at 0 (readPos=", static uint32_t badSplineCount = 0;
packet.getReadPos(), "/", packet.getSize(), ")"); ++badSplineCount;
if (badSplineCount <= 5 || (badSplineCount % 100) == 0) {
LOG_WARNING(" Spline pointCount=", pointCount,
" exceeds maximum, capping at 0 (readPos=",
packet.getReadPos(), "/", packet.getSize(),
", occurrence=", badSplineCount, ")");
}
pointCount = 0; pointCount = 0;
} else { } else {
LOG_DEBUG(" Spline pointCount=", pointCount); LOG_DEBUG(" Spline pointCount=", pointCount);

View file

@ -6,6 +6,7 @@
#include <filesystem> #include <filesystem>
#include <fstream> #include <fstream>
#include <limits> #include <limits>
#include <unordered_set>
#include "stb_image.h" #include "stb_image.h"
@ -145,13 +146,19 @@ BLPImage AssetManager::loadTexture(const std::string& path) {
std::vector<uint8_t> blpData = readFile(normalizedPath); std::vector<uint8_t> blpData = readFile(normalizedPath);
if (blpData.empty()) { if (blpData.empty()) {
LOG_WARNING("Texture not found: ", normalizedPath); static std::unordered_set<std::string> loggedMissingTextures;
if (loggedMissingTextures.insert(normalizedPath).second) {
LOG_WARNING("Texture not found: ", normalizedPath);
}
return BLPImage(); return BLPImage();
} }
BLPImage image = BLPLoader::load(blpData); BLPImage image = BLPLoader::load(blpData);
if (!image.isValid()) { if (!image.isValid()) {
LOG_ERROR("Failed to load texture: ", normalizedPath); static std::unordered_set<std::string> loggedDecodeFails;
if (loggedDecodeFails.insert(normalizedPath).second) {
LOG_ERROR("Failed to load texture: ", normalizedPath);
}
return BLPImage(); return BLPImage();
} }

View file

@ -1167,7 +1167,11 @@ bool M2Renderer::loadModel(const pipeline::M2Model& model, uint32_t modelId) {
GLuint texId = loadTexture(texPath, tex.flags); GLuint texId = loadTexture(texPath, tex.flags);
bool failed = (texId == whiteTexture); bool failed = (texId == whiteTexture);
if (failed) { if (failed) {
LOG_WARNING("M2 model ", model.name, " texture[", ti, "] failed to load: ", texPath); static std::unordered_set<std::string> loggedModelTextureFails;
std::string failKey = model.name + "|" + texKey;
if (loggedModelTextureFails.insert(failKey).second) {
LOG_WARNING("M2 model ", model.name, " texture[", ti, "] failed to load: ", texPath);
}
} }
if (isInvisibleTrap) { if (isInvisibleTrap) {
LOG_INFO(" InvisibleTrap texture[", ti, "]: ", texPath, " -> ", (failed ? "WHITE" : "OK")); LOG_INFO(" InvisibleTrap texture[", ti, "]: ", texPath, " -> ", (failed ? "WHITE" : "OK"));
@ -1187,8 +1191,7 @@ bool M2Renderer::loadModel(const pipeline::M2Model& model, uint32_t modelId) {
} }
static const bool kGlowDiag = envFlagEnabled("WOWEE_M2_GLOW_DIAG", false); static const bool kGlowDiag = envFlagEnabled("WOWEE_M2_GLOW_DIAG", false);
static std::unordered_set<std::string> loggedLanternGlowModels; if (kGlowDiag) {
{
std::string lowerName = model.name; std::string lowerName = model.name;
std::transform(lowerName.begin(), lowerName.end(), lowerName.begin(), std::transform(lowerName.begin(), lowerName.end(), lowerName.begin(),
[](unsigned char c) { return static_cast<char>(std::tolower(c)); }); [](unsigned char c) { return static_cast<char>(std::tolower(c)); });
@ -1196,11 +1199,11 @@ bool M2Renderer::loadModel(const pipeline::M2Model& model, uint32_t modelId) {
(lowerName.find("lantern") != std::string::npos) || (lowerName.find("lantern") != std::string::npos) ||
(lowerName.find("lamp") != std::string::npos) || (lowerName.find("lamp") != std::string::npos) ||
(lowerName.find("light") != std::string::npos); (lowerName.find("light") != std::string::npos);
if (lanternLike && (kGlowDiag || loggedLanternGlowModels.insert(lowerName).second)) { if (lanternLike) {
for (size_t ti = 0; ti < model.textures.size(); ++ti) { for (size_t ti = 0; ti < model.textures.size(); ++ti) {
const std::string key = (ti < textureKeysLower.size()) ? textureKeysLower[ti] : std::string(); const std::string key = (ti < textureKeysLower.size()) ? textureKeysLower[ti] : std::string();
LOG_INFO("M2 GLOW TEX '", model.name, "' tex[", ti, "]='", key, "' flags=0x", LOG_DEBUG("M2 GLOW TEX '", model.name, "' tex[", ti, "]='", key, "' flags=0x",
std::hex, model.textures[ti].flags, std::dec); std::hex, model.textures[ti].flags, std::dec);
} }
} }
} }
@ -1386,16 +1389,16 @@ bool M2Renderer::loadModel(const pipeline::M2Model& model, uint32_t modelId) {
(lowerName.find("light") != std::string::npos || (lowerName.find("light") != std::string::npos ||
lowerName.find("lamp") != std::string::npos || lowerName.find("lamp") != std::string::npos ||
lowerName.find("lantern") != std::string::npos)) { lowerName.find("lantern") != std::string::npos)) {
LOG_INFO("M2 GLOW DIAG '", model.name, "' batch ", gpuModel.batches.size(), LOG_DEBUG("M2 GLOW DIAG '", model.name, "' batch ", gpuModel.batches.size(),
": blend=", bgpu.blendMode, " matFlags=0x", ": blend=", bgpu.blendMode, " matFlags=0x",
std::hex, bgpu.materialFlags, std::dec, std::hex, bgpu.materialFlags, std::dec,
" colorKey=", bgpu.colorKeyBlack ? "Y" : "N", " colorKey=", bgpu.colorKeyBlack ? "Y" : "N",
" hasAlpha=", bgpu.hasAlpha ? "Y" : "N", " hasAlpha=", bgpu.hasAlpha ? "Y" : "N",
" unlit=", (bgpu.materialFlags & 0x01) ? "Y" : "N", " unlit=", (bgpu.materialFlags & 0x01) ? "Y" : "N",
" lanternHint=", bgpu.lanternGlowHint ? "Y" : "N", " lanternHint=", bgpu.lanternGlowHint ? "Y" : "N",
" glowSize=", bgpu.glowSize, " glowSize=", bgpu.glowSize,
" tex=", bgpu.texture, " tex=", bgpu.texture,
" idxCount=", bgpu.indexCount); " idxCount=", bgpu.indexCount);
} }
gpuModel.batches.push_back(bgpu); gpuModel.batches.push_back(bgpu);
} }
@ -3144,7 +3147,10 @@ GLuint M2Renderer::loadTexture(const std::string& path, uint32_t texFlags) {
// Load BLP texture // Load BLP texture
pipeline::BLPImage blp = assetManager->loadTexture(key); pipeline::BLPImage blp = assetManager->loadTexture(key);
if (!blp.isValid()) { if (!blp.isValid()) {
LOG_WARNING("M2: Failed to load texture: ", path); static std::unordered_set<std::string> loggedTextureLoadFails;
if (loggedTextureLoadFails.insert(key).second) {
LOG_WARNING("M2: Failed to load texture: ", path);
}
// Don't cache failures — transient StormLib thread contention can // Don't cache failures — transient StormLib thread contention can
// cause reads to fail; next loadModel call will retry. // cause reads to fail; next loadModel call will retry.
return whiteTexture; return whiteTexture;