feat: add detailed logging to all API routes and global access log middleware

Each API module now logs:
- evaluations: trigger (scenario path, task_id), status polls, list
- runs: list (count), detail (run_id, metrics, sample counts)
- scenarios: list (total, valid, error counts)
- pipeline: submit (docs_path, models, max_docs), status polls, list
- llm_profiles: CRUD ops (name, model, id), probe/test (model, ok, latency), apply (patched fields)
- score: already had per-request logging

Global middleware (webapp.access logger):
- Every API request: METHOD path -> status (latency_ms) at INFO
- Static file requests demoted to DEBUG to reduce noise

Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com>

webapp/api/evaluations.py

@@ -2,6 +2,8 @@
 
 from __future__ import annotations
 
+import logging
+
 from fastapi import APIRouter, HTTPException
 
 from webapp.models import (
@@ -13,19 +15,23 @@ from webapp.services import scenario_scanner
 from webapp.services.task_manager import task_manager
 
 router = APIRouter(prefix="/api/evaluations", tags=["evaluations"])
+logger = logging.getLogger("webapp.api.evaluations")
 
 
 @router.post("", response_model=TriggerEvaluationResponse)
 def trigger_evaluation(request: TriggerEvaluationRequest) -> TriggerEvaluationResponse:
     """Validate the scenario path and queue a background evaluation task."""
+    logger.info("[trigger] scenario=%s", request.scenario_path)
     resolved = scenario_scanner.resolve_scenario_path(request.scenario_path)
     if resolved is None:
+        logger.warning("[trigger] invalid scenario path: %s", request.scenario_path)
         raise HTTPException(
             status_code=400,
             detail=f"无效或不允许的场景路径: {request.scenario_path}",
         )
 
     task_id = task_manager.submit(request.scenario_path)
+    logger.info("[trigger] queued  task_id=%s  scenario=%s", task_id, request.scenario_path)
     return TriggerEvaluationResponse(task_id=task_id)
 
 
@@ -34,11 +40,15 @@ def get_task_status(task_id: str) -> TaskStatus:
     """Return the current status and logs for one evaluation task."""
     status = task_manager.get(task_id)
     if status is None:
+        logger.warning("[task_status] not found  task_id=%s", task_id)
         raise HTTPException(status_code=404, detail=f"未找到任务: {task_id}")
+    logger.debug("[task_status] task_id=%s  status=%s", task_id, status.status)
     return status
 
 
 @router.get("", response_model=dict)
 def list_tasks() -> dict[str, list]:
     """Return all known evaluation tasks for this server session."""
-    return {"tasks": [task.model_dump() for task in task_manager.list_tasks()]}
+    tasks = task_manager.list_tasks()
+    logger.info("[list_tasks] count=%d", len(tasks))
+    return {"tasks": [task.model_dump() for task in tasks]}

webapp/api/llm_profiles.py

@@ -2,6 +2,7 @@
 
 from __future__ import annotations
 
+import logging
 import time
 
 from fastapi import APIRouter, HTTPException
@@ -19,6 +20,7 @@ from webapp.services.profile_manager import profile_manager
 from webapp.services.yaml_patcher import apply_profiles_to_scenario
 
 router = APIRouter(prefix="/api/llm-profiles", tags=["llm-profiles"])
+logger = logging.getLogger("webapp.api.llm_profiles")
 
 
 def _do_connectivity_test(
@@ -50,35 +52,44 @@ def _do_connectivity_test(
 @router.post("/probe", response_model=ProfileTestResponse, tags=["llm-profiles"])
 def probe_connectivity(request: ProfileProbeRequest) -> ProfileTestResponse:
     """Test LLM connectivity with inline credentials (no saved profile required)."""
-    return _do_connectivity_test(
+    logger.info("[probe] model=%s  base_url=%s", request.model, request.base_url)
+    result = _do_connectivity_test(
         model=request.model,
         base_url=request.base_url,
         api_key=request.api_key,
         timeout_seconds=request.timeout_seconds,
     )
+    logger.info("[probe] ok=%s  latency=%sms  msg=%s", result.ok, result.latency_ms, result.message)
+    return result
 
 
 @router.get("", response_model=dict)
 def list_profiles() -> dict:
     """Return all saved LLM profiles."""
-    return {"profiles": [p.model_dump() for p in profile_manager.list_all()]}
+    profiles = profile_manager.list_all()
+    logger.info("[list_profiles] count=%d", len(profiles))
+    return {"profiles": [p.model_dump() for p in profiles]}
 
 
 @router.post("", status_code=201, response_model=LLMProfile)
 def create_profile(request: CreateProfileRequest) -> LLMProfile:
     """Create a new LLM profile."""
-    return profile_manager.create(
+    logger.info("[create_profile] name=%r  model=%s  base_url=%s", request.name, request.model, request.base_url)
+    profile = profile_manager.create(
         name=request.name,
         model=request.model,
         base_url=request.base_url,
         api_key=request.api_key,
         timeout_seconds=request.timeout_seconds,
     )
+    logger.info("[create_profile] created  id=%s", profile.profile_id)
+    return profile
 
 
 @router.put("/{profile_id}", response_model=LLMProfile)
 def update_profile(profile_id: str, request: CreateProfileRequest) -> LLMProfile:
     """Update an existing LLM profile by id."""
+    logger.info("[update_profile] id=%s  name=%r  model=%s", profile_id, request.name, request.model)
     updated = profile_manager.update(
         profile_id=profile_id,
         name=request.name,
@@ -88,16 +99,21 @@ def update_profile(profile_id: str, request: CreateProfileRequest) -> LLMProfile
         timeout_seconds=request.timeout_seconds,
     )
     if updated is None:
+        logger.warning("[update_profile] not found  id=%s", profile_id)
         raise HTTPException(status_code=404, detail=f"Profile not found: {profile_id}")
+    logger.info("[update_profile] updated  id=%s", profile_id)
     return updated
 
 
 @router.delete("/{profile_id}", response_model=dict)
 def delete_profile(profile_id: str) -> dict:
     """Delete an LLM profile by id."""
+    logger.info("[delete_profile] id=%s", profile_id)
     deleted = profile_manager.delete(profile_id)
     if not deleted:
+        logger.warning("[delete_profile] not found  id=%s", profile_id)
         raise HTTPException(status_code=404, detail=f"Profile not found: {profile_id}")
+    logger.info("[delete_profile] deleted  id=%s", profile_id)
     return {"deleted": True}
 
 
@@ -106,18 +122,31 @@ def test_profile(profile_id: str) -> ProfileTestResponse:
     """Test LLM connectivity for a saved profile."""
     profile = profile_manager.get(profile_id)
     if profile is None:
+        logger.warning("[test_profile] not found  id=%s", profile_id)
         raise HTTPException(status_code=404, detail=f"Profile not found: {profile_id}")
-    return _do_connectivity_test(
+    logger.info("[test_profile] id=%s  model=%s  base_url=%s", profile_id, profile.model, profile.base_url)
+    result = _do_connectivity_test(
         model=profile.model,
         base_url=profile.base_url,
         api_key=profile.api_key,
         timeout_seconds=profile.timeout_seconds,
     )
+    logger.info("[test_profile] ok=%s  latency=%sms", result.ok, result.latency_ms)
+    return result
 
 
 @router.post("/apply", response_model=ProfileApplyResponse)
 def apply_profiles(request: ProfileApplyRequest) -> ProfileApplyResponse:
     """Patch selected LLM profiles into the target scenario YAML file."""
+    logger.info(
+        "[apply_profiles] scenario=%s  judge=%s  answer=%s  dataset=%s  metric_weights=%s  doc_weights=%s",
+        request.scenario_path,
+        request.judge_profile_id,
+        request.answer_profile_id,
+        request.dataset_profile_id,
+        bool(request.metric_weights),
+        bool(request.doc_weights),
+    )
     role_profiles: dict[str, LLMProfile | None] = {
         "judge": profile_manager.get(request.judge_profile_id) if request.judge_profile_id else None,
         "answer": profile_manager.get(request.answer_profile_id) if request.answer_profile_id else None,
@@ -135,6 +164,7 @@ def apply_profiles(request: ProfileApplyRequest) -> ProfileApplyResponse:
     ]
 
     if missing:
+        logger.warning("[apply_profiles] missing profiles for roles: %s", missing)
         raise HTTPException(
             status_code=400,
             detail=f"Profile(s) not found for roles: {', '.join(missing)}",
@@ -148,6 +178,7 @@ def apply_profiles(request: ProfileApplyRequest) -> ProfileApplyResponse:
         metric_weights=request.metric_weights,
         doc_weights=request.doc_weights,
     )
+    logger.info("[apply_profiles] patched fields: %s", patched)
     return ProfileApplyResponse(
         scenario_path=request.scenario_path,
         patched_fields=patched,

webapp/api/pipeline.py

@@ -0,0 +1,131 @@
+"""Routes for the end-to-end pipeline API (document parse → build → eval)."""
+
+from __future__ import annotations
+
+import logging
+
+from fastapi import APIRouter, HTTPException
+
+from webapp.models import (
+    PipelineJobRequest,
+    PipelineJobResponse,
+    PipelineJobStatus,
+)
+from webapp.services.pipeline_task_manager import pipeline_task_manager
+
+router = APIRouter(prefix="/api/pipeline", tags=["pipeline"])
+logger = logging.getLogger("webapp.api.pipeline")
+
+
+@router.post(
+    "/jobs",
+    status_code=202,
+    response_model=PipelineJobResponse,
+    summary="提交全链路评估任务",
+    responses={
+        202: {
+            "description": "任务已成功排队，立即返回 job_id。",
+            "content": {
+                "application/json": {
+                    "example": {
+                        "job_id": "a1b2c3d4e5f6",
+                        "job_name": "siemens-ct-eval-2026",
+                        "status": "queued",
+                    }
+                }
+            },
+        },
+        422: {"description": "请求参数校验失败（docs_path 等必填字段缺失或格式错误）。"},
+    },
+)
+def submit_pipeline_job(request: PipelineJobRequest) -> PipelineJobResponse:
+    """提交一个「解析文档 → 生成题库 → RAGAS 评估 → 输出报告」全链路任务。
+
+    任务在后台线程中异步执行，立即返回 `job_id`。
+    通过 `GET /api/pipeline/jobs/{job_id}` 轮询 `status` / `phase` / `logs`。
+
+    **Pipeline 执行阶段**：
+    1. `parsing_documents` — 调用阿里云 DocMind 解析每份 PDF
+    2. `generating_questions` — LLM 从文档片段生成草稿题库
+    3. `evaluating` — RAGAS 在线评测打分（answer_model 答题 + judge_model 评分）
+    4. `done` — 所有产物写入磁盘，`status` 变为 `completed`
+    """
+    logger.info(
+        "[submit_pipeline] docs_path=%s  job_name=%r  gen_model=%s  judge=%s  max_docs=%s",
+        request.docs_path, request.job_name, request.generation_model,
+        request.judge_model, request.max_documents,
+    )
+    task = pipeline_task_manager.submit(request)
+    logger.info("[submit_pipeline] queued  job_id=%s  job_name=%s", task.job_id, task.job_name)
+    return PipelineJobResponse(
+        job_id=task.job_id,
+        job_name=task.job_name,
+        status=task.status,
+    )
+
+
+@router.get(
+    "/jobs/{job_id}",
+    response_model=PipelineJobStatus,
+    summary="查询任务状态",
+    responses={
+        200: {"description": "返回任务当前状态、执行阶段、日志及完成后的产物路径。"},
+        404: {"description": "指定 job_id 的任务不存在。"},
+    },
+)
+def get_pipeline_job(job_id: str) -> PipelineJobStatus:
+    """查询一个 Pipeline 任务的当前状态、执行阶段、实时日志和结果。
+
+    **轮询建议**：每 3–5 秒查询一次，直到 `status` 为 `completed` 或 `failed`。
+
+    `result` 字段在任务完成后填充，包含：
+    - `scores_csv` — 每道题目逐项评分
+    - `summary_md` — 评估摘要 Markdown
+    - `dataset_csv` — 生成的题库 CSV
+    - `source_chunks_jsonl` — 文档片段索引
+    """
+    status = pipeline_task_manager.get(job_id)
+    if status is None:
+        logger.warning("[get_pipeline_job] not found  job_id=%s", job_id)
+        raise HTTPException(status_code=404, detail=f"Pipeline job not found: {job_id}")
+    logger.debug("[get_pipeline_job] job_id=%s  status=%s  phase=%s", job_id, status.status, status.phase)
+    return status
+
+
+@router.get(
+    "/jobs",
+    response_model=dict,
+    summary="列出所有任务",
+    responses={
+        200: {
+            "description": "按创建时间倒序返回本次服务器会话中所有的 Pipeline 任务。",
+            "content": {
+                "application/json": {
+                    "example": {
+                        "jobs": [
+                            {
+                                "job_id": "a1b2c3d4e5f6",
+                                "job_name": "siemens-ct-eval",
+                                "status": "completed",
+                                "phase": "done",
+                                "logs": ["[build] 17 documents parsed", "..."],
+                                "result": {
+                                    "total_questions": 19,
+                                    "eval_run_id": "2026-06-18T...",
+                                    "scores_csv": "outputs/pipeline/.../scores.csv",
+                                    "summary_md": "outputs/pipeline/.../summary.md",
+                                },
+                                "error": None,
+                            }
+                        ]
+                    }
+                }
+            },
+        }
+    },
+)
+def list_pipeline_jobs() -> dict:
+    """返回本次服务器会话中所有已提交的 Pipeline 任务，按创建时间倒序排列。"""
+    jobs = pipeline_task_manager.list_jobs()
+    logger.info("[list_pipeline_jobs] count=%d", len(jobs))
+    return {"jobs": [s.model_dump() for s in jobs]}

webapp/api/runs.py

@@ -2,31 +2,42 @@
 
 from __future__ import annotations
 
+import logging
+
 from fastapi import APIRouter, HTTPException
 
 from webapp.models import RunDetail
 from webapp.services import report_builder, run_reader
 
 router = APIRouter(prefix="/api/runs", tags=["runs"])
+logger = logging.getLogger("webapp.api.runs")
 
 
 @router.get("")
 def get_runs() -> dict[str, list]:
     """Return summaries for every discoverable evaluation run."""
     summaries = run_reader.list_run_summaries()
+    logger.info("[get_runs] found %d runs", len(summaries))
     return {"runs": [summary.model_dump() for summary in summaries]}
 
 
 @router.get("/{run_id}")
 def get_run_detail(run_id: str) -> RunDetail:
     """Return the full summary and aggregated report for one run."""
+    logger.info("[get_run_detail] run_id=%s", run_id)
     run_dir = run_reader.find_run_dir(run_id)
     if run_dir is None:
+        logger.warning("[get_run_detail] not found  run_id=%s", run_id)
         raise HTTPException(status_code=404, detail=f"未找到运行: {run_id}")
 
     summary = run_reader.build_run_summary(run_dir)
     if summary is None:
+        logger.warning("[get_run_detail] missing metadata  run_id=%s", run_id)
         raise HTTPException(status_code=404, detail=f"运行元数据缺失: {run_id}")
 
     report = report_builder.build_report(run_dir, summary.metrics)
+    logger.info(
+        "[get_run_detail] ok  run_id=%s  metrics=%s  valid=%d  invalid=%d",
+        run_id, summary.metrics, summary.valid_samples, summary.invalid_samples,
+    )
     return RunDetail(summary=summary, report=report)

webapp/api/scenarios.py

@@ -2,15 +2,20 @@
 
 from __future__ import annotations
 
+import logging
+
 from fastapi import APIRouter
 
 from webapp.services import scenario_scanner
 
 router = APIRouter(prefix="/api/scenarios", tags=["scenarios"])
+logger = logging.getLogger("webapp.api.scenarios")
 
 
 @router.get("")
 def get_scenarios() -> dict[str, list]:
     """Return every scenario file found under the scenarios/ directory."""
     scenarios = scenario_scanner.list_scenarios()
+    valid = sum(1 for s in scenarios if not s.error)
+    logger.info("[get_scenarios] total=%d  valid=%d  errors=%d", len(scenarios), valid, len(scenarios) - valid)
     return {"scenarios": [item.model_dump() for item in scenarios]}

webapp/server.py

@@ -8,6 +8,7 @@ the server starts even when the evaluation dependencies are not yet installed.
 from __future__ import annotations
 
 import logging
+import time
 from pathlib import Path
 
 from fastapi import FastAPI, Request
@@ -20,6 +21,7 @@ from webapp.api import evaluations, llm_profiles, pipeline, runs, scenarios, sco
 
 STATIC_DIR = Path(__file__).resolve().parent / "static"
 logger = logging.getLogger("webapp.server")
+access_logger = logging.getLogger("webapp.access")
 
 # OpenAPI tag metadata — controls the grouping and descriptions in /docs.
 OPENAPI_TAGS = [
@@ -107,6 +109,24 @@ def create_app() -> FastAPI:
     app.include_router(pipeline.router)
     app.include_router(score.router)
 
+    @app.middleware("http")
+    async def access_log_middleware(request: Request, call_next):
+        """Log every API request with method, path, status code and latency.
+
+        Static file requests are logged at DEBUG level to keep the console clean.
+        """
+        t0 = time.monotonic()
+        response = await call_next(request)
+        latency_ms = int((time.monotonic() - t0) * 1000)
+        path = request.url.path
+        is_static = path.startswith("/static/") or path in ("/", "/favicon.ico")
+        msg = "%s %s → %d  (%dms)", request.method, path, response.status_code, latency_ms
+        if is_static:
+            access_logger.debug(*msg)
+        else:
+            access_logger.info(*msg)
+        return response
+
     @app.exception_handler(RequestValidationError)
     async def validation_exception_handler(request: Request, exc: RequestValidationError) -> JSONResponse:
         """Log full validation error detail to help diagnose 422 responses."""