chore: instrumentation [REPLAY] pour diagnostic chaîne replay

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) <noreply@anthropic.com>
This commit is contained in:
Dom
2026-04-10 22:07:56 +02:00
parent b92cb9db03
commit f82753debe
2 changed files with 84 additions and 4 deletions

View File

@@ -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