# 远光智炼 — 日志使用指南 > 版本: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` |