From f82753debe327b1617ca9a0fb08a3c085429a301 Mon Sep 17 00:00:00 2001 From: Dom Date: Fri, 10 Apr 2026 22:07:56 +0200 Subject: [PATCH] =?UTF-8?q?chore:=20instrumentation=20[REPLAY]=20pour=20di?= =?UTF-8?q?agnostic=20cha=C3=AEne=20replay?= MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Ajoute 6 points de log structurés homogénéisés avec le préfixe [REPLAY] aux endroits clés de la chaîne de replay, pour permettre de suivre précisément ce qui se passe pendant un test humain et diagnostiquer les points de rupture sans déduire à l'aveugle. Points de log : 1. DISPATCH — /replay/next envoie une action (expected_before/after, resolve_order, has_uia, has_anchor, by_text, strict) 2. RESOLVE_ENTRY — _resolve_target_sync reçoit la demande (window_title, uia_target, anchor, strict_mode) 3. RESOLVE_EXIT — résolution terminée (method, coords, score, from_memory) 4. RESOLVE_EXCEPTION — crash rare dans la résolution 5. REPORT — /replay/result reçoit le rapport agent (success, error, warning, resolution_method, actual_position) 6. VERIFY — décision finale post-vérification (agent_success, ver_verified, sem_verified, final_success) Usage : journalctl --user -u rpa-streaming -f | grep REPLAY Aucune modif de logique, uniquement des logger.info() aux points de décision critiques. 56 tests E2E + Phase0 restent verts. Ces logs sont là pour stabiliser la chaîne après les modifications robustesse du matin (strict control, UIA strict, filtre UIA-aware) qui ont cassé les replays réels de Dom et ne se voient pas dans les tests automatisés in silico. Co-Authored-By: Claude Opus 4.6 (1M context) --- agent_v0/server_v1/api_stream.py | 73 ++++++++++++++++++++++++++-- agent_v0/server_v1/resolve_engine.py | 15 ++++++ 2 files changed, 84 insertions(+), 4 deletions(-) diff --git a/agent_v0/server_v1/api_stream.py b/agent_v0/server_v1/api_stream.py index 71589f14c..c3a34e52c 100644 --- a/agent_v0/server_v1/api_stream.py +++ b/agent_v0/server_v1/api_stream.py @@ -2808,10 +2808,34 @@ async def get_next_action(session_id: str, machine_id: str = "default"): "replay_id": "", } + # [REPLAY] log structuré pour suivre une action à travers toute la chaîne + # Grep facile : journalctl --user -u rpa-streaming -f | grep REPLAY + _rid = owning_replay.get("replay_id", "?") if owning_replay else "?" + _tspec = action.get("target_spec") or {} + _expected_before = ( + action.get("expected_window_before", "") + or _tspec.get("window_title", "") + ) + _expected_after = action.get("expected_window_title", "") + _resolve_order = _tspec.get("resolve_order") or [] + _by_text = _tspec.get("by_text", "") + _vlm_desc = _tspec.get("vlm_description", "") + _has_uia = bool(_tspec.get("uia_target")) + _has_anchor = bool(_tspec.get("anchor_image_base64")) + _precheck_sim = ( + f" precheck_sim={precheck_result['similarity']:.3f}" + if precheck_result else "" + ) + _intent_log = (action.get("intention", "") or "")[:50] logger.info( - f"Action envoyée à {session_id} (machine={machine_id}) : " - f"{action.get('type')} (id={action.get('action_id')})" - f"{' [precheck OK sim=' + str(precheck_result['similarity']) + ']' if precheck_result else ''}" + f"[REPLAY] DISPATCH replay={_rid} session={session_id} machine={machine_id} " + f"action_id={action.get('action_id')} type={action.get('type')} " + f"intent='{_intent_log}' " + f"expected_before='{_expected_before}' expected_after='{_expected_after}' " + f"resolve_order={_resolve_order} has_uia={_has_uia} has_anchor={_has_anchor} " + f"by_text='{_by_text[:40]}' vlm_desc='{_vlm_desc[:40]}' " + f"strict={bool(action.get('success_strict'))}" + f"{_precheck_sim}" ) response: Dict[str, Any] = { @@ -2841,6 +2865,19 @@ async def report_action_result(report: ReplayResultReport): session_id = report.session_id action_id = report.action_id + # [REPLAY] log structuré d'arrivée du rapport agent + _pos_log = report.actual_position or {} + _x_log = _pos_log.get("x_pct", "?") if isinstance(_pos_log, dict) else "?" + _y_log = _pos_log.get("y_pct", "?") if isinstance(_pos_log, dict) else "?" + logger.info( + f"[REPLAY] REPORT action_id={action_id} session={session_id} " + f"success={report.success} error='{(report.error or '')[:80]}' " + f"warning='{report.warning or ''}' " + f"resolution_method='{report.resolution_method or '?'}' " + f"resolution_score={report.resolution_score or 0} " + f"actual_position=({_x_log}, {_y_log})" + ) + # Trouver le replay correspondant à cette session with _replay_lock: replay_state = None @@ -2949,6 +2986,24 @@ async def report_action_result(report: ReplayResultReport): with _replay_lock: replay_state["_last_screenshot_before"] = screenshot_after + # [REPLAY] log structuré de la décision de vérification + _ver_verified = verification.verified if verification else None + _ver_detail = verification.detail[:100] if verification and verification.detail else "" + _ver_sem = verification.semantic_verified if verification else None + _ver_sem_detail = ( + verification.semantic_detail[:100] + if verification and hasattr(verification, "semantic_detail") and verification.semantic_detail + else "" + ) + _final_success = report.success and (verification is None or verification.verified) + logger.info( + f"[REPLAY] VERIFY action_id={action_id} session={session_id} " + f"agent_success={report.success} " + f"ver_verified={_ver_verified} ver_detail='{_ver_detail}' " + f"sem_verified={_ver_sem} sem_detail='{_ver_sem_detail}' " + f"final_success={_final_success}" + ) + # === Enregistrer le résultat === with _replay_lock: result_entry = { @@ -3515,9 +3570,19 @@ async def resolve_target(request: ResolveTargetRequest): request.strict_mode, processor, ) + # [REPLAY] log structuré de sortie résolution + logger.info( + f"[REPLAY] RESOLVE_EXIT session={request.session_id} " + f"resolved={result.get('resolved', False) if result else False} " + f"method='{result.get('method', '?') if result else 'none'}' " + f"coords=({result.get('x_pct', 0):.4f}, {result.get('y_pct', 0):.4f}) " + f"score={result.get('score', 0) if result else 0} " + f"from_memory={bool(result.get('from_memory', False)) if result else False} " + f"reason='{result.get('reason', '') if result else ''}'" + ) return result except Exception as e: - logger.error(f"Résolution visuelle échouée: {e}") + logger.error(f"[REPLAY] RESOLVE_EXCEPTION session={request.session_id} error={e}") return _fallback_response(request, "analysis_error", str(e)) finally: import os diff --git a/agent_v0/server_v1/resolve_engine.py b/agent_v0/server_v1/resolve_engine.py index ffe884962..e15cab95e 100644 --- a/agent_v0/server_v1/resolve_engine.py +++ b/agent_v0/server_v1/resolve_engine.py @@ -1558,6 +1558,21 @@ def _resolve_target_sync( """ anchor_image_b64 = target_spec.get("anchor_image_base64", "") + # [REPLAY] log structuré d'entrée résolution + _window_title_log = target_spec.get("window_title", "") or "" + _resolve_order_log = target_spec.get("resolve_order") or [] + _uia_target_log = target_spec.get("uia_target") or {} + _by_text_log = target_spec.get("by_text", "") + _vlm_desc_log = target_spec.get("vlm_description", "") + logger.info( + f"[REPLAY] RESOLVE_ENTRY window='{_window_title_log}' " + f"resolve_order={_resolve_order_log} " + f"has_uia={bool(_uia_target_log)} uia_name='{_uia_target_log.get('name','')[:40]}' " + f"has_anchor={bool(anchor_image_b64)} " + f"by_text='{_by_text_log[:40]}' vlm_desc='{_vlm_desc_log[:40]}' " + f"strict_mode={strict_mode} screen={screen_width}x{screen_height}" + ) + # =================================================================== # PHASE 1 APPRENTISSAGE : Lookup mémoire persistante (Fiche #18) # ===================================================================