更新日志的中文说明

2026-08-21 09:42:03 +08:00
parent 8455d99d49
commit 29d8a506cd
12 changed files with 1923 additions and 168 deletions
--- a/日志使用指南.md
+++ b/日志使用指南.md
@@ -0,0 +1,530 @@
+# 远光智炼 — 日志使用指南
+
+> 版本：v2.0 | 适用范围：后端开发 & 运维 & 测试 & 业务排查
+
+---
+
+## 一、日志系统总览
+
+本平台的日志系统由三个核心组件构成，所有日志均输出为 **JSON 结构化格式**，按用途分流到不同文件。
+
+**所有日志的 `message` 字段均为中文**，直接可读，无需解析 JSON 字段即可知道"谁干了什么"。
+
+```
+backend/app/core/
+├── logging.py    ← 日志基础设施（格式化、脱敏、滚动、中间件）
+└── op_log.py     ← 操作日志（@op_log 装饰器 + log_operation 函数）
+```
+
+### 1.1 日志文件分流
+
+日志文件存放在 `backend/logs/` 目录，按日期命名，按大小滚动：
+
+| 文件名格式 | 用途 | 记录内容 | 保留周期 |
+|-----------|------|---------|---------|
+| `app-biz-YYYY-MM-DD.log` | **业务日志** | 用户操作（登录、删除、创建、停止等） | 7 天 |
+| `app-access-YYYY-MM-DD.log` | **访问日志** | 所有 HTTP 请求的方法、路径、状态码、耗时 | 15 天 |
+| `app-error-YYYY-MM-DD.log` | **错误日志** | 仅 ERROR 级别，含完整堆栈 | 30 天 |
+
+> 每个文件超过配置的 `max_bytes`（默认 100MB）时自动滚动为 `.1`、`.2` 后缀文件。
+
+### 1.2 日志数据流
+
+```
+用户请求
+  │
+  ▼
+FastAPI 中间件 (logging.py: request_logging_middleware)
+  │── 生成 traceId（UUID）
+  │── 写入 app-access（中文 message：HTTP请求 DELETE /路径 → 200（耗时xxms））
+  │
+  ▼
+路由处理函数
+  │── @op_log 装饰器自动记录操作
+  │     ├── 写入 app-biz（中文 message：用户[admin] 删除模型推理「cmp_xxx」，结果：成功）
+  │     └── 写入 operation_logs 表（数据库审计）
+  │
+  │── 手动调用 biz_logger.info()
+  │     └── 写入 app-biz（中文 message：用户创建数据处理任务成功）
+  │
+  └── 异常时
+        ├── 写入 app-error（中文 message + 完整堆栈）
+        └── 写入 app-biz（中文 message：用户[xxx] 删除xxx，结果：失败（PoolTimeout: xxx））
+```
+
+---
+
+## 二、日志格式说明
+
+### 2.1 业务日志（app-biz）— 中文 message 示例
+
+每条业务日志的 `message` 字段直接用中文描述"谁干了什么"，一眼就能看懂：
+
+```json
+{
+  "@timestamp": "2026-08-20T08:38:45.516+08:00",
+  "level": "INFO",
+  "logger": "app.biz",
+  "traceId": "31a4773a-e2ac-4ec7-8dd7-0e2431ec982e",
+  "message": "用户[admin] 删除模型推理「cmp_74e0d2f34b43」，结果：成功",
+  "clientIp": "127.0.0.1",
+  "fields": {
+    "action": "delete",
+    "bizModule": "model-inference",
+    "durationMs": 6799.44,
+    "opStatus": "success",
+    "targetId": "cmp_74e0d2f34b43",
+    "targetName": "cmp_74e0d2f34b43",
+    "targetType": "inference",
+    "username": "admin",
+    "requestMethod": "DELETE",
+    "requestPath": "/modelTF/model-inference/cmp_74e0d2f34b43"
+  }
+}
+```
+
+**怎么读**：直接看 `message` 字段 → `用户[admin] 删除模型推理「cmp_74e0d2f34b43」，结果：成功`
+
+失败时的 message 示例：
+```json
+"message": "用户[admin] 删除模型训练「ft_001」，结果：失败（PoolTimeout: database connection timeout）"
+```
+
+### 2.2 访问日志（app-access）— 中文 message 示例
+
+```json
+{
+  "@timestamp": "2026-08-20T08:38:45.657+08:00",
+  "level": "INFO",
+  "logger": "app.access",
+  "traceId": "31a4773a-e2ac-4ec7-8dd7-0e2431ec982e",
+  "message": "HTTP请求 DELETE /modelTF/model-inference/cmp_74e0d2f34b43 → 200（耗时175.06ms）",
+  "clientIp": "127.0.0.1",
+  "fields": {
+    "request_method": "DELETE",
+    "request_path": "/modelTF/model-inference/cmp_74e0d2f34b43",
+    "status_code": 200,
+    "duration_ms": 175.06,
+    "client_ip": "127.0.0.1"
+  }
+}
+```
+
+**怎么读**：直接看 `message` → `HTTP请求 DELETE /modelTF/model-inference/cmp_74e0d2f34b43 → 200（耗时175.06ms）`
+
+### 2.3 错误日志（app-error）— 中文 message 示例
+
+```json
+{
+  "@timestamp": "2026-08-20T08:59:27.017+08:00",
+  "level": "ERROR",
+  "logger": "app.workers.compute_poller",
+  "traceId": "-",
+  "message": "计算轮询执行失败",
+  "error": {
+    "type": "PoolTimeout",
+    "message": "计算轮询执行失败",
+    "stack_trace": "Traceback (most recent call last):\n  File \"compute_poller.py\", line 23 ..."
+  }
+}
+```
+
+**怎么读**：`message` → `计算轮询执行失败`，再看 `error.type` 和 `error.stack_trace` 确认具体原因。
+
+### 2.4 message 格式速查
+
+| 日志类型 | message 格式 | 示例 |
+|---------|-------------|------|
+| 业务操作成功 | `用户[xxx] 动词+模块+对象，结果：成功` | `用户[admin] 删除模型推理「cmp_001」，结果：成功` |
+| 业务操作失败 | `用户[xxx] 动词+模块+对象，结果：失败（异常类型: 异常消息）` | `用户[admin] 删除模型训练「ft_001」，结果：失败（PoolTimeout: 超时）` |
+| 系统操作 | `系统 动词+模块+对象，结果：成功` | `系统 退出登录用户，结果：成功` |
+| HTTP 请求 | `HTTP请求 方法 路径 → 状态码（耗时xxms）` | `HTTP请求 DELETE /modelTF/xxx → 200（耗时175ms）` |
+| HTTP 异常 | `HTTP请求异常 方法 路径（耗时xxms）— 服务内部错误` | `HTTP请求异常 POST /modelTF/xxx（耗时5000ms）— 服务内部错误` |
+| 后台任务 | 中文描述 | `计算轮询执行失败`、`数据处理预览完成` |
+
+---
+
+## 三、如何看日志
+
+### 3.1 快速查看某天的操作
+
+```bash
+# 查看今天用户做了哪些操作（直接看 message 字段）
+cat backend/logs/app-biz-2026-08-20.log | python -m json.tool
+
+# 在 PowerShell 中格式化查看
+Get-Content backend/logs/app-biz-2026-08-20.log | ForEach-Object { ($_ | ConvertFrom-Json).message }
+```
+
+输出效果（只看 message）：
+```
+用户[admin] 删除模型推理「cmp_74e0d2f34b43」，结果：成功
+用户[admin] 删除模型管理「tm_aaaa8e5ad5d7」，结果：成功
+用户创建数据处理任务成功
+用户停止数据处理任务成功
+用户发布数据处理任务成功
+```
+
+### 3.2 按用户筛选
+
+```bash
+# Linux/Mac
+grep '"username":"admin"' backend/logs/app-biz-2026-08-20.log
+
+# PowerShell
+Select-String -Path backend/logs/app-biz-2026-08-20.log -Pattern '"username":"admin"'
+```
+
+### 3.3 按操作类型筛选
+
+```bash
+# 查看所有删除操作
+grep '"action":"delete"' backend/logs/app-biz-2026-08-20.log
+
+# 查看所有失败的操作
+grep '"opStatus":"failure"' backend/logs/app-biz-2026-08-20.log
+
+# 用中文关键词搜索（直接搜 message 中的中文）
+grep '删除' backend/logs/app-biz-2026-08-20.log
+grep '失败' backend/logs/app-biz-2026-08-20.log
+grep '登录' backend/logs/app-biz-2026-08-20.log
+```
+
+### 3.4 按链路追踪（traceId）排查
+
+```bash
+# 拿到一个 traceId 后，搜索所有相关日志
+grep '31a4773a-e2ac-4ec7-8dd7-0e2431ec982e' backend/logs/app-*.log
+```
+
+这会同时匹配 `app-biz`、`app-access`、`app-error` 三个文件，让你看到该请求的完整链路：
+- `app-biz`：用户做了什么操作
+- `app-access`：HTTP 请求的方法、路径、状态码
+- `app-error`：有没有触发错误
+
+### 3.5 查看错误
+
+```bash
+# 当天的所有错误
+cat backend/logs/app-error-2026-08-20.log | python -m json.tool
+
+# 只看错误类型
+Get-Content backend/logs/app-error-2026-08-20.log | ForEach-Object { ($_ | ConvertFrom-Json).error.type }
+```
+
+---
+
+## 四、开发指南：如何写日志
+
+### 4.1 使用 `@op_log` 装饰器（推荐）
+
+对于所有写操作（创建、删除、启动、停止等），在路由函数上加 `@op_log` 装饰器，自动记录操作日志：
+
+```python
+from app.core.op_log import op_log, OpModule, OpAction
+
+@router.delete("/model-eval/{eval_id}")
+@op_log(module=OpModule.MODEL_EVAL, action=OpAction.DELETE, target_type="eval")
+async def delete_eval(eval_id: str, current_user: dict, request: Request):
+    # 你的业务逻辑
+    store.delete_eval(eval_id)
+    return {"message": "删除成功"}
+```
+
+装饰器会自动生成中文 message，例如：
+> `用户[admin] 删除模型评测「eval_001」，结果：成功`
+
+同时自动：
+- 捕获成功/失败状态
+- 记录操作耗时（`durationMs`）
+- 记录请求方法和路径（`requestMethod`、`requestPath`）
+- 失败时记录完整异常堆栈
+- 同时写入 `app-biz` 文件日志 + `operation_logs` 数据库表
+
+### 4.2 手动调用 `biz_logger`
+
+对于不方便用装饰器的场景（如多步骤操作、流程中间节点），使用 `StructuredLogger`：
+
+```python
+from app.core.logging import get_structured_logger
+
+biz_logger = get_structured_logger("app.biz.data_process")
+
+# 记录成功（message 直接用中文）
+biz_logger.info("用户创建数据处理任务成功", taskId="dpt_001", processType="unstructured")
+
+# 记录失败
+biz_logger.error("用户发布数据处理任务失败", taskId="dpt_001", errorType="ConnectionError")
+```
+
+### 4.3 模块和动作中文映射表
+
+`@op_log` 装饰器会自动将模块和动作翻译为中文，无需手动处理：
+
+| 英文（代码常量） | 中文（日志显示） |
+|-----------------|----------------|
+| `fine-tune` | 模型训练 |
+| `model-eval` | 模型评测 |
+| `model-inference` | 模型推理 |
+| `model-manage` | 模型管理 |
+| `dataset` | 数据集 |
+| `data-process` | 数据处理 |
+| `data-convert` | 数据转换 |
+| `compute` | 算力节点 |
+| `system` | 系统 |
+
+| 动作（英文） | 动作（中文） |
+|-------------|-------------|
+| `create` | 创建 |
+| `update` | 更新 |
+| `delete` | 删除 |
+| `start` | 启动 |
+| `stop` | 停止 |
+| `upload` | 上传 |
+| `download` | 下载 |
+| `login` | 登录 |
+| `logout` | 退出登录 |
+| `publish` | 发布 |
+| `retry` | 重试 |
+
+---
+
+## 五、错误排查实战示例
+
+### 场景一：用户反馈"删除模型评测任务后列表仍显示该记录"
+
+#### 第一步：确认操作是否被记录
+
+用户说在 8 月 20 日 08:38 左右执行了删除操作。先查业务日志：
+
+```bash
+# 方法 1：用中文关键词搜（最傻瓜）
+grep '删除' backend/logs/app-biz-2026-08-20.log
+
+# 方法 2：用英文字段搜（更精确）
+grep '"action":"delete"' backend/logs/app-biz-2026-08-20.log | grep 'model-eval'
+```
+
+找到记录，直接看 `message` 字段：
+
+```json
+{
+  "@timestamp": "2026-08-20T08:38:45.516+08:00",
+  "level": "INFO",
+  "logger": "app.biz",
+  "traceId": "31a4773a-e2ac-4ec7-8dd7-0e2431ec982e",
+  "message": "用户[admin] 删除模型推理「cmp_74e0d2f34b43」，结果：成功",
+  "fields": {
+    "action": "delete",
+    "bizModule": "model-inference",
+    "opStatus": "success",
+    "targetId": "cmp_74e0d2f34b43",
+    "username": "admin",
+    "durationMs": 6799.44,
+    "requestMethod": "DELETE",
+    "requestPath": "/modelTF/model-inference/cmp_74e0d2f34b43"
+  }
+}
+```
+
+**一眼就能读明白**：`用户[admin]` 在 `08:38:45` 删除了模型推理 `cmp_74e0d2f34b43`，操作成功，耗时 6.8 秒。
+
+#### 第二步：用 traceId 追踪完整请求链路
+
+拿到 `traceId` 后，搜索所有日志文件：
+
+```bash
+grep '31a4773a-e2ac-4ec7-8dd7-0e2431ec982e' backend/logs/app-*.log
+```
+
+会看到两条日志，`message` 直接告诉你发生了什么：
+
+1. **app-biz**：`用户[admin] 删除模型推理「cmp_74e0d2f34b43」，结果：成功`
+2. **app-access**：`HTTP请求 DELETE /modelTF/model-inference/cmp_74e0d2f34b43 → 200（耗时175.06ms）`
+
+#### 第三步：确认是否有错误
+
+```bash
+grep '31a4773a-e2ac-4ec7-8dd7-0e2431ec982e' backend/logs/app-error-2026-08-20.log
+```
+
+没有匹配 → 没有错误。
+
+#### 排查结论
+
+| 日志文件 | message | 结论 |
+|---------|---------|------|
+| `app-biz` | `用户[admin] 删除模型推理「cmp_xxx」，结果：成功` | 后端删除成功 |
+| `app-access` | `HTTP请求 DELETE /modelTF/... → 200` | 接口正常返回 |
+| `app-error` | 无 | 没有异常 |
+
+**结论**：删除操作本身没问题，问题出在查询逻辑（列表接口未过滤软删除记录）。
+
+---
+
+### 场景二：数据库连接超时导致后台轮询失败
+
+用户反馈"训练任务状态一直不更新"。
+
+#### 第一步：查看错误日志
+
+```bash
+cat backend/logs/app-error-2026-08-19.log
+```
+
+直接看 `message`：
+
+```json
+{
+  "@timestamp": "2026-08-19T11:19:10.341+08:00",
+  "level": "ERROR",
+  "logger": "app.workers.compute_poller",
+  "traceId": "-",
+  "message": "计算轮询执行失败",
+  "error": {
+    "type": "PoolTimeout",
+    "stack_trace": "...\npsycopg_pool.PoolTimeout: couldn't get a connection after 30.00 sec"
+  }
+}
+```
+
+**一眼读明白**：`计算轮询执行失败`，错误类型是 `PoolTimeout`（数据库连接池超时）。
+
+#### 第二步：确认频率
+
+```bash
+grep '计算轮询执行失败' backend/logs/app-error-2026-08-19.log | wc -l
+```
+
+从 11:19 到 13:49，每 33 秒一条，共 30+ 条 → 数据库不可用持续约 2.5 小时。
+
+#### 排查结论
+
+| 问题 | 原因 | 解决方案 |
+|------|------|---------|
+| 训练任务状态不更新 | 数据库连接池超时（PoolTimeout），后台轮询无法查询任务状态 | 检查 PostgreSQL 服务是否存活；增大连接池配置；检查网络连通性 |
+
+---
+
+### 场景三：数据处理预览失败（网络超时）
+
+用户反馈"点击数据处理预览后一直转圈"。
+
+#### 第一步：查看错误日志
+
+```bash
+grep '数据处理' backend/logs/app-error-2026-08-20.log
+```
+
+```json
+{
+  "@timestamp": "2026-08-20T08:59:27.017+08:00",
+  "level": "ERROR",
+  "logger": "app.api.v1.endpoints.data_process",
+  "traceId": "7e00377f-12ed-4130-bd40-8bbd0bc4992b",
+  "message": "数据处理预览失败 task_id=dpt_54045fd0ec744cc4ab8c preview_run_id=dpprun_8453fe1f349e4913809e duration_ms=45254.31",
+  "error": {
+    "type": "LocalEntryNotFoundError",
+    "stack_trace": "...httpx.ConnectTimeout: [WinError 10060] 由于连接方在一段时间后没有正确答复..."
+  }
+}
+```
+
+**一眼读明白**：`数据处理预览失败`，task_id 是 `dpt_54045fd0ec744cc4ab8c`，耗时 45 秒，错误类型是 `LocalEntryNotFoundError`，根因是网络超时（`WinError 10060`）。
+
+#### 第二步：用 traceId 看请求链路
+
+```bash
+grep '7e00377f-12ed-4130-bd40-8bbd0bc4992b' backend/logs/app-access-2026-08-20.log
+```
+
+```json
+{
+  "message": "HTTP请求 POST /modelTF/data-process/dpt_54045fd0ec744cc4ab8c/preview/start → 500（耗时45255ms）",
+  "fields": {
+    "request_method": "POST",
+    "request_path": "/modelTF/data-process/dpt_54045fd0ec744cc4ab8c/preview/start",
+    "status_code": 500
+  }
+}
+```
+
+**一眼读明白**：`POST 请求返回了 500`，耗时 45 秒（网络超时导致）。
+
+#### 排查结论
+
+| 问题 | 原因 | 解决方案 |
+|------|------|---------|
+| 数据处理预览一直转圈 | docling 需要从 HuggingFace 下载模型，网络连接超时 | 检查网络连通性；配置 HuggingFace 镜像源；或预下载模型到本地缓存 |
+
+---
+
+## 六、日志文件位置速查
+
+```
+backend/logs/
+├── app-biz-2026-08-20.log          ← 今天的业务操作日志（用户干了啥）
+├── app-biz-2026-08-20.log.1        ← 滚动后的旧业务日志
+├── app-access-2026-08-20.log       ← 今天的访问日志（HTTP 请求记录）
+├── app-error-2026-08-20.log        ← 今天的错误日志（ERROR + 堆栈）
+├── backend-2026-08-20.log          ← 兼容旧格式（全部日志）
+└── error-2026-08-19.log            ← 兼容旧错误日志
+```
+
+> **提示**：日期会自动变化，文件名中的日期就是当天。超过保留周期的旧文件会被自动清理。
+
+---
+
+## 七、快速排查口诀
+
+```
+1. 先看 app-biz —— 谁干了什么，成功还是失败（直接看 message）
+2. 再看 app-access —— 请求了什么路径，返回什么状态码
+3. 有错误看 app-error —— 什么异常，堆栈在哪一行
+4. 用 traceId 串联三个文件 —— 一个请求的完整链路
+```
+
+**中文关键词速查**：
+
+| 想查什么 | 搜什么关键词 |
+|---------|------------|
+| 删除操作 | `删除` |
+| 创建操作 | `创建` |
+| 登录/退出 | `登录`、`退出登录` |
+| 失败的操作 | `结果：失败` |
+| HTTP 请求 | `HTTP请求` |
+| HTTP 异常 | `HTTP请求异常` |
+| 计算轮询 | `计算轮询` |
+| 数据处理 | `数据处理` |
+
+---
+
+## 八、开发检查清单
+
+新增接口或修改业务逻辑时，请对照此清单：
+
+- [ ] 所有写操作（create/delete/start/stop/update）是否加了 `@op_log` 装饰器？
+- [ ] 手动 `biz_logger` 的 message 是否用了中文描述？
+- [ ] 多步骤流程是否用 `biz_logger.info()` 记录了关键中间节点？
+- [ ] 异常分支是否用 `logger.exception()` 记录了失败原因？
+- [ ] 日志中是否包含了足够的业务上下文（`taskId`、`datasetId` 等）？
+- [ ] 是否避免了在日志中打印密码、token 等敏感信息？（系统已自动脱敏，但仍需注意）
+- [ ] 是否避免了在 for/while 循环内打印 INFO 级别日志？
+
+---
+
+## 九、核心源码位置
+
+| 功能 | 文件位置 | 关键类/函数 |
+|------|---------|------------|
+| 日志配置入口 | `backend/app/core/logging.py` | `configure_logging()` |
+| JSON 格式化 | `backend/app/core/logging.py` | `JsonLogFormatter` |
+| 链路追踪 | `backend/app/core/logging.py` | `TraceIdFilter`、`request_id_var` |
+| 敏感数据脱敏 | `backend/app/core/logging.py` | `mask_sensitive_dict()`、`mask_value()` |
+| 大对象截断 | `backend/app/core/logging.py` | `truncate_large_value()` |
+| 文件滚动 | `backend/app/core/logging.py` | `DateSizeRotatingFileHandler` |
+| 请求日志中间件 | `backend/app/core/logging.py` | `setup_request_logging()` |
+| 结构化日志器 | `backend/app/core/logging.py` | `StructuredLogger`、`get_structured_logger()` |
+| 操作日志装饰器 | `backend/app/core/op_log.py` | `@op_log`、`log_operation()` |
+| 操作日志常量 | `backend/app/core/op_log.py` | `OpModule`、`OpAction`、`OpStatus` |
+| 中文 message 生成 | `backend/app/core/op_log.py` | `_build_cn_message()`、`MODULE_CN`、`ACTION_CN`、`TARGET_TYPE_CN` |