"""好友申请监听器：轮询 fmessage 系统消息，解析后触发自动通过。 独立后台协程，不侵入 MessageStreamer 架构。复用其 mtime 感知 + 复合游标 (create_time, local_id) 增量检测模式，但独立游标与频率控制。 auto_accept 关闭时挂起在 asyncio.Event 上，不轮询 DB。 DB_ENCRYPTED 时 _init_cursor 返回 False，每轮重试初始化。 """ from __future__ import annotations import asyncio import logging import time from dataclasses import dataclass from typing import Optional from woc_bridge.models import AcceptDecision, BridgeError from woc_bridge.models.contact import FriendRequestInfo from woc_bridge.messaging.friend_parser import parse_friend_request logger = logging.getLogger("woc-bridge") class FriendRequestWatcher: """好友申请监听器：轮询 fmessage 系统消息，解析后触发自动通过。""" def __init__( self, db_reader, # DbReader（避免类型注解循环 import） rule_engine, # AcceptRuleEngine send_queue, # SendQueue idem_cache, # IdemCache xdotool_driver, # XdotoolDriver breaker, # CircuitBreaker poll_interval: float = 3.0, cursor_create_time: int = 0, cursor_local_id: int = 0, login_guard=None, # LoginGuard（登录守卫，None 时跳过登录检查） ) -> None: self._db_reader = db_reader self._rule_engine = rule_engine self._send_queue = send_queue self._idem_cache = idem_cache self._xdotool = xdotool_driver self._breaker = breaker self._poll_interval = poll_interval self._login_guard = login_guard # 复合游标 (create_time, local_id)，与 get_friend_requests_since 返回值对齐 self._cursor_create_time: int = cursor_create_time self._cursor_local_id: int = cursor_local_id self._last_db_mtime: float = 0.0 self._last_wal_mtime: float = 0.0 # contact.db 独立 mtime：好友申请可能只写入 contact.db 的 ticket_info， # 不触发 message_0.db 变化，必须单独感知 self._last_contact_db_mtime: float = 0.0 self._last_contact_wal_mtime: float = 0.0 # ticket_info 增量游标：避免每次全量读取历史已通过/残留 ticket self._ticket_cursor_local_id: int = 0 self._ticket_cursor_inited: bool = False self._watcher: Optional[asyncio.Task] = None self._enabled_event: asyncio.Event = asyncio.Event() # auto_accept 开关事件 self._cursor_inited: bool = False # 上轮满载标志：为 True 时跳过 mtime 一级过滤，避免批量积压（>50 条）时 # 剩余批次因 DB mtime 未变被卡住 self._has_more_pending: bool = False self._has_more_ticket_pending: bool = False # 状态统计（供 /api/friends/auto_accept/status 查询） self._processed_count: int = 0 self._accepted_count: int = 0 self._rejected_count: int = 0 self._last_processed_time: Optional[int] = None # 短期去重：同一个 wxid 在 N 秒内不重复入队执行 UI 通过， # 避免已通过但 verify 校验超时/失败时被反复处理导致乱点 self._recent_wxids: dict[str, float] = {} self._recent_wxid_ttl: float = 60.0 @property def is_running(self) -> bool: return self._watcher is not None and not self._watcher.done() @property def is_enabled(self) -> bool: return self._enabled_event.is_set() @property def processed_count(self) -> int: return self._processed_count @property def accepted_count(self) -> int: return self._accepted_count @property def rejected_count(self) -> int: return self._rejected_count @property def last_processed_time(self) -> Optional[int]: return self._last_processed_time @property def cursor_create_time(self) -> int: return self._cursor_create_time @property def cursor_local_id(self) -> int: return self._cursor_local_id async def start(self) -> None: if self._watcher is None or self._watcher.done(): self._watcher = asyncio.create_task(self._watch_loop()) logger.info("FriendRequestWatcher 已启动") async def stop(self) -> None: if self._watcher is not None and not self._watcher.done(): self._watcher.cancel() try: await self._watcher except asyncio.CancelledError: pass self._watcher = None def set_enabled(self, enabled: bool) -> None: if enabled: # 开启时重置游标，避免批量处理积压申请 self._cursor_inited = False self._ticket_cursor_inited = False self._has_more_pending = False self._has_more_ticket_pending = False self._enabled_event.set() else: self._enabled_event.clear() logger.info("FriendRequestWatcher enabled=%s", enabled) async def _init_cursor(self) -> bool: """对齐游标到当前 fmessage 表最大 (create_time, local_id)。 Returns: True 表示已对齐（或 DB 不可读但标记为已初始化，避免无限重试） False 表示异常，下一轮重试 """ try: max_cursor = await asyncio.to_thread( self._db_reader.get_max_create_time_for_talker, "fmessage" ) if max_cursor is None: # DB 不可读（_ensure_decrypted 抛 BridgeError 已被吞掉返回 None） # 不标记 _cursor_inited，下一轮重试 logger.warning("FriendRequestWatcher 游标初始化: DB 不可读，将在下轮重试") return False if isinstance(max_cursor, tuple) and max_cursor[0] > 0: self._cursor_create_time = max_cursor[0] self._cursor_local_id = max_cursor[1] logger.info( "FriendRequestWatcher 游标对齐到 (create_time=%d, local_id=%d)（跳过历史申请）", self._cursor_create_time, self._cursor_local_id, ) # 无论 max_cursor 是否为 (0, 0)（空表），都标记为已初始化，避免空表时无限重试 self._cursor_inited = True return True except Exception as e: logger.warning("FriendRequestWatcher 游标初始化失败: %s", e) return False async def _init_ticket_cursor(self) -> bool: """初始化 ticket_info 增量游标到当前最大 id，跳过历史数据。 Returns: True 表示已初始化；None 时按 0 处理并标记成功。 """ try: max_id = await asyncio.to_thread( self._db_reader.get_max_ticket_info_id ) if max_id is None: logger.warning( "FriendRequestWatcher ticket 游标初始化: DB 不可读，将在下轮重试" ) return False self._ticket_cursor_local_id = max_id self._ticket_cursor_inited = True logger.info( "FriendRequestWatcher ticket 游标对齐到 max_id=%d（跳过历史 ticket）", self._ticket_cursor_local_id, ) return True except Exception as e: logger.warning("FriendRequestWatcher ticket 游标初始化失败: %s", e) return False async def _poll_once(self) -> None: # 1. mtime 感知（一级过滤，避免空 SQL） # 必须同时感知 message_0.db 与 contact.db：微信 4.x Linux 好友申请可能 # 只写入 contact.db 的 ticket_info，不触发 message_0.db 变化。 # 上轮满载时跳过过滤（仍有未读批次），否则会因 DB mtime 未变卡住剩余申请。 msg_changed = False contact_changed = False mtimes = await asyncio.to_thread( self._db_reader.get_db_mtime, "message/message_0.db" ) if mtimes is None: logger.debug("FriendRequestWatcher _poll_once: message_0.db mtime 不可读") else: db_mtime, wal_mtime = mtimes if ( self._has_more_pending or db_mtime != self._last_db_mtime or wal_mtime != self._last_wal_mtime ): msg_changed = True self._last_db_mtime = db_mtime self._last_wal_mtime = wal_mtime mtimes_contact = await asyncio.to_thread( self._db_reader.get_db_mtime, "contact/contact.db" ) if mtimes_contact is None: logger.debug("FriendRequestWatcher _poll_once: contact.db mtime 不可读") else: cdb_mtime, cwal_mtime = mtimes_contact if ( self._has_more_ticket_pending or cdb_mtime != self._last_contact_db_mtime or cwal_mtime != self._last_contact_wal_mtime ): contact_changed = True self._last_contact_db_mtime = cdb_mtime self._last_contact_wal_mtime = cwal_mtime logger.debug( "FriendRequestWatcher _poll_once: 开始轮询 " "cursor=(%d,%d) msg_changed=%s contact_changed=%s " "last_msg_mtime=(%.3f,%.3f) last_contact_mtime=(%.3f,%.3f)", self._cursor_create_time, self._cursor_local_id, msg_changed, contact_changed, self._last_db_mtime, self._last_wal_mtime, self._last_contact_db_mtime, self._last_contact_wal_mtime, ) if not msg_changed and not contact_changed: logger.debug( "FriendRequestWatcher _poll_once: message_0.db/contact.db mtime 均未变化，跳过本次轮询" ) return # 2. 查询 fmessage 分片表增量消息（复合游标） result = await asyncio.to_thread( self._db_reader.get_friend_requests_since, self._cursor_create_time, self._cursor_local_id, 50, # limit ) if result is None: # DB 不可读（_ensure_decrypted 抛 BridgeError） logger.warning( "FriendRequestWatcher _poll_once: get_friend_requests_since 返回 None（DB 不可读）" ) return raw_items: list[dict] = list(result["requests"]) # 2.1 fallback：微信 4.x Linux 好友申请可能仅存于 contact.db 的 ticket_info， # fmessage 表可能为空。额外读取 ticket_info，通过 since_id 游标跳过历史数据。 ticket_items = await asyncio.to_thread( self._db_reader.get_pending_requests_from_ticket_info, 50, self._ticket_cursor_local_id, ) if ticket_items: logger.info( "FriendRequestWatcher _poll_once: 从 ticket_info 读到 %d 条新申请 " "(since_id=%d)", len(ticket_items), self._ticket_cursor_local_id, ) raw_items.extend(ticket_items) # 推进 ticket_info 游标到本批最大 id max_ticket_id = max(item["local_id"] for item in ticket_items) if max_ticket_id > self._ticket_cursor_local_id: self._ticket_cursor_local_id = max_ticket_id self._has_more_ticket_pending = len(ticket_items) >= 50 logger.info( "FriendRequestWatcher _poll_once: 本轮检测到 %d 条原始申请 " "(cursor=%d,%d → next=%d,%d)", len(raw_items), self._cursor_create_time, self._cursor_local_id, result["next_create_time"], result["next_local_id"], ) # 3. 解析 XML + 逐条处理 parsed_count = 0 for item in raw_items: info = parse_friend_request( item["content"], item["create_time"], item["local_id"] ) if info is None: # 非 verifyUser 类型或解析失败，记录日志便于排查 logger.debug( "FriendRequestWatcher: 解析失败或非 verifyUser，content=%s", repr(item["content"][:200]) if item.get("content") else "", ) continue parsed_count += 1 logger.info( "FriendRequestWatcher: 解析到申请 wxid=%s nickname=%s scene=%s", info.stranger_wxid, info.nickname, info.scene, ) await self._handle_request(info) # 4. 推进复合游标（仅由 fmessage 结果决定；ticket_info 无时间戳，不参与游标） self._cursor_create_time = result["next_create_time"] self._cursor_local_id = result["next_local_id"] # 5. 满载标志：仅由 fmessage 本批是否达 limit 决定 self._has_more_pending = len(result["requests"]) >= 50 logger.debug( "FriendRequestWatcher _poll_once: 解析成功 %d/%d 条，满载=%s", parsed_count, len(raw_items), self._has_more_pending, ) async def _watch_loop(self) -> None: while True: try: # auto_accept 关闭时挂起，避免空轮询 await self._enabled_event.wait() # 登录守卫：微信未登录时跳过轮询，不推进游标 # 登录后自然从上次游标位置重新读取，DB 中积累的申请不丢失 if self._login_guard is not None and not self._login_guard.is_logged_in: logger.info( "FriendRequestWatcher: 微信未登录 (state=%s)，暂停轮询等待登录恢复", self._login_guard.current_state, ) # 等待登录恢复，带超时避免紧密循环 # 超时后 continue 回到 while 顶部重新检查状态 await self._login_guard.wait_for_login( timeout=self._poll_interval ) continue # 游标未初始化时先对齐（DB 恢复可读后自动补齐） # DB_ENCRYPTED 时 _init_cursor 返回 False，下一轮仍会重试 if not self._cursor_inited: await self._init_cursor() if not self._cursor_inited: # DB 仍不可读，本轮跳过 _poll_once await asyncio.sleep(self._poll_interval) continue # fmessage 游标初始化成功后，再初始化 ticket_info 游标 if not self._ticket_cursor_inited: await self._init_ticket_cursor() if not self._ticket_cursor_inited: await asyncio.sleep(self._poll_interval) continue await asyncio.sleep(self._poll_interval) await self._poll_once() except asyncio.CancelledError: raise except Exception as e: logger.exception("FriendRequestWatcher 异常: %s", e) await asyncio.sleep(5.0) async def _verify_with_retry(self, stranger_wxid: str) -> bool: """UI 操作完成后轮询 DB 校验好友是否已通过。 先等待 1.5s 让微信刷盘，之后每隔 1s 查询一次，最多 10s。 期间任一次校验成功即返回 True；DB 异常视为未通过并继续重试。 """ await asyncio.sleep(1.5) deadline = time.monotonic() + 10.0 attempt = 0 while time.monotonic() < deadline: attempt += 1 try: verified = await asyncio.to_thread( self._db_reader.verify_friend_accepted, stranger_wxid ) logger.info( "FriendRequestWatcher: verify 尝试 #%d (wxid=%s) → verified=%s", attempt, stranger_wxid, verified, ) if verified: return True except Exception as exc: logger.warning( "FriendRequestWatcher: verify_friend_accepted 异常 #%d (wxid=%s): %s", attempt, stranger_wxid, exc, ) await asyncio.sleep(1.0) logger.warning( "FriendRequestWatcher: verify 超时 (wxid=%s, 尝试 %d 次)", stranger_wxid, attempt, ) return False async def _handle_request(self, req: FriendRequestInfo) -> None: self._processed_count += 1 self._last_processed_time = req.create_time # 步骤 1：收到申请，打印原始信息 logger.info( "[自动通过][步骤1/8] 收到好友申请 wxid=%s nickname=%s scene=%s verify=%s", req.stranger_wxid, req.nickname, req.scene, repr(req.verify_message[:80]) if req.verify_message else "", ) # 步骤 2：规则引擎决策 logger.info("[自动通过][步骤2/8] 进入规则引擎评估 wxid=%s", req.stranger_wxid) decision = await self._rule_engine.evaluate(req) if decision == AcceptDecision.REJECT: self._rejected_count += 1 logger.info( "[自动通过][步骤2/8] 决策结果=REJECT（拒绝），处理结束 wxid=%s", req.stranger_wxid, ) return if decision != AcceptDecision.ACCEPT: logger.info( "[自动通过][步骤2/8] 决策结果=SKIP（跳过），处理结束 wxid=%s，" "原因：未命中任何通过规则（accept_all=false、无白名单/关键词匹配）", req.stranger_wxid, ) return logger.info( "[自动通过][步骤2/8] 决策结果=ACCEPT（允许通过） wxid=%s", req.stranger_wxid, ) # 步骤 2.5：前置 DB 检查，避免已经通过的好友被重复执行 UI logger.info("[自动通过][步骤2.5/8] 前置校验是否已是好友 wxid=%s", req.stranger_wxid) try: already_accepted = await asyncio.to_thread( self._db_reader.verify_friend_accepted, req.stranger_wxid ) except Exception as exc: logger.warning( "[自动通过][步骤2.5/8] verify_friend_accepted 异常，按未通过继续 wxid=%s: %s", req.stranger_wxid, exc, ) already_accepted = False if already_accepted: self._idem_cache.set( "friend_accept", req.stranger_wxid, "", {"success": True, "verified": True, "pre_check": True}, "", ) self._accepted_count += 1 logger.info( "[自动通过][步骤2.5/8] 已是好友，跳过 UI 操作并写入幂等缓存 wxid=%s", req.stranger_wxid, ) return logger.info("[自动通过][步骤2.5/8] 尚未通过，继续执行 UI wxid=%s", req.stranger_wxid) # 步骤 3：幂等去重（TTL=300s，5 分钟内不重复处理同一申请人） logger.info("[自动通过][步骤3/8] 检查幂等缓存 wxid=%s", req.stranger_wxid) cached = self._idem_cache.get( "friend_accept", req.stranger_wxid, "", "" ) if cached is not None: logger.info( "[自动通过][步骤3/8] 幂等命中，跳过 wxid=%s (cached=%s)", req.stranger_wxid, cached, ) return # 步骤 3.5：短期去重，避免 verify 超时/失败后在短时间内重复入队乱点 now = time.monotonic() last_at = self._recent_wxids.get(req.stranger_wxid) if last_at is not None and now - last_at < self._recent_wxid_ttl: logger.info( "[自动通过][步骤3.5/8] %.0fs 内已处理过，跳过 wxid=%s", self._recent_wxid_ttl, req.stranger_wxid, ) return logger.info("[自动通过][步骤3/8] 幂等未命中，继续处理 wxid=%s", req.stranger_wxid) # 步骤 4：熔断检查 logger.info("[自动通过][步骤4/8] 检查熔断器 wxid=%s", req.stranger_wxid) breaker_allowed = self._breaker.allow() breaker_state = self._breaker.state.value logger.info( "[自动通过][步骤4/8] 熔断器状态 allow=%s state=%s wxid=%s", breaker_allowed, breaker_state, req.stranger_wxid, ) if not breaker_allowed: logger.warning( "[自动通过][步骤4/8] 熔断器 OPEN，跳过 wxid=%s", req.stranger_wxid, ) return # 步骤 5/6：入队执行 UI 通过 logger.info( "[自动通过][步骤5/8] 准备入队执行 UI 通过 wxid=%s", req.stranger_wxid, ) # 记录本次处理时间，用于短期去重（即使后续 verify 失败也不立即重试） self._recent_wxids[req.stranger_wxid] = time.monotonic() try: result = await self._send_queue.enqueue( lambda req=req: self._xdotool.accept_friend_request( stranger_wxid=req.stranger_wxid, nickname=req.nickname, ), delay_ms=None, # 使用 send_queue 默认间隔 ) logger.info( "[自动通过][步骤6/8] UI 操作完成 result=%s，开始 DB 校验 wxid=%s", result, req.stranger_wxid, ) # 步骤 7：等待微信 DB WAL 刷盘后校验 verified = await self._verify_with_retry(req.stranger_wxid) # 步骤 8：结果处理 if verified: # 只有真正通过并验证成功才写幂等缓存，避免坐标不准等临时失败 # 导致该申请人 5 分钟内无法再次处理 self._idem_cache.set( "friend_accept", req.stranger_wxid, "", {"success": True, "verified": True}, "", ) self._breaker.record_success() self._accepted_count += 1 logger.info( "[自动通过][步骤8/8] 通过并验证成功 wxid=%s nickname=%s", req.stranger_wxid, req.nickname, ) else: # UI 操作完成但 DB 校验未通过（可能有延迟），不写入幂等缓存， # 下轮仍可尝试；仅记录熔断器失败。 self._breaker.record_failure() logger.warning( "[自动通过][步骤8/8] UI 操作完成但 DB 校验未通过，" "不写入幂等缓存，允许下轮重试 wxid=%s", req.stranger_wxid, ) except BridgeError as e: # 透传 BridgeError 错误码（RATE_LIMITED / SEND_FAILED / WINDOW_NOT_FOUND 等） self._breaker.record_failure() logger.error( "[自动通过][步骤6/8] BridgeError code=%s: %s wxid=%s", getattr(e, "code", "UNKNOWN"), e, req.stranger_wxid, ) except Exception as e: self._breaker.record_failure() logger.error( "[自动通过][步骤6/8] 异常: %s wxid=%s", e, req.stranger_wxid, )