From 7379b642170017c24e2f91db0263b51af955449e Mon Sep 17 00:00:00 2001 From: =?UTF-8?q?=E9=98=BF=E7=94=B7?= Date: Sun, 26 Apr 2026 23:42:03 +0800 Subject: [PATCH] htyproc: add detailed tracing to AI_SCORE pipeline --- htyproc/src/tasks/pipelines.rs | 13 +++++++++++-- 1 file changed, 11 insertions(+), 2 deletions(-) diff --git a/htyproc/src/tasks/pipelines.rs b/htyproc/src/tasks/pipelines.rs index efd1373..d2cee90 100644 --- a/htyproc/src/tasks/pipelines.rs +++ b/htyproc/src/tasks/pipelines.rs @@ -312,6 +312,7 @@ pub(crate) async fn execute_ai_score_pipeline( let task_type = req.task_type.ok_or_else(|| anyhow::anyhow!("missing task_type"))?; let base = rt.ai_url.trim_end_matches('/'); let compare_url = format!("{base}/api/v1/ai/compare"); + tracing::debug!("AI_SCORE -> POST AI compare, url={compare_url}"); let resp = rt .http .post(&compare_url) @@ -327,12 +328,14 @@ pub(crate) async fn execute_ai_score_pipeline( .task_id .clone() .ok_or_else(|| anyhow::anyhow!("compare: missing ai task_id"))?; + tracing::debug!("AI_SCORE -> AI compare ok, ai_task_id={compare_ai_task_id:?}"); let ts_task = wrap_ts_common_task(req); let ai_task = wrap_common_task(&compare_result, task_type.as_db_str()); let mut req_score = build_req_score(payload, &ts_task, &ai_task, None); let ws_base = rt.htyws_url.trim_end_matches('/'); let create_url = format!("{ws_base}/api/v1/ws/create_score"); + tracing::debug!("AI_SCORE -> POST create_score, url={create_url}"); let cs_resp = rt .http .post(&create_url) @@ -345,6 +348,7 @@ pub(crate) async fn execute_ai_score_pipeline( let score_d = parse_hty_response(cs_resp).await?; let score_id = json_value_as_string(&score_d) .ok_or_else(|| anyhow::anyhow!("create_score: expected string id in d"))?; + tracing::debug!("AI_SCORE -> create_score ok, score_id={score_id}"); if let Some(obj) = req_score.as_object_mut() { obj.insert("id".to_string(), json!(score_id.clone())); } @@ -356,7 +360,9 @@ pub(crate) async fn execute_ai_score_pipeline( let updated = poll_ai_once(rt, sudo, host, &compare_ai_task_id).await?; let status = updated.task_status.as_deref().unwrap_or(""); + tracing::debug!("AI_SCORE -> poll ai_task_id={compare_ai_task_id} retry={retry} status={status}"); if status == AI_STATUS_FAILED { + tracing::error!("AI_SCORE -> AI returned FAILED, ai_task_id={compare_ai_task_id} result={:?}", updated.task_result); let ts_t = wrap_ts_common_task(req); let ai_t = wrap_common_task(&updated, task_type.as_db_str()); let fail_score = build_req_score(payload, &ts_t, &ai_t, Some(&score_id)); @@ -370,9 +376,10 @@ pub(crate) async fn execute_ai_score_pipeline( .json(&fail_score) .send() .await?; - anyhow::bail!("AI scoring FAILED"); + anyhow::bail!("AI scoring FAILED for ai_task_id={compare_ai_task_id}"); } if status == AI_STATUS_SUCCESS { + tracing::debug!("AI_SCORE -> AI returned SUCCESS, ai_task_id={compare_ai_task_id}"); payload.task_result = Some(updated.clone()); let ts_t = wrap_ts_common_task(req); let ai_t = wrap_common_task(&updated, task_type.as_db_str()); @@ -389,10 +396,12 @@ pub(crate) async fn execute_ai_score_pipeline( .send() .await?; let _ = parse_hty_response(upd_resp).await?; + tracing::debug!("AI_SCORE -> update_score ok, score_id={score_id}"); return Ok(()); } retry += 1; if retry >= max_retry { + tracing::error!("AI_SCORE -> max retries exceeded, ai_task_id={compare_ai_task_id}"); let ts_t = wrap_ts_common_task(req); let ai_t = wrap_common_task(&updated, task_type.as_db_str()); let timeout_score = build_req_score(payload, &ts_t, &ai_t, Some(&score_id)); @@ -406,7 +415,7 @@ pub(crate) async fn execute_ai_score_pipeline( .json(&timeout_score) .send() .await?; - anyhow::bail!("AI task exceeded max retries"); + anyhow::bail!("AI task exceeded max retries, ai_task_id={compare_ai_task_id}"); } } }