feat: add diagnostic logs for generation flows

This commit is contained in:
chengma
2026-06-29 17:49:45 +08:00
parent 588b352eac
commit cd1256bc5e
17 changed files with 1455 additions and 104 deletions
+268 -2
View File
@@ -1,3 +1,4 @@
import json
import unittest
import os
import sys
@@ -624,8 +625,18 @@ class GuiTests(TempDirMixin, unittest.TestCase):
self.assertEqual({"title": "标题提示", "cover": "封面提示"}, prompt_values)
self.assertEqual(account, ai_cfg["account_by_alias"]["alias-a"])
self.assertEqual(cfg["db_path"], ai_cfg["db_path"])
self.assertIn("on_event", ai_cfg)
self.assertIn("on_error", ai_cfg)
self.assertFalse(should_stop())
on_progress({"total": 1, "title_done": 1, "cover_done": 0, "failed": 0})
ai_cfg["on_event"](
{
"task": tasks[0],
"phase": "cover",
"step": "cover_request",
"result": "start",
}
)
ai_cfg["on_task_update"](tasks[0].id, {"stage": "generated"})
return {"ok": True, "total": 1, "title_done": 1, "cover_done": 1, "failed": 0}
@@ -642,8 +653,117 @@ class GuiTests(TempDirMixin, unittest.TestCase):
summary = worker.execute()
self.assertEqual(1, summary["cover_done"])
self.assertIsInstance(summary["run_id"], int)
self.assertEqual([batch_id], summary["batch_ids"])
self.assertEqual([{"total": 1, "title_done": 1, "cover_done": 0, "failed": 0}], progress)
self.assertEqual([(tasks[0].id, {"stage": "generated"})], rows)
run_log = db.list_run_logs(limit=1, run_type="generate", path=cfg["db_path"])[0]
self.assertEqual(summary["run_id"], run_log.id)
events = db.list_run_log_events(summary["run_id"], path=cfg["db_path"])
self.assertTrue(any("phase=cover step=cover_request result=start" in event.message for event in events))
self.assert_removed(temp_dir)
def test_generate_worker_writes_run_log_and_diagnostic_log_on_image_failure(self):
with self.make_temp_dir() as temp_dir:
cfg = self.make_config(temp_dir)
accounts.create_account("主店", "alias-a", debug_port=9222, config=cfg)
batch_id = db.create_batch(["input.xlsx"], path=cfg["db_path"])
db.insert_tasks(
batch_id,
[
{
"source_file_abs": os.path.join(temp_dir, "input.xlsx"),
"source_sheet": "商品",
"source_row": 2,
"account_name": "Excel主店",
"alias": "alias-a",
"item_id": "51100639510",
}
],
path=cfg["db_path"],
)
task = db.list_tasks(batch_id=batch_id, path=cfg["db_path"])[0]
old_cover = os.path.join(temp_dir, "old.jpg")
with open(old_cover, "wb") as fh:
fh.write(b"jpeg")
db.set_collected(task.id, "旧标题", old_cover, path=cfg["db_path"])
tasks = db.list_tasks(batch_id=batch_id, path=cfg["db_path"])
diagnostic_log_dir = os.path.join(temp_dir, "logs")
def fake_title(title_prompt, old_title, **kwargs):
callback = kwargs.get("on_step")
if callback:
callback("title_request")
return "新标题"
def fake_cover(cover_prompt, old_cover_path, out_path, **kwargs):
callback = kwargs.get("on_step")
if callback:
callback("cover_request")
raise RuntimeError("图片生成失败 token=SECRET-TOKEN")
with mock.patch("app.ai.gen_title", side_effect=fake_title), \
mock.patch("app.ai.gen_cover", side_effect=fake_cover):
summary = GenerateWorker(
tasks,
{"title": "标题提示", "cover": "封面提示"},
db_path=cfg["db_path"],
config=cfg,
diagnostic_log_dir=diagnostic_log_dir,
).execute()
self.assertFalse(summary["ok"])
self.assertEqual(1, summary["title_done"])
self.assertEqual(0, summary["cover_done"])
self.assertEqual(1, summary["failed"])
failed_task = db.list_tasks(batch_id=batch_id, path=cfg["db_path"])[0]
self.assertEqual("failed", failed_task.status)
self.assertIn("图片生成失败", failed_task.last_error)
self.assertNotIn("SECRET-TOKEN", failed_task.last_error)
events = db.list_run_log_events(summary["run_id"], path=cfg["db_path"])
messages = "\n".join(event.message for event in events)
self.assertIn("phase=cover step=cover_request result=failed", messages)
self.assertIn("token=***", messages)
self.assertNotIn("SECRET-TOKEN", messages)
log_path = os.path.join(diagnostic_log_dir, "cmshopee.log")
self.assertTrue(os.path.exists(log_path))
with open(log_path, "r", encoding="utf-8") as fh:
raw_log = fh.read()
self.assertIn("cover_request", raw_log)
self.assertIn("AI生成任务失败", raw_log)
self.assertIn("token=***", raw_log)
self.assertNotIn("SECRET-TOKEN", raw_log)
self.assert_removed(temp_dir)
def test_generate_tab_loads_latest_generate_run_log(self):
with self.make_temp_dir() as temp_dir:
cfg = self.make_config(temp_dir)
db.init_db(cfg["db_path"])
run_id = db.create_run_log("generate", total=1, path=cfg["db_path"])
db.add_run_log_event(
run_id,
"phase=cover step=cover_request result=failed detail=图片生成失败",
level="error",
path=cfg["db_path"],
)
db.finish_run_log(
run_id,
status="done",
done=1,
failed_count=1,
summary_json={"failed": 1},
path=cfg["db_path"],
)
tab = GenerateTab(config=cfg)
self.addCleanup(tab.close)
self.assertEqual("generateRunLogView", tab.run_log_view.objectName())
self.assertIn("phase=cover step=cover_request result=failed", tab.run_log_view.toPlainText())
self.assert_removed(temp_dir)
@@ -725,6 +845,7 @@ class GuiTests(TempDirMixin, unittest.TestCase):
self.assertIsInstance(tab.task_table, QTableView)
self.assertEqual(["店铺", "商品ID", "新标题", "新封面", "阶段", "结果"], tab.model.HEADERS)
self.assertEqual("开始更新", tab.start_update_button.text())
self.assertEqual("applyItemFilter", tab.item_filter.objectName())
self.assertEqual("停止", tab.stop_update_button.text())
self.assertFalse(tab.stop_update_button.isEnabled())
self.assertEqual(2, tab.model.rowCount())
@@ -756,6 +877,17 @@ class GuiTests(TempDirMixin, unittest.TestCase):
self.assertEqual("已更新", tab.model.index(0, 4).data())
self.assertEqual("成功", tab.model.index(0, 5).data())
tab.batch_filter.setCurrentIndex(tab.batch_filter.findData(None))
tab.status_filter.setCurrentIndex(tab.status_filter.findData("all"))
tab.item_filter.setText("51100639512")
self.assertEqual(1, tab.model.rowCount())
self.assertEqual("51100639512", tab.model.index(0, 1).data())
self.assertEqual("任务 1/4 条", tab.summary_label.text())
self.assertIn(
"商品ID:51100639512",
tab._confirmation_message(list(tab.model.tasks)),
)
self.assert_removed(temp_dir)
def test_apply_tab_start_update_requires_confirmation_before_starting_worker(self):
@@ -784,6 +916,7 @@ class GuiTests(TempDirMixin, unittest.TestCase):
statuses = []
tab = ApplyTab(config=cfg, status_callback=statuses.append)
self.addCleanup(tab.close)
tab.item_filter.setText("51100639510")
with mock.patch(
"app.gui.QMessageBox.question",
@@ -795,6 +928,7 @@ class GuiTests(TempDirMixin, unittest.TestCase):
self.assertIn("任务数:1", message)
self.assertIn("提交线上", message)
self.assertIn("状态:已生成", message)
self.assertIn("商品ID:51100639510", message)
self.assertIn("测试商品ID=51100639510", message)
self.assertEqual("已取消开始更新", statuses[-1])
apply_task.assert_not_called()
@@ -960,6 +1094,7 @@ class GuiTests(TempDirMixin, unittest.TestCase):
statuses = []
tab = ApplyTab(config=cfg, status_callback=statuses.append)
self.addCleanup(tab.close)
tab.item_filter.setText("51100639510")
with mock.patch("app.gui.QMessageBox.warning") as warning, \
mock.patch("app.gui.QMessageBox.question") as question, \
@@ -1560,6 +1695,7 @@ class GuiTests(TempDirMixin, unittest.TestCase):
tab = GenerateTab(config=cfg)
self.addCleanup(tab.close)
self.assertEqual("generateItemFilter", tab.item_filter.objectName())
self.assertEqual(4, tab.model.rowCount())
self.assertEqual("主店", tab.model.index(0, 0).data())
self.assertEqual("51100639510", tab.model.index(0, 1).data())
@@ -1586,6 +1722,13 @@ class GuiTests(TempDirMixin, unittest.TestCase):
tab.model.data(tab.model.index(0, 0), gui.Qt.ToolTipRole),
)
tab.batch_filter.setCurrentIndex(tab.batch_filter.findData(None))
tab.status_filter.setCurrentIndex(tab.status_filter.findData("all"))
tab.item_filter.setText("639512")
self.assertEqual(1, tab.model.rowCount())
self.assertEqual("51100639512", tab.model.index(0, 1).data())
self.assertEqual("任务 1/4 条", tab.summary_label.text())
self.assert_removed(temp_dir)
def test_tab_switch_updates_status_bar(self):
@@ -1924,12 +2067,14 @@ class GuiTests(TempDirMixin, unittest.TestCase):
return {"logged_in": False, "reason": "LOGIN_PAGE"}
raise AssertionError(account.alias)
def fake_collect(account, task):
def fake_collect(account, task, on_step=None):
self.assertEqual(logged.alias, account.alias)
self.assertEqual("51100639510", task["item_id"])
self.assertTrue(task["old_cover_path"].endswith(
os.path.join(logged.slug, "51100639510_old.jpg")
))
self.assertTrue(callable(on_step))
on_step("download_cover")
return {
"old_title": "旧标题",
"old_cover_path": task["old_cover_path"],
@@ -1944,7 +2089,14 @@ class GuiTests(TempDirMixin, unittest.TestCase):
preflight=False,
).execute()
self.assertEqual({"ok": True, "total": 3, "done": 3, "collected": 1, "skipped": 2, "failed": 0}, summary)
self.assertTrue(summary["ok"])
self.assertEqual(3, summary["total"])
self.assertEqual(3, summary["done"])
self.assertEqual(1, summary["collected"])
self.assertEqual(2, summary["skipped"])
self.assertEqual(0, summary["failed"])
self.assertEqual([batch_id], summary["batch_ids"])
self.assertIsInstance(summary["run_id"], int)
collect.assert_called_once()
updated = db.list_tasks(batch_id=batch_id, path=cfg["db_path"])
by_alias = {task.alias: task for task in updated}
@@ -1958,6 +2110,120 @@ class GuiTests(TempDirMixin, unittest.TestCase):
self.assertEqual("skipped", by_alias["missing"].status)
self.assertEqual("别名未匹配账号", by_alias["missing"].last_error)
run_logs = db.list_run_logs(limit=1, run_type="collect", path=cfg["db_path"])
self.assertEqual(summary["run_id"], run_logs[0].id)
self.assertEqual("done", run_logs[0].status)
self.assertEqual(3, run_logs[0].done)
self.assertEqual(1, run_logs[0].success_count)
self.assertEqual(2, run_logs[0].skipped_count)
events = db.list_run_log_events(summary["run_id"], path=cfg["db_path"])
messages = [event.message for event in events]
self.assertTrue(any("step=download_cover result=start" in item for item in messages))
self.assertTrue(any("别名未匹配账号" in item for item in messages))
self.assert_removed(temp_dir)
def test_collect_worker_writes_run_log_and_diagnostic_log_on_failure(self):
with self.make_temp_dir() as temp_dir:
cfg = self.make_config(temp_dir)
logged = accounts.create_account("主店", "alias-a", debug_port=9222, config=cfg)
batch_id = db.create_batch(["input.xlsx"], path=cfg["db_path"])
db.insert_tasks(
batch_id,
[
{
"source_file_abs": os.path.join(temp_dir, "input.xlsx"),
"source_sheet": "商品",
"source_row": 2,
"account_name": "Excel主店",
"alias": "alias-a",
"item_id": "51100639510",
}
],
path=cfg["db_path"],
)
tasks = db.list_tasks(batch_id=batch_id, path=cfg["db_path"])
diagnostic_log_dir = os.path.join(temp_dir, "logs")
def fake_login(account, path=None, config=None):
self.assertEqual(logged.alias, account.alias)
return {"logged_in": True, "reason": None}
def fake_collect(account, task, on_step=None):
on_step("wait_ready")
raise RuntimeError("页面未就绪 token=SECRET-TOKEN")
with mock.patch("app.gui.accounts.detect_login", side_effect=fake_login), \
mock.patch("app.gui.editor.collect", side_effect=fake_collect):
summary = CollectWorker(
tasks,
db_path=cfg["db_path"],
config=cfg,
preflight=False,
diagnostic_log_dir=diagnostic_log_dir,
).execute()
self.assertFalse(summary["ok"])
self.assertEqual(1, summary["failed"])
self.assertIsInstance(summary["run_id"], int)
failed_task = db.list_tasks(batch_id=batch_id, path=cfg["db_path"])[0]
self.assertEqual("failed", failed_task.status)
self.assertIn("页面未就绪", failed_task.last_error)
self.assertNotIn("SECRET-TOKEN", failed_task.last_error)
run_log = db.list_run_logs(limit=1, run_type="collect", path=cfg["db_path"])[0]
self.assertEqual(summary["run_id"], run_log.id)
self.assertEqual("done", run_log.status)
self.assertEqual(1, run_log.failed_count)
events = db.list_run_log_events(summary["run_id"], path=cfg["db_path"])
messages = [event.message for event in events]
joined_messages = "\n".join(messages)
self.assertTrue(any("step=wait_ready result=failed" in item for item in messages))
self.assertTrue(any("页面未就绪" in item for item in messages))
self.assertNotIn("SECRET-TOKEN", joined_messages)
self.assertIn("token=***", joined_messages)
log_path = os.path.join(diagnostic_log_dir, "cmshopee.log")
self.assertTrue(os.path.exists(log_path))
with open(log_path, "r", encoding="utf-8") as fh:
raw_log = fh.read()
self.assertNotIn("SECRET-TOKEN", raw_log)
self.assertIn("token=***", raw_log)
entry = json.loads(raw_log.strip().splitlines()[-1])
self.assertEqual("wait_ready", entry["step"])
self.assertEqual("alias-a", entry["alias"])
self.assertEqual("51100639510", entry["item_id"])
self.assertEqual("RuntimeError", entry["exception"])
self.assert_removed(temp_dir)
def test_collect_tab_loads_latest_collect_run_log(self):
with self.make_temp_dir() as temp_dir:
cfg = self.make_config(temp_dir)
db.init_db(cfg["db_path"])
run_id = db.create_run_log("collect", total=1, path=cfg["db_path"])
db.add_run_log_event(
run_id,
"step=download_cover result=failed detail=旧封面下载超时",
level="error",
path=cfg["db_path"],
)
db.finish_run_log(
run_id,
status="done",
done=1,
failed_count=1,
summary_json={"failed": 1},
path=cfg["db_path"],
)
tab = CollectTab(config=cfg)
self.addCleanup(tab.close)
self.assertEqual("collectRunLogView", tab.run_log_view.objectName())
self.assertIn("step=download_cover result=failed", tab.run_log_view.toPlainText())
self.assertIn("旧封面下载超时", tab.run_log_view.toPlainText())
self.assert_removed(temp_dir)
def test_collect_tab_auto_starts_write_back_after_collect_success(self):