chore(debug): add connection heartbeat diagnostics

server/status.py

@@ -1,6 +1,7 @@
 from __future__ import annotations
 import time
 import re
+import os
 from pathlib import Path
 from flask import Blueprint, jsonify, request, send_file, session
 
@@ -20,9 +21,12 @@ from modules.host_workspace_manager import (
     resolve_host_workspace,
 )
 from utils.host_workspace_debug import write_host_workspace_debug
+from .utils_common import log_conn_diag
 from . import state
 
 status_bp = Blueprint('status', __name__)
+STATUS_DIAG_VERBOSE = os.environ.get("STATUS_DIAG_VERBOSE", "0") not in {"0", "false", "False"}
+STATUS_DIAG_SLOW_MS = int(os.environ.get("STATUS_DIAG_SLOW_MS", "1200") or 1200)
 
 
 def _parse_android_version_from_gradle(project_root: Path) -> tuple[int, str]:
@@ -70,9 +74,33 @@ def _is_host_mode_request() -> bool:
 @with_terminal
 def get_status(terminal, workspace, username):
     """获取系统状态（包含对话、容器、版本等信息）"""
-    status = terminal.get_status()
+    started_at = time.perf_counter()
+    heartbeat_id = request.headers.get("X-Connection-Heartbeat", "").strip()
+    diag_requested = STATUS_DIAG_VERBOSE or request.args.get("diag") == "1"
+    timings = {
+        "terminal_ms": 0.0,
+        "terminals_ms": 0.0,
+        "conversation_meta_ms": 0.0,
+        "container_ms": 0.0,
+        "policy_ms": 0.0,
+    }
+    phase_started_at = time.perf_counter()
+    try:
+        status = terminal.get_status()
+    except Exception as exc:
+        timings["terminal_ms"] = (time.perf_counter() - phase_started_at) * 1000
+        total_ms = (time.perf_counter() - started_at) * 1000
+        log_conn_diag(
+            f"status hb={heartbeat_id or '-'} user={username} phase=terminal.get_status "
+            f"total_ms={total_ms:.1f} terminal_ms={timings['terminal_ms']:.1f} error={exc}"
+        )
+        raise
+    timings["terminal_ms"] = (time.perf_counter() - phase_started_at) * 1000
+    phase_started_at = time.perf_counter()
     if terminal.terminal_manager:
         status['terminals'] = terminal.terminal_manager.list_terminals()
+    timings["terminals_ms"] = (time.perf_counter() - phase_started_at) * 1000
+    phase_started_at = time.perf_counter()
     try:
         current_conv = terminal.context_manager.current_conversation_id
         status.setdefault('conversation', {})['current_id'] = current_conv
@@ -92,13 +120,18 @@ def get_status(terminal, workspace, username):
                     "job_id": meta.get("compression_job_id"),
                 }
     except Exception as exc:
-        print(f"[Status] 获取当前对话信息失败: {exc}")
+        log_conn_diag(f"status conversation-meta-failed user={username} error={exc}")
+    timings["conversation_meta_ms"] = (time.perf_counter() - phase_started_at) * 1000
     status['project_path'] = str(workspace.project_path)
+    phase_started_at = time.perf_counter()
     try:
         status['container'] = container_manager.get_container_status(username)
     except Exception as exc:
         status['container'] = {"success": False, "error": str(exc)}
+        log_conn_diag(f"status container-status-failed user={username} error={exc}")
+    timings["container_ms"] = (time.perf_counter() - phase_started_at) * 1000
     status['version'] = AGENT_VERSION
+    phase_started_at = time.perf_counter()
     try:
         policy = resolve_admin_policy(user_manager.get_user(username))
         status['admin_policy'] = {
@@ -109,6 +142,20 @@ def get_status(terminal, workspace, username):
         }
     except Exception:
         pass
+    timings["policy_ms"] = (time.perf_counter() - phase_started_at) * 1000
+    total_ms = (time.perf_counter() - started_at) * 1000
+    is_slow = total_ms >= STATUS_DIAG_SLOW_MS
+    if diag_requested or is_slow:
+        conversation = status.get("conversation") or {}
+        log_conn_diag(
+            f"status hb={heartbeat_id or '-'} user={username} host_mode={bool(session.get('host_mode'))} "
+            f"workspace_id={session.get('workspace_id') or '-'} "
+            f"conversation_id={conversation.get('current_id') or '-'} "
+            f"total_ms={total_ms:.1f} slow={is_slow} "
+            f"terminal_ms={timings['terminal_ms']:.1f} terminals_ms={timings['terminals_ms']:.1f} "
+            f"conversation_meta_ms={timings['conversation_meta_ms']:.1f} "
+            f"container_ms={timings['container_ms']:.1f} policy_ms={timings['policy_ms']:.1f}"
+        )
     return jsonify(status)
 
 

server/utils_common.py

@@ -144,6 +144,7 @@ DEBUG_LOG_FILE = Path(LOGS_DIR).expanduser().resolve() / "debug_stream.log"
 CHUNK_BACKEND_LOG_FILE = Path(LOGS_DIR).expanduser().resolve() / "chunk_backend.log"
 CHUNK_FRONTEND_LOG_FILE = Path(LOGS_DIR).expanduser().resolve() / "chunk_frontend.log"
 STREAMING_DEBUG_LOG_FILE = Path(LOGS_DIR).expanduser().resolve() / "streaming_debug.log"
+CONN_DIAG_LOG_FILE = Path(LOGS_DIR).expanduser().resolve() / "conn_diag.log"
 
 
 def _write_log(file_path: Path, message: str) -> None:
@@ -158,6 +159,11 @@ def debug_log(message):
     _write_log(DEBUG_LOG_FILE, message)
 
 
+def log_conn_diag(message: str):
+    """连接诊断日志：统一关键词并直接落盘到独立文件。"""
+    _write_log(CONN_DIAG_LOG_FILE, f"[CONN_DIAG] {message}")
+
+
 def log_backend_chunk(conversation_id: str, iteration: int, chunk_index: int, elapsed: float, char_len: int, content_preview: str):
     preview = content_preview.replace('\n', '\\n')
     _write_log(
@@ -192,4 +198,6 @@ __all__ = [
     "CHUNK_BACKEND_LOG_FILE",
     "CHUNK_FRONTEND_LOG_FILE",
     "STREAMING_DEBUG_LOG_FILE",
+    "CONN_DIAG_LOG_FILE",
+    "log_conn_diag",
 ]

static/src/app/methods/ui.ts

@@ -60,6 +60,61 @@ function uiBounceTrace(
   console.log('[SCROLL_BOUNCE_TRACE_UI]', event, payload);
 }
 
+function isConnectionDiagEnabled() {
+  if (typeof window === 'undefined') return true;
+  try {
+    const explicit = (window as any).__CONN_DIAG__;
+    if (explicit === false || explicit === '0') return false;
+    if (explicit === true || explicit === '1') return true;
+    const localFlag = window.localStorage?.getItem('connDiag');
+    if (localFlag === '0' || localFlag === 'false') return false;
+    if (localFlag === '1' || localFlag === 'true') return true;
+    // 默认常开：无需手动启动
+    return true;
+  } catch {
+    return true;
+  }
+}
+
+function pushConnectionDiagRecord(record: Record<string, any>) {
+  if (typeof window === 'undefined') return;
+  try {
+    const w = window as any;
+    if (!Array.isArray(w.__CONN_DIAG_LOGS__)) {
+      w.__CONN_DIAG_LOGS__ = [];
+    }
+    w.__CONN_DIAG_LOGS__.push(record);
+    const max = 400;
+    if (w.__CONN_DIAG_LOGS__.length > max) {
+      w.__CONN_DIAG_LOGS__.splice(0, w.__CONN_DIAG_LOGS__.length - max);
+    }
+  } catch {
+    // ignore
+  }
+}
+
+function connectionDiag(
+  level: 'log' | 'warn' | 'error',
+  event: string,
+  payload: Record<string, any> = {},
+  options: { force?: boolean } = {}
+) {
+  const force = !!options.force;
+  const enabled = isConnectionDiagEnabled();
+  if (!enabled && !force) {
+    return;
+  }
+  const record = {
+    ts: new Date().toISOString(),
+    event,
+    ...payload
+  };
+  pushConnectionDiagRecord(record);
+  const logger =
+    level === 'error' ? console.error : level === 'warn' ? console.warn : console.log;
+  logger('[CONN_DIAG]', event, record);
+}
+
 function parseSubAgentDoneLabel(rawContent: any): string | null {
   const content = (rawContent || '').toString().trim();
   if (!content) {
@@ -1970,23 +2025,105 @@ export const uiMethods = {
   },
 
   async checkConnectionHealth() {
+    const seq = Number(this.connectionHeartbeatSeq || 0) + 1;
+    this.connectionHeartbeatSeq = seq;
+    const requestId = `${Date.now()}-${seq}`;
+    const startedAt = Date.now();
+    const diagEnabled = isConnectionDiagEnabled();
+    const statusUrl = diagEnabled ? '/api/status?diag=1' : '/api/status';
+    const wasConnected = !!this.isConnected;
+    let responseStatus: number | null = null;
     const controller = typeof AbortController !== 'undefined' ? new AbortController() : null;
     const timeoutId = controller ? window.setTimeout(() => controller.abort(), 5000) : null;
     try {
-      const response = await fetch('/api/status', {
+      const response = await fetch(statusUrl, {
         method: 'GET',
         cache: 'no-store',
+        headers: {
+          'X-Connection-Heartbeat': requestId
+        },
         signal: controller?.signal
       });
+      responseStatus = response.status;
       if (!response.ok) {
         throw new Error(`HTTP ${response.status}`);
       }
+      const failCountBeforeRecover = this.connectionHeartbeatFailCount || 0;
       this.isConnected = true;
       this.connectionHeartbeatFailCount = 0;
+      this.connectionHeartbeatLastLatencyMs = Date.now() - startedAt;
+      this.connectionHeartbeatLastStatusCode = responseStatus;
+      this.connectionHeartbeatLastError = '';
+      if (!wasConnected) {
+        this.connectionHeartbeatLastChangeAt = Date.now();
+        connectionDiag(
+          'warn',
+          'health-recovered',
+          {
+            requestId,
+            seq,
+            elapsedMs: this.connectionHeartbeatLastLatencyMs,
+            failCountBeforeRecover,
+            status: responseStatus,
+            diagEnabled,
+            conversationId: this.currentConversationId || null,
+            taskInProgress: !!this.taskInProgress,
+            streamingMessage: !!this.streamingMessage,
+            visibility: document?.visibilityState || 'unknown',
+            online: typeof navigator !== 'undefined' ? navigator.onLine : null
+          },
+          { force: true }
+        );
+      } else if (
+        isConnectionDiagEnabled() &&
+        (this.connectionHeartbeatLastLatencyMs >= 700 || seq <= 3 || seq % 60 === 0)
+      ) {
+        connectionDiag('log', 'health-ok', {
+          requestId,
+          seq,
+          elapsedMs: this.connectionHeartbeatLastLatencyMs,
+          status: responseStatus,
+          visibility: document?.visibilityState || 'unknown'
+        });
+      }
     } catch (error) {
-      this.connectionHeartbeatFailCount = (this.connectionHeartbeatFailCount || 0) + 1;
+      const nextFailCount = (this.connectionHeartbeatFailCount || 0) + 1;
+      this.connectionHeartbeatFailCount = nextFailCount;
+      this.connectionHeartbeatLastLatencyMs = Date.now() - startedAt;
+      this.connectionHeartbeatLastStatusCode = responseStatus;
+      const errName = error?.name || 'Error';
+      const errMessage = error?.message || String(error);
+      this.connectionHeartbeatLastError = `${errName}: ${errMessage}`;
       // 一次失败就先置灰，避免“服务已断但常亮绿色”的误导
       this.isConnected = false;
+      if (wasConnected) {
+        this.connectionHeartbeatLastChangeAt = Date.now();
+      }
+      const shouldLogFail = wasConnected || nextFailCount <= 3 || nextFailCount % 10 === 0;
+      connectionDiag(
+        shouldLogFail ? 'warn' : 'log',
+        'health-failed',
+        {
+          requestId,
+          seq,
+          elapsedMs: this.connectionHeartbeatLastLatencyMs,
+          failCount: nextFailCount,
+          status: responseStatus,
+          diagEnabled,
+          wasConnected,
+          nowConnected: !!this.isConnected,
+          errorName: errName,
+          errorMessage: errMessage,
+          timeout: errName === 'AbortError',
+          visibility: document?.visibilityState || 'unknown',
+          online: typeof navigator !== 'undefined' ? navigator.onLine : null,
+          conversationId: this.currentConversationId || null,
+          taskInProgress: !!this.taskInProgress,
+          streamingMessage: !!this.streamingMessage,
+          hasPendingTools: typeof this.hasPendingToolActions === 'function' ? this.hasPendingToolActions() : null
+        },
+        { force: shouldLogFail }
+      );
     } finally {
       if (timeoutId) {
         clearTimeout(timeoutId);
@@ -2000,6 +2137,15 @@ export const uiMethods = {
     }
     this.connectionHeartbeatActive = true;
     this.connectionHeartbeatFailCount = 0;
+    connectionDiag(
+      'log',
+      'heartbeat-start',
+      {
+        connectedIntervalMs: this.connectionHeartbeatIntervalMs,
+        disconnectedIntervalMs: this.connectionHeartbeatDisconnectedIntervalMs
+      },
+      { force: true }
+    );
     const runHeartbeat = async () => {
       if (!this.connectionHeartbeatActive) {
         return;
@@ -2018,6 +2164,14 @@ export const uiMethods = {
           ? this.connectionHeartbeatDisconnectedIntervalMs
           : 1000;
       const nextInterval = this.isConnected ? connectedInterval : disconnectedInterval;
+      if (isConnectionDiagEnabled() && (!this.isConnected || (this.connectionHeartbeatSeq || 0) <= 3)) {
+        connectionDiag('log', 'heartbeat-next', {
+          seq: this.connectionHeartbeatSeq,
+          isConnected: !!this.isConnected,
+          failCount: this.connectionHeartbeatFailCount,
+          nextInterval
+        });
+      }
       this.connectionHeartbeatTimer = window.setTimeout(() => {
         runHeartbeat();
       }, nextInterval);
@@ -2033,6 +2187,7 @@ export const uiMethods = {
       clearTimeout(this.connectionHeartbeatTimer);
       this.connectionHeartbeatTimer = null;
     }
+    connectionDiag('log', 'heartbeat-stop', {}, { force: true });
   },
 
   openRealtimeTerminal() {

static/src/app/state.ts

@@ -139,6 +139,11 @@ export function dataState() {
     connectionHeartbeatTimer: null,
     connectionHeartbeatActive: false,
     connectionHeartbeatFailCount: 0,
+    connectionHeartbeatSeq: 0,
+    connectionHeartbeatLastLatencyMs: 0,
+    connectionHeartbeatLastError: '',
+    connectionHeartbeatLastStatusCode: null,
+    connectionHeartbeatLastChangeAt: 0,
     connectionHeartbeatIntervalMs: 8000,
     connectionHeartbeatDisconnectedIntervalMs: 1000,