Fix UNHEALTHY status: Add file-based heartbeat as primary health check

The issue was that heartbeat validation relied solely on JSON file reads
which could be stale or fail to reflect true worker state.

Changes:
- /api/state now checks /app/logs/worker_heartbeat.txt directly (primary source)
- Added fallback to JSON heartbeat if file check fails
- Added detailed diagnostics with failure_reason logging
- Watchdog _is_process_alive now uses file heartbeat as primary check
- Added comprehensive logging for health check failures

This fixes the issue where brain_pid exists but heartbeat_fresh is False
by using the worker-written file as the source of truth for activity.

Co-Authored-By: Claude Code <noreply@anthropic.com>

app.py

@@ -185,11 +185,38 @@ class ProcessWatchdog:
         self._log("info", "Monitor thread stopped")
 
     def _is_process_alive(self) -> bool:
-        """Check if the managed process is alive and the PID is real."""
+        """
+        Check if the managed process is alive and actively running.
+
+        Uses multiple checks in order:
+        1. File-based heartbeat (primary truth source - written by worker)
+        2. Subprocess polling (detects crashes)
+        3. PID existence verification (detects ghost PIDs)
+        4. Process name verification (ensures it's our python process)
+        """
         if self.process is None or self.pid is None:
             return False
 
-        # First check: try polling the subprocess
+        # PRIMARY CHECK: File-based heartbeat (source of truth for worker activity)
+        heartbeat_path = Path("/app/logs/worker_heartbeat.txt")
+        if heartbeat_path.exists():
+            try:
+                with open(heartbeat_path, "r") as f:
+                    heartbeat_content = f.read().strip()
+                if heartbeat_content:
+                    heartbeat_time = datetime.fromisoformat(heartbeat_content.replace("+00:00", "").replace("Z", ""))
+                    # Make timezone-naive for comparison
+                    if heartbeat_time.tzinfo is not None:
+                        heartbeat_time = heartbeat_time.replace(tzinfo=None)
+                    heartbeat_age = (datetime.utcnow() - heartbeat_time).total_seconds()
+                    # Heartbeat is fresh if updated within 15 seconds
+                    if heartbeat_age < 15:
+                        # Fresh heartbeat means worker is actively running
+                        return True
+            except Exception as e:
+                self._log("warning", "Heartbeat file check failed", error=str(e))
+
+        # SECONDARY CHECK: Try polling the subprocess
         try:
             poll_result = self.process.poll()
             if poll_result is not None:
@@ -200,7 +227,7 @@ class ProcessWatchdog:
             self._log("warning", "Process poll failed", error=str(e))
             return False
 
-        # Second check: verify PID exists in system (detect ghost PIDs)
+        # TERTIARY CHECK: Verify PID exists in system (detect ghost PIDs)
         try:
             if not psutil.pid_exists(self.pid):
                 self._log("warning", "Ghost PID detected - process not found in system", pid=self.pid)
@@ -208,7 +235,7 @@ class ProcessWatchdog:
         except Exception as e:
             self._log("warning", "PID check failed", error=str(e))
 
-        # Third check: verify process name matches python (double-verify)
+        # QUATERNARY CHECK: Verify process name matches python (double-verify)
         try:
             proc = psutil.Process(self.pid)
             if "python" not in proc.name().lower():
@@ -220,8 +247,11 @@ class ProcessWatchdog:
         except Exception as e:
             self._log("warning", "Process name check failed", error=str(e))
 
-        # All checks passed
-        return True
+        # All checks passed (but heartbeat was stale)
+        # Log this case - process exists but heartbeat is stale
+        self._log("info", "Process exists but heartbeat stale", pid=self.pid,
+                  note="Heartbeat file exists but is >15s old")
+        return False
 
     def _update_status_file(self):
         """Update cain_status.json with current process info."""
@@ -483,19 +513,56 @@ async def api_state(request: Request):
 
     watchdog_status = _watchdog.get_status() if _watchdog else {"is_alive": False, "pid": None}
 
-    # Check heartbeat freshness - if heartbeat is older than 15 seconds, worker is likely dead
-    heartbeat_str = status_data.get("worker_heartbeat")
+    # PRIMARY HEARTBEAT CHECK: Read file-based heartbeat (written directly by worker process)
+    # This is the source of truth for detecting a live worker process
+    heartbeat_path = Path("/app/logs/worker_heartbeat.txt")
+    file_heartbeat_time = None
+    file_heartbeat_age = None
     heartbeat_fresh = False
-    if heartbeat_str:
+
+    if heartbeat_path.exists():
         try:
-            from datetime import timedelta
-            heartbeat_time = datetime.fromisoformat(heartbeat_str.replace("+00:00", "").replace("Z", "+00:00"))
-            if heartbeat_time.endswith("+00:00"):
-                heartbeat_time = heartbeat_time.replace(tzinfo=None)
-            heartbeat_age = (datetime.utcnow() - heartbeat_time.replace(tzinfo=None)).total_seconds()
-            heartbeat_fresh = heartbeat_age < 15
-        except Exception:
-            heartbeat_fresh = False
+            with open(heartbeat_path, "r") as f:
+                content = f.read().strip()
+            if content:
+                # Parse ISO timestamp
+                file_heartbeat_time = datetime.fromisoformat(content.replace("+00:00", "").replace("Z", "+00:00"))
+                if file_heartbeat_time.tzinfo is not None:
+                    file_heartbeat_time = file_heartbeat_time.replace(tzinfo=None)
+                file_heartbeat_age = (datetime.utcnow() - file_heartbeat_time).total_seconds()
+                # Heartbeat is fresh if updated within 15 seconds
+                heartbeat_fresh = file_heartbeat_age < 15
+        except Exception as e:
+            logger.warning(f"[STATE] Failed to read heartbeat file: {e}")
+
+    # FALLBACK: Check heartbeat in JSON file (secondary source)
+    json_heartbeat_str = status_data.get("worker_heartbeat")
+    json_heartbeat_age = None
+    if json_heartbeat_str and not heartbeat_fresh:
+        try:
+            json_heartbeat_time = datetime.fromisoformat(json_heartbeat_str.replace("+00:00", "").replace("Z", "+00:00"))
+            if json_heartbeat_time.endswith("+00:00"):
+                json_heartbeat_time = json_heartbeat_time.replace(tzinfo=None)
+            json_heartbeat_age = (datetime.utcnow() - json_heartbeat_time.replace(tzinfo=None)).total_seconds()
+            # Use JSON heartbeat if it's fresh (even if file check failed)
+            if json_heartbeat_age < 15:
+                heartbeat_fresh = True
+                file_heartbeat_age = json_heartbeat_age
+        except Exception as e:
+            logger.warning(f"[STATE] Failed to parse JSON heartbeat: {e}")
+
+    # DETAILED DIAGNOSTICS: Log why state is determined as unhealthy
+    failure_reason = None
+    if not heartbeat_fresh:
+        if file_heartbeat_age is not None:
+            failure_reason = f"File heartbeat stale: {file_heartbeat_age:.1f}s old (threshold: 15s)"
+        elif json_heartbeat_age is not None:
+            failure_reason = f"JSON heartbeat stale: {json_heartbeat_age:.1f}s old"
+        else:
+            failure_reason = "No heartbeat found (file or JSON)"
+
+        # Log with full diagnostic info
+        logger.warning(f"[STATE] Heartbeat check failed: {failure_reason} | PID={watchdog_status.get('pid')} | File exists={heartbeat_path.exists()}")
 
     # Determine actual state based on watchdog health and heartbeat freshness
     worker_state = status_data.get("_worker_state", "")
@@ -510,15 +577,30 @@ async def api_state(request: Request):
     else:
         reported_state = current_state
 
+    # Build detail message with diagnostic info
+    if watchdog_status["is_alive"] and heartbeat_fresh:
+        detail = "Cain is operational"
+    elif failure_reason:
+        detail = f"Brain process issue: {failure_reason}"
+    else:
+        detail = "Brain process not running or stale"
+
     return {
         "state": reported_state,
-        "detail": "Cain is operational" if watchdog_status["is_alive"] and heartbeat_fresh else "Brain process not running or stale",
+        "detail": detail,
         "updated_at": datetime.utcnow().isoformat() + "+00:00",
         "stage": status_data.get("stage", "RUNNING"),
         "health": "HEALTHY" if watchdog_status["is_alive"] and heartbeat_fresh else "UNHEALTHY",
         "is_alive": watchdog_status["is_alive"],
         "brain_pid": watchdog_status.get("pid"),
-        "heartbeat_fresh": heartbeat_fresh
+        "heartbeat_fresh": heartbeat_fresh,
+        "heartbeat_age_seconds": round(file_heartbeat_age, 2) if file_heartbeat_age is not None else None,
+        "_diagnostics": {
+            "heartbeat_file_exists": heartbeat_path.exists(),
+            "failure_reason": failure_reason,
+            "file_heartbeat_age": round(file_heartbeat_age, 2) if file_heartbeat_age is not None else None,
+            "json_heartbeat_age": round(json_heartbeat_age, 2) if json_heartbeat_age is not None else None
+        }
     }