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) # ===================================================================