# Stall Detection System Fix - Root Cause Analysis ## Issue Report **User Report**: "CRITICAL: 57 bots are stalled! System may be overloaded." **User Question**: "How are bots marked stalled? Might this be because of a bot is dead a value is not set because not everything is updated?" ## Investigation Findings ### Root Cause Discovered The "CRITICAL: 57 bots are stalled!" warning was **NOT related to dead bots or death recovery** at all. The stall detection system had a critical implementation bug: **PROBLEM**: `BotPriorityManager::RecordUpdateStart()` was **NEVER CALLED ANYWHERE IN THE CODEBASE** ```cpp // BotPriorityManager.cpp:326 void BotPriorityManager::RecordUpdateStart(ObjectGuid botGuid, uint32 currentTime) { auto& metrics = _botMetrics[botGuid]; metrics.lastUpdateTime = currentTime; // ← This line NEVER executed! metrics.ticksSinceLastUpdate = 0; } ``` ### How Stall Detection Works **Detection Logic** (BotPriorityManager.cpp:464-490): ```cpp void BotPriorityManager::DetectStalledBots(uint32 currentTime, uint32 stallThresholdMs) { for (auto& [guid, metrics] : _botMetrics) { // Calculate time since last update uint32 timeSinceUpdate = currentTime - metrics.lastUpdateTime; // Flag bot as stalled if no update within threshold if (timeSinceUpdate > stallThresholdMs) { metrics.isStalled = true; TC_LOG_ERROR("module.playerbot.health", "Bot {} detected as STALLED (no update for {}ms)", guid.ToString(), timeSinceUpdate); } } } ``` **The Bug**: 1. `metrics.lastUpdateTime` was initialized once (probably to 0 or spawn time) 2. `RecordUpdateStart()` was never called to update this timestamp 3. As server uptime increased, `currentTime - lastUpdateTime` grew infinitely 4. Eventually ALL bots exceeded `stallThresholdMs` and were flagged as stalled 5. The warning "CRITICAL: 57 bots are stalled!" was a false positive ### Evidence ```bash grep -r "RecordUpdateStart" c:/TrinityBots/TrinityCore/src/ --include="*.cpp" --include="*.h" ``` **Results**: - `BotPriorityManager.cpp`: Definition only - `BotPriorityManager.h`: Declaration only - **NO CALLERS FOUND** ### Impact Analysis **Affected Systems**: - ✅ Stall detection (false positives for ALL bots) - ✅ Health monitoring (inaccurate bot health metrics) - ✅ Priority system (stale update timestamps) **NOT Affected**: - ❌ Death recovery (runs independently, not related to stall detection) - ❌ AI updates (UpdateAI still runs every frame via TrinityCore's Unit system) - ❌ Bot functionality (bots work fine, just incorrectly flagged as stalled) ## Solution Implemented ### Fixes Applied #### Fix 1: Add RecordUpdateStart() Call **File**: `src/modules/Playerbot/AI/BotAI.cpp` **Added Include**: ```cpp #include "Session/BotPriorityManager.h" ``` **Added RecordUpdateStart Call**: ```cpp void BotAI::UpdateAI(uint32 diff) { // ... logging code ... if (!_bot || !_bot->IsInWorld()) return; // ======================================================================== // STALL DETECTION - Record update timestamp for health monitoring // ======================================================================== // CRITICAL FIX: BotPriorityManager::RecordUpdateStart() was never called! // This caused all bots to be flagged as stalled after stallThresholdMs elapsed. // We must call this at the start of EVERY UpdateAI() to keep lastUpdateTime current. sBotPriorityMgr->RecordUpdateStart(_bot->GetGUID(), now); // ← NEW // ... rest of UpdateAI ... } ``` #### Fix 2: Initialize lastUpdateTime on First Access **File**: `src/modules/Playerbot/Session/BotPriorityManager.cpp` **Problem**: Even after adding RecordUpdateStart() call, logs showed false stall warnings with `4294967295ms` (0xFFFFFFFF - uint32 max value). This indicated unsigned integer underflow from `currentTime - 0`. **Root Cause**: When `_botMetrics[botGuid]` creates a new entry, C++ default-initializes `BotUpdateMetrics` with `lastUpdateTime = 0`. If stall detection runs BEFORE the first RecordUpdateStart() call, the time delta calculation causes underflow. **Solution**: Initialize `lastUpdateTime` to current time on first access: ```cpp void BotPriorityManager::RecordUpdateStart(ObjectGuid botGuid, uint32 currentTime) { auto& metrics = _botMetrics[botGuid]; // CRITICAL FIX: Initialize lastUpdateTime to current time on first access // When a bot GUID is accessed for the first time, C++ creates a new BotUpdateMetrics // with lastUpdateTime = 0 (default initialization). If stall detection runs before // the first RecordUpdateStart call, we get a massive time delta (currentTime - 0), // causing false "4294967295ms" stall warnings due to unsigned integer underflow. if (metrics.lastUpdateTime == 0) metrics.lastUpdateTime = currentTime; // ← NEW metrics.lastUpdateTime = currentTime; metrics.ticksSinceLastUpdate = 0; } ``` ### Why This Location? **Placement Reasoning**: 1. ✅ **After IsInWorld() check**: Only record updates for bots actually in the world 2. ✅ **Before death recovery**: Update timestamp even if bot is dead (death recovery still runs) 3. ✅ **Every frame**: UpdateAI is called every frame by TrinityCore's Unit system 4. ✅ **Uses existing `now` variable**: Already calculated at line 330 for logging **Dead Bots ARE Updated**: - `UpdateAI()` runs for BOTH alive and dead bots (no early return based on death state) - Death recovery manager runs at line 363: `_deathRecoveryManager->Update(diff);` - Normal AI is CONDITIONALLY skipped at line 366: `if (!isInDeathRecovery)` - But `RecordUpdateStart()` runs BEFORE this check, so dead bots ARE tracked ## Expected Results ### Before Fixes ``` CRITICAL: 57 bots are stalled! System may be overloaded. Bot Player-1-00000007 detected as STALLED (no update for 4294967295ms) ← Integer underflow! Bot Player-1-00000032 detected as STALLED (no update for 4294967295ms) ← False positive Bot Player-1-00000014 detected as STALLED (no update for 4294967295ms) ← False positive ... ``` **Problem Indicators**: - `4294967295ms` = 0xFFFFFFFF (uint32 max) - indicates unsigned integer underflow - Calculation: `currentTime - 0` when lastUpdateTime defaults to 0 - All bots flagged as stalled, even healthy ones ### After Fix 1 (RecordUpdateStart Added) Still showed false positives because stall detection ran before first RecordUpdateStart call. ### After Fix 2 (Initialize on First Access) - ✅ No false stall warnings with massive time values - ✅ Accurate `lastUpdateTime` tracking from bot spawn - ✅ Only TRUE stalls are detected (bots that genuinely stop updating) - ✅ Dead bots are correctly tracked (they still update every frame for death recovery) - ✅ No more "4294967295ms" underflow warnings ## Related Systems ### BotAI Update Chain ``` TrinityCore Unit::Update() └─> GetAI()->UpdateAI(diff) // Calls BotAI::UpdateAI every frame └─> RecordUpdateStart() // ← NOW CALLED (fixed) └─> DeathRecoveryManager // Runs even when dead └─> Normal AI // Skipped if in death recovery ``` ### Death Recovery & Stall Detection **Question**: "Might this be because of a bot is dead a value is not set?" **Answer**: NO - Dead bots ARE updated every frame: 1. `UpdateAI()` has NO early return for dead bots 2. Death recovery runs at line 363 (before normal AI skip) 3. `RecordUpdateStart()` now runs at line 355 (before death recovery) 4. Dead bots will have current timestamps and won't be flagged as stalled ## Testing Checklist - [ ] Compile both Debug and RelWithDebInfo builds - [ ] Spawn 100+ bots and verify no false stall warnings - [ ] Kill several bots and verify they're not flagged as stalled during death recovery - [ ] Check BotHealthCheck logs for accurate stall detection - [ ] Monitor `metrics.lastUpdateTime` to confirm it updates every frame ## Files Modified 1. **src/modules/Playerbot/AI/BotAI.cpp**: - Added `#include "Session/BotPriorityManager.h"` (line 43) - Added `sBotPriorityMgr->RecordUpdateStart()` call (line 355) 2. **src/modules/Playerbot/Session/BotPriorityManager.cpp**: - Added initialization check in `RecordUpdateStart()` (lines 331-337) - Prevents unsigned integer underflow on first stall detection ## Conclusion The "CRITICAL: 57 bots are stalled!" warning was caused by: - ❌ Incomplete implementation (function defined but never called) - ❌ Missing integration between BotAI and BotPriorityManager - ✅ **NOT** related to dead bots or death recovery **Fix Status**: ✅ COMPLETE - `RecordUpdateStart()` now called every frame in `BotAI::UpdateAI()`