From cb334ddd5449ede6414b8ef3b052cdb37cf5ad4e Mon Sep 17 00:00:00 2001 From: hmo Date: Sun, 19 Jul 2026 23:43:28 +0800 Subject: [PATCH] fix(bot+auto_heal): stop auto_heal from killing bot during slow LLM calls MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Root cause of 'no response': auto_heal restart_zhiwei_bot fired whenever inbound>0 + outbound=0 + errors>0 — which is exactly the normal state while the bot waits for a slow LLM call (agent tool-use turns take 1-10 min). Restart killed the in-flight LLM call -> user never got reply -> next cron cycle saw same state -> restart again. Death loop (fired 22:30,22:35,22:40, 22:45,22:50,23:35). Fixes: - CALL_HERMES_TIMEOUT 180s -> 600s (agent tool calls need minutes) - health(): parse last_inbound/outbound timestamps from journal - auto_heal: restart bot ONLY if last inbound >600s old with no outbound since (truly stuck), plus 600s bot-restart cooldown - slow-but-normal state now logs bot_busy_not_stuck instead of killing --- deploy/bot/xmpp_agent_core.py | 4 +-- xmpp_logger.py | 60 ++++++++++++++++++++++++++++++----- 2 files changed, 54 insertions(+), 10 deletions(-) diff --git a/deploy/bot/xmpp_agent_core.py b/deploy/bot/xmpp_agent_core.py index f44c3829..cd7a5324 100644 --- a/deploy/bot/xmpp_agent_core.py +++ b/deploy/bot/xmpp_agent_core.py @@ -52,8 +52,8 @@ ACK_DELAY = 120 # 真卡死才提示（普通 LLM 冷启动 20-100s 不应触 GATEWAY_URL = "" GATEWAY_API_KEY = "" GATEWAY_SESSION_ID = "" -GATEWAY_DEADLINE_SECONDS = 180 -CALL_HERMES_TIMEOUT = 180 +GATEWAY_DEADLINE_SECONDS = 600 +CALL_HERMES_TIMEOUT = 600 # agent 带工具调用（读文件/查数据）需几分钟 FALLBACK_REPLY = "请稍等，我在处理..." # ── 图片 OCR 配置（截图消息 → SenseNova vision）── diff --git a/xmpp_logger.py b/xmpp_logger.py index 5bbc20a0..cb44533e 100644 --- a/xmpp_logger.py +++ b/xmpp_logger.py @@ -292,11 +292,27 @@ def health(): inbound = [l for l in lines if "📩 收到" in l] outbound = [l for l in lines if "📤 发送" in l or "📤" in l] errors = [l for l in lines if "ERROR" in l or "TimeoutError" in l or "timed out" in l] + + # 解析最后一条 inbound 的时间（行首 python logging 时间戳 "2026-07-19 23:31:07,342"） + import re as _re2 + def _line_epoch(line): + m = _re2.search(r"(\d{4}-\d{2}-\d{2} \d{2}:\d{2}:\d{2})", line) + if not m: + return 0 + try: + return datetime.strptime(m.group(1), "%Y-%m-%d %H:%M:%S").timestamp() + except Exception: + return 0 + + last_inbound_ts = max((_line_epoch(l) for l in inbound), default=0) + last_outbound_ts = max((_line_epoch(l) for l in outbound), default=0) result["bot_activity"] = { "inbound": len(inbound), "outbound": len(outbound), "errors": len(errors), "last_error": errors[-1][:250] if errors else None, "last_inbound": inbound[-1][:250] if inbound else None, "last_outbound": outbound[-1][:200] if outbound else None, + "last_inbound_age_sec": int(now_epoch - last_inbound_ts) if last_inbound_ts else -1, + "last_outbound_age_sec": int(now_epoch - last_outbound_ts) if last_outbound_ts else -1, } if errors and not outbound: result["status"] = "degraded" if inbound and not outbound: result["status"] = "degraded" @@ -494,16 +510,44 @@ def auto_heal(): "success": False, "detail": str(e)[:100]}) - # 2. Bot 无出站 → 重启知微 Bot + # 2. Bot 真卡死才重启：最后一条 inbound 超过 10 分钟仍无出站，才算死（不是 LLM 慢） + # LLM 正常冷启动/工具调用需要 1-10 分钟，inbound 后立即重启会杀掉进行中的调用。 ba = h.get("bot_activity", {}) - if ba.get("inbound", 0) > 0 and ba.get("outbound", 0) == 0 and ba.get("errors", 0) > 0: + inbound_age = ba.get("last_inbound_age_sec", -1) + outbound_age = ba.get("last_outbound_age_sec", -1) + bot_truly_stuck = ( + inbound_age > 600 # 最后一条用户消息已超过10分钟 + and (outbound_age < 0 or outbound_age > inbound_age - 600) # 且其间没有任何出站 + and ba.get("inbound", 0) > 0 + ) + if bot_truly_stuck: + # cooldown: bot 重启不频繁于10分钟一次 try: - r = _sp.run(["sudo", "-n", "systemctl", "restart", "xmpp-zhiwei"], capture_output=True, timeout=30, text=True) - actions.append({"action": "restart_zhiwei_bot", "target": "xmpp-zhiwei", - "success": r.returncode == 0, "detail": "restarted" if r.returncode == 0 else r.stderr[:100]}) - except Exception as e: - actions.append({"action": "restart_zhiwei_bot", "target": "xmpp-zhiwei", - "success": False, "detail": str(e)[:100]}) + last_bot_restart = 0 + bf = LOG_DIR / "last_bot_restart.txt" + if bf.exists(): + last_bot_restart = float(bf.read_text().strip() or 0) + except Exception: + last_bot_restart = 0 + bot_elapsed = _time.time() - last_bot_restart + if bot_elapsed < 600: + actions.append({"action": "skip_bot_restart", + "reason": f"bot restart cooldown {int(bot_elapsed)}s < 600s"}) + else: + try: + _sp.Popen(["sudo", "-n", "systemctl", "restart", "xmpp-zhiwei"], + stdout=_sp.DEVNULL, stderr=_sp.DEVNULL, start_new_session=True) + (LOG_DIR / "last_bot_restart.txt").write_text(str(_time.time())) + actions.append({"action": "restart_zhiwei_bot", "target": "xmpp-zhiwei", + "success": True, "detail": "restart triggered (async)"}) + except Exception as e: + actions.append({"action": "restart_zhiwei_bot", "target": "xmpp-zhiwei", + "success": False, "detail": str(e)[:100]}) + elif ba.get("inbound", 0) > 0 and ba.get("outbound", 0) == 0 and ba.get("errors", 0) > 0: + # inbound 后仍在处理窗口内（LLM 慢但正常），不动 bot + actions.append({"action": "bot_busy_not_stuck", + "inbound_age_sec": inbound_age, + "reason": "inbound < 10min ago — LLM still processing, no restart"}) # 3. ejabberd → 重启容器 if h.get("ejabberd", "") and "Up" not in str(h["ejabberd"]):