Remove debug logging and add negative texture cache to fix lag spikes

Remove PPM composite dumps, MODEL1_BOUNDS vertex analysis, TEX_REGION
logging, FOUNTAIN_PARTICLES debug output, and verbose chat/warden gate
logging. Add negative cache for failed texture loads to prevent repeated
file I/O for missing textures like deathknighteyeglow.blp.
This commit is contained in:
Kelsi 2026-02-16 00:45:47 -08:00
parent 4190cb796f
commit d87a86e35c
8 changed files with 19 additions and 106 deletions

View file

@ -251,6 +251,7 @@ private:
}; };
std::unordered_map<std::string, TextureCacheEntry> textureCache; std::unordered_map<std::string, TextureCacheEntry> textureCache;
std::unordered_map<std::string, GLuint> compositeCache_; // key → GPU texture for reuse std::unordered_map<std::string, GLuint> compositeCache_; // key → GPU texture for reuse
std::unordered_set<std::string> failedTextureCache_; // negative cache for missing textures
size_t textureCacheBytes_ = 0; size_t textureCacheBytes_ = 0;
uint64_t textureCacheCounter_ = 0; uint64_t textureCacheCounter_ = 0;
size_t textureCacheBudgetBytes_ = 1024ull * 1024 * 1024; // Default, overridden at init size_t textureCacheBudgetBytes_ = 1024ull * 1024 * 1024; // Default, overridden at init

View file

@ -284,10 +284,10 @@ void GameHandler::update(float deltaTime) {
if (wardenGateSeen_ && socket && socket->isConnected()) { if (wardenGateSeen_ && socket && socket->isConnected()) {
wardenGateElapsed_ += deltaTime; wardenGateElapsed_ += deltaTime;
if (wardenGateElapsed_ >= wardenGateNextStatusLog_) { if (wardenGateElapsed_ >= wardenGateNextStatusLog_) {
LOG_INFO("Warden gate status: elapsed=", wardenGateElapsed_, LOG_DEBUG("Warden gate status: elapsed=", wardenGateElapsed_,
"s connected=", socket->isConnected() ? "yes" : "no", "s connected=", socket->isConnected() ? "yes" : "no",
" packetsAfterGate=", wardenPacketsAfterGate_); " packetsAfterGate=", wardenPacketsAfterGate_);
wardenGateNextStatusLog_ += 5.0f; wardenGateNextStatusLog_ += 30.0f;
} }
} }
@ -4196,11 +4196,7 @@ void GameHandler::handleMessageChat(network::Packet& packet) {
channelInfo = "[" + data.channelName + "] "; channelInfo = "[" + data.channelName + "] ";
} }
LOG_INFO("========================================"); LOG_DEBUG("[", getChatTypeString(data.type), "] ", channelInfo, senderInfo, ": ", data.message);
LOG_INFO(" CHAT [", getChatTypeString(data.type), "]");
LOG_INFO("========================================");
LOG_INFO(channelInfo, senderInfo, ": ", data.message);
LOG_INFO("========================================");
} }
void GameHandler::sendTextEmote(uint32_t textEmoteId, uint64_t targetGuid) { void GameHandler::sendTextEmote(uint32_t textEmoteId, uint64_t targetGuid) {

View file

@ -507,16 +507,8 @@ bool ClassicPacketParsers::parseMessageChat(network::Packet& packet, MessageChat
data.chatTag = packet.readUInt8(); data.chatTag = packet.readUInt8();
} }
LOG_INFO("[Classic] Parsed SMSG_MESSAGECHAT:"); LOG_DEBUG("[Classic] SMSG_MESSAGECHAT: type=", getChatTypeString(data.type),
LOG_INFO(" Type: ", getChatTypeString(data.type)); " sender=", data.senderName.empty() ? std::to_string(data.senderGuid) : data.senderName);
LOG_INFO(" Sender GUID: 0x", std::hex, data.senderGuid, std::dec);
if (!data.senderName.empty()) {
LOG_INFO(" Sender name: ", data.senderName);
}
if (!data.channelName.empty()) {
LOG_INFO(" Channel: ", data.channelName);
}
LOG_INFO(" Message: ", data.message);
return true; return true;
} }

View file

@ -1127,6 +1127,7 @@ M2Model M2Loader::load(const std::vector<uint8_t>& m2Data) {
if (midpoint < 0.0f || midpoint > 1.0f) midpoint = 0.5f; if (midpoint < 0.0f || midpoint > 1.0f) midpoint = 0.5f;
// Synthesize color FBlock from static BGRA values // Synthesize color FBlock from static BGRA values
// Vanilla M2 stores 3× uint32 as BGRA (little-endian: byte0=B, byte1=G, byte2=R, byte3=A)
{ {
em.particleColor.timestamps = {0.0f, midpoint, 1.0f}; em.particleColor.timestamps = {0.0f, midpoint, 1.0f};
em.particleColor.vec3Values.resize(3); em.particleColor.vec3Values.resize(3);

View file

@ -357,11 +357,15 @@ GLuint CharacterRenderer::loadTexture(const std::string& path) {
return whiteTexture; return whiteTexture;
} }
// Check negative cache to avoid repeated file I/O for textures that don't exist
if (failedTextureCache_.count(key)) {
return whiteTexture;
}
auto blpImage = assetManager->loadTexture(key); auto blpImage = assetManager->loadTexture(key);
if (!blpImage.isValid()) { if (!blpImage.isValid()) {
core::Logger::getInstance().warning("Failed to load texture: ", path); core::Logger::getInstance().warning("Failed to load texture: ", path);
// Do not cache failures as white. Some asset reads can fail transiently and failedTextureCache_.insert(key);
// we want later retries (e.g., mount skins loaded shortly after model spawn).
return whiteTexture; return whiteTexture;
} }
@ -553,11 +557,6 @@ GLuint CharacterRenderer::compositeTextures(const std::vector<std::string>& laye
} }
} }
// Debug dump removed: it was always-on and could stall badly under load.
// Debug: dump first composite to /tmp for visual inspection
// Upload composite to GPU // Upload composite to GPU
GLuint texId; GLuint texId;
glGenTextures(1, &texId); glGenTextures(1, &texId);
@ -765,26 +764,6 @@ GLuint CharacterRenderer::compositeWithRegions(const std::string& basePath,
" at (", dstX, ",", dstY, ") ", overlay.width, "x", overlay.height, " from ", rl.second); " at (", dstX, ",", dstY, ") ", overlay.width, "x", overlay.height, " from ", rl.second);
} }
// Debug: dump composite to /tmp for visual inspection
{
static int dumpCount = 0;
if (dumpCount < 6) {
dumpCount++;
std::string dumpPath = "/tmp/wowee_composite_" + std::to_string(dumpCount) + ".ppm";
FILE* f = fopen(dumpPath.c_str(), "wb");
if (f) {
fprintf(f, "P6\n%d %d\n255\n", width, height);
for (int i = 0; i < width * height; i++) {
fputc(composite[i * 4 + 0], f);
fputc(composite[i * 4 + 1], f);
fputc(composite[i * 4 + 2], f);
}
fclose(f);
core::Logger::getInstance().info("compositeWithRegions: dumped to ", dumpPath);
}
}
}
// Upload to GPU // Upload to GPU
GLuint texId; GLuint texId;
glGenTextures(1, &texId); glGenTextures(1, &texId);
@ -874,37 +853,6 @@ bool CharacterRenderer::loadModel(const pipeline::M2Model& model, uint32_t id) {
" verts, ", model.bones.size(), " bones, ", model.sequences.size(), " verts, ", model.bones.size(), " bones, ", model.sequences.size(),
" anims, ", model.textures.size(), " textures)"); " anims, ", model.textures.size(), " textures)");
// Debug: dump vertex bounding boxes per submesh group for player model
if (id == 1) {
core::Logger::getInstance().info("MODEL1_VERSION: ", model.version);
std::map<uint16_t, std::array<float,6>> groupBounds; // group -> minX,minY,minZ,maxX,maxY,maxZ
for (const auto& b : model.batches) {
uint16_t grp = b.submeshId;
for (uint32_t idx = b.indexStart; idx < b.indexStart + b.indexCount && idx < model.indices.size(); idx++) {
uint16_t vi = model.indices[idx];
if (vi >= model.vertices.size()) continue;
const auto& v = model.vertices[vi];
auto it = groupBounds.find(grp);
if (it == groupBounds.end()) {
groupBounds[grp] = {v.position.x, v.position.y, v.position.z,
v.position.x, v.position.y, v.position.z};
} else {
auto& bb = it->second;
bb[0] = std::min(bb[0], v.position.x);
bb[1] = std::min(bb[1], v.position.y);
bb[2] = std::min(bb[2], v.position.z);
bb[3] = std::max(bb[3], v.position.x);
bb[4] = std::max(bb[4], v.position.y);
bb[5] = std::max(bb[5], v.position.z);
}
}
}
for (const auto& [grp, bb] : groupBounds) {
core::Logger::getInstance().info("MODEL1_BOUNDS: submesh=", grp,
" X[", bb[0], "..", bb[3], "] Y[", bb[1], "..", bb[4], "] Z[", bb[2], "..", bb[5], "]");
}
}
return true; return true;
} }

View file

@ -2352,14 +2352,8 @@ void M2Renderer::renderM2Particles(const glm::mat4& view, const glm::mat4& proj)
float alpha = interpFBlockFloat(em.particleAlpha, lifeRatio); float alpha = interpFBlockFloat(em.particleAlpha, lifeRatio);
float scale = interpFBlockFloat(em.particleScale, lifeRatio); float scale = interpFBlockFloat(em.particleScale, lifeRatio);
// Some waterfall/spray emitters become overly dark after channel-correct decoding. // Note: blue-dominant color correction removed — it was over-brightening
// Apply a small correction only for strongly blue-dominant particle colors. // water/fountain particles, making them look like spell effects.
if (color.b > color.r * 1.4f && color.b > color.g * 1.15f) {
float luma = color.r * 0.2126f + color.g * 0.7152f + color.b * 0.0722f;
color = glm::mix(color, glm::vec3(luma), 0.35f);
color *= 1.35f;
color = glm::clamp(color, glm::vec3(0.28f, 0.35f, 0.45f), glm::vec3(1.0f));
}
GLuint tex = whiteTexture; GLuint tex = whiteTexture;
if (p.emitterIndex < static_cast<int>(gpu.particleTextures.size())) { if (p.emitterIndex < static_cast<int>(gpu.particleTextures.size())) {
@ -2421,18 +2415,9 @@ void M2Renderer::renderM2Particles(const glm::mat4& view, const glm::mat4& proj)
for (auto& [key, group] : groups) { for (auto& [key, group] : groups) {
if (group.vertexData.empty()) continue; if (group.vertexData.empty()) continue;
// Set blend mode. Many classic glow textures use a black background with no alpha, // Use blend mode as specified by the emitter — don't override based on texture alpha.
// and expect additive blending so black contributes nothing. // BlendType: 0=opaque, 1=alphaKey, 2=alpha, 3=add, 4=mod
bool texHasAlpha = true;
if (auto it = textureHasAlphaById_.find(group.texture); it != textureHasAlphaById_.end()) {
texHasAlpha = it->second;
}
uint8_t blendType = group.blendType; uint8_t blendType = group.blendType;
if ((blendType == 1 || blendType == 2) && !texHasAlpha) {
blendType = 4; // Treat as additive fallback
}
if (blendType == 3 || blendType == 4) { if (blendType == 3 || blendType == 4) {
glBlendFunc(GL_SRC_ALPHA, GL_ONE); // Additive glBlendFunc(GL_SRC_ALPHA, GL_ONE); // Additive
} else { } else {

View file

@ -1189,7 +1189,6 @@ void WMORenderer::render(const Camera& camera, const glm::mat4& view, const glm:
const auto& group = model.groups[gi]; const auto& group = model.groups[gi];
glm::vec3 groupCenter = (group.boundingBoxMin + group.boundingBoxMax) * 0.5f; glm::vec3 groupCenter = (group.boundingBoxMin + group.boundingBoxMax) * 0.5f;
glm::vec4 worldCenter = instance.modelMatrix * glm::vec4(groupCenter, 1.0f); glm::vec4 worldCenter = instance.modelMatrix * glm::vec4(groupCenter, 1.0f);
float distToGroup = glm::length(cameraPos - glm::vec3(worldCenter));
// Log bounding box to identify groups that are positioned HIGH (floating shell) // Log bounding box to identify groups that are positioned HIGH (floating shell)
glm::vec3 size = group.boundingBoxMax - group.boundingBoxMin; glm::vec3 size = group.boundingBoxMax - group.boundingBoxMin;
@ -1233,8 +1232,8 @@ void WMORenderer::render(const Camera& camera, const glm::mat4& view, const glm:
float distToGroup = glm::length(cameraPos - glm::vec3(worldCenter)); float distToGroup = glm::length(cameraPos - glm::vec3(worldCenter));
static int logCounter = 0; static int logCounter = 0;
if (logCounter++ % 300 == 0) { if (logCounter++ % 10000 == 0) {
LOG_INFO("LOD Shell Group ", gi, ": worldZ=", worldCenter.z, " sizeZ=", size.z, LOG_DEBUG("LOD Shell Group ", gi, ": worldZ=", worldCenter.z, " sizeZ=", size.z,
" distToGroup=", distToGroup, " (hiding if < 185)"); " distToGroup=", distToGroup, " (hiding if < 185)");
} }

View file

@ -2804,15 +2804,6 @@ void GameScreen::updateCharacterTextures(game::Inventory& inventory) {
} }
} }
// TEMP: log region layers for debugging
{
static const char* regionNames[] = {"ArmUpper","ArmLower","Hand","TorsoUpper","TorsoLower","LegUpper","LegLower","Foot"};
for (const auto& rl : regionLayers) {
LOG_INFO("TEX_REGION: region=", rl.first, "(", (rl.first < 8 ? regionNames[rl.first] : "?"), ") path=", rl.second);
}
LOG_INFO("TEX_REGION: total=", regionLayers.size(), " regions, baseSkin=", bodySkinPath);
}
// Re-composite: base skin + underwear + equipment regions // Re-composite: base skin + underwear + equipment regions
// Clear composite cache first to prevent stale textures from being reused // Clear composite cache first to prevent stale textures from being reused
charRenderer->clearCompositeCache(); charRenderer->clearCompositeCache();