Skip to content

Commit 561175e

Browse files
committed
fix(logging): 审计日志此前全部被丢弃 + 三层日志轮转方案
## 生产缺陷(实测) uvicorn 默认 LOGGING_CONFIG 只配置 `uvicorn` / `uvicorn.access` (propagate=false),**从不配置 root**;root 默认 level=WARNING 且无 handler。 于是应用里 9 个模块 `logging.getLogger(__name__)` 的 INFO 被静默丢弃: - PROPOSAL §8 要求的凭证审计日志(增删改/pin/账号切换,7 处 logger.info) 一条都没落盘(grep -c 管理员 logs/*.log → 全 0) - executor 的上游错误 WARNING、quota_probe/checkin 的失败也全部消失 生产路径是 `uvicorn src.main:build_app --factory`(launchd/容器/systemd 均如此), 不经过 run(),因此配置挂在 build_app 上(幂等,测试反复调用不叠加 handler)。 同时把 httpx/httpcore 的 INFO 压到 WARNING:root 升到 INFO 后它们给每个上游 请求打一条含完整 URL 的日志,既是噪音也与 §8「日志脱敏」冲突(URL 可能带 query 参数);root=DEBUG 时放开,排查上游问题仍可看详情。 ## 轮转:应用只写 stderr,交给平台(三平台通用) 不在应用内开文件/用 RotatingFileHandler:launchd、systemd、docker 三种形态 采集方式不同但都靠 stdout/stderr 对接;应用自己写文件会与平台轮转争抢同一 文件,容器里还会写进镜像层(重启即丢、docker logs 看不到)。 - Docker:compose 加 logging 段(json-file 默认无上限,是真实缺口) - macOS:deploy/newsyslog/ + scripts/install-newsyslog.sh(需 sudo) - Linux systemd:deploy/systemd/(journald 自带轮转,顺带补上缺失的 unit 模板) - Linux 非 systemd:deploy/logrotate/(用 copytruncate,进程持有 fd) newsyslog 字段已核对 man page(when=* 表示仅按 size;J=bzip2;N=不发信号), 规则里的路径与属主已与 launchd plist、实际文件属主逐项对齐。清理了 logs/{server,uvicorn}.log 两个失联残留(已无任何代码引用)。 测试:审计日志真的写到 handler(直接看 emit,不用 caplog——caplog 靠往 root 加 handler,不能证明我们的 handler 收到记录)、幂等、级别归一、降噪与 DEBUG 放开、stderr 而非文件、以及部署资产静态断言(compose 限额、newsyslog 字段数 与属主匹配、logrotate 用 copytruncate、systemd 走 journal、安装脚本可执行)。
1 parent 2632407 commit 561175e

11 files changed

Lines changed: 506 additions & 0 deletions

File tree

‎README.md‎

Lines changed: 32 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -131,6 +131,38 @@ curl http://127.0.0.1:8000/v1/user/balance -H "Authorization: Bearer sk-你的ke
131131

132132
- **时区**:镜像默认 `TZ=Asia/Shanghai`;如需其它时区显式覆盖 `TZ`。
133133

134+
## 日志
135+
136+
应用只写 **stdout / stderr**,不自己写文件也不自己轮转(原因见
137+
[`src/webapp/logging.py`](src/webapp/logging.py) 顶部说明):三种部署形态的
138+
采集方式不同,但都靠这两个 fd 对接,轮转交给各自的平台工具。因此**日志自己
139+
不会停止增长**——按下面对应形态配一次即可。
140+
141+
| 部署形态 | 日志到哪 | 轮转机制 | 需做什么 |
142+
|---|---|---|---|
143+
| **Docker / compose** | `docker logs coding2api` | json-file 驱动(已在 compose 配好 `10m × 5`) | **无需操作** |
144+
| **macOS(launchd)** | `logs/launchd.{out,err}.log` | 系统自带 `newsyslog` | 跑一次 `./scripts/install-newsyslog.sh`(需 sudo) |
145+
| **Linux(systemd)** | `journalctl -u coding2api` | journald 自带 | **无需操作**(模板见 `deploy/systemd/`) |
146+
| **Linux(非 systemd)** | 重定向到 `/var/log/coding2api/*.log` | `logrotate` | `sudo cp deploy/logrotate/coding2api /etc/logrotate.d/` |
147+
| **裸跑**(`uv run python -m src.main`) | 终端 stderr | 无 | 自己重定向并自备轮转 |
148+
149+
级别用 `LOG_LEVEL`(默认 `INFO`)控制。**审计日志(凭证增删改/pin/账号切换)
150+
是 INFO 级**,把 `LOG_LEVEL` 调到 `WARNING` 会把它一并关掉。
151+
152+
```bash
153+
# macOS:装轮转规则(单文件超 10MB 转,留 7 份,bzip2 压缩)
154+
./scripts/install-newsyslog.sh
155+
./scripts/install-newsyslog.sh --uninstall # 卸载
156+
157+
# 看日志
158+
tail -f logs/launchd.err.log # macOS
159+
docker logs -f coding2api # 容器
160+
journalctl -u coding2api -f # systemd
161+
```
162+
163+
> 容器里的 `data/dumps/`(诊断开关 `DUMP_REQUEST_BODIES=true` 写入)不在
164+
> docker 日志体系内,由应用自行保持最多 200 份。
165+
134166
## 开发
135167

136168
```bash

‎TECHNICAL.md‎

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -32,6 +32,7 @@ coding2api/
3232
│ │ ├── limits.py # 请求体上限 ASGI 中间件(登录 8KB / 其余 16MB)
3333
│ │ ├── security.py # Host 白名单 + 安全响应头(CSP/nosniff)
3434
│ │ ├── handlers.py # 异常 → HTTP 响应(稳定错误码,TECHNICAL §6.5)
35+
│ │ ├── logging.py # root logger 配置(审计/上游日志落 stderr)
3536
│ │ └── static.py # 前端产物定位 + SPA catch-all
3637
│ ├── db/
3738
│ │ ├── schema.sql # DDL 定稿
@@ -378,6 +379,16 @@ fixture 断言两个方向:**解析正确**(样本 → 期望 Event)与**
378379
全量重算作对账,两者结果一致(幂等)
379380
- **延迟均值只算成功请求**:分子 `SUM(latency_ms WHERE ok=1)` 与分母 `ok_count`
380381
配对;失败请求的耗时不能拉偏「典型耗时」(与图表口径一致)
382+
- **应用日志只写 stderr,轮转交给平台**:不在应用内开文件、不用
383+
`RotatingFileHandler`。理由:三种部署形态(launchd / systemd / docker)的
384+
采集方式不同但都靠 stdout/stderr 对接;应用自己写文件会与平台轮转争抢同一个
385+
文件,容器里还会写进镜像层(重启即丢且 `docker logs` 看不到)。
386+
各自配置见 `deploy/`(newsyslog / logrotate / systemd)与 compose 的 `logging` 段
387+
- **必须在 build_app 里配 root logger**:uvicorn 默认 `LOGGING_CONFIG` 只配
388+
`uvicorn` / `uvicorn.access`(`propagate=false`),**从不配 root**;root 默认
389+
`WARNING` 且无 handler,导致 `logging.getLogger(__name__)` 的 INFO 静默丢失。
390+
生产路径 `uvicorn src.main:build_app --factory` 不经过 `run()`,
391+
所以配置必须挂在 `build_app`(幂等,见 `src/webapp/logging.py`)
381392
- **两套数据源共存(已知不一致)**:`overview` / `by_provider` 读 `usage_events`(即时,
382393
仅覆盖 90 天明细),`timeline` / `model-timeline` 读 `usage_hourly`(≤5 分钟滞后,永久)。
383394
时间范围 ≤90 天时两者一致(汇总由同一批明细算出);选「全部」时总览会小于图表,

‎deploy/logrotate/coding2api‎

Lines changed: 24 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,24 @@
1+
# Linux(非 systemd,或 systemd 但想把日志落独立文件)日志轮转
2+
#
3+
# 安装:
4+
# sudo cp deploy/logrotate/coding2api /etc/logrotate.d/
5+
# sudo logrotate -d /etc/logrotate.d/coding2api # 干跑校验
6+
#
7+
# 路径按实际部署改(systemd 版见 deploy/systemd/coding2api.service,
8+
# 那条路线用 journald 自带轮转,不需要本文件)。
9+
#
10+
# 注意:本配置依赖应用把日志写到 stdout/stderr 后被重定向到该文件,
11+
# 而不是应用自己写文件——见 src/webapp/logging.py 的说明。
12+
# 因此必须配合 copytruncate(进程持有 fd 时 rename 不会让它换文件):
13+
# >> /var/log/coding2api/app.log 这种重定向下,用 copytruncate 最稳。
14+
15+
/var/log/coding2api/*.log {
16+
daily
17+
rotate 7
18+
maxsize 10M
19+
missingok
20+
notifempty
21+
compress
22+
delaycompress
23+
copytruncate
24+
}

‎deploy/newsyslog/coding2api.conf‎

Lines changed: 25 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,25 @@
1+
# macOS 日志轮转规则(newsyslog)
2+
#
3+
# 安装(需 root,newsyslog 只读 /etc/newsyslog.d/):
4+
# sudo cp deploy/newsyslog/coding2api.conf /etc/newsyslog.d/
5+
# sudo launchctl kickstart -k system/com.apple.newsyslog # 立即生效
6+
# 卸载:
7+
# sudo rm /etc/newsyslog.d/coding2api.conf
8+
#
9+
# 字段含义(newsyslog.conf(5),已核 man page):
10+
# logfilename owner:group mode count size(KB) when flags
11+
#
12+
# size=10240 单文件超 10MB 即轮转
13+
# when=* 仅依据 size 轮转(不按时间);磁盘占用只与总量相关
14+
# count=7 最多保留 7 份归档(不含当前日志)
15+
# flags=J 归档用 bzip2 压缩
16+
# flags=N 轮转后不发信号(进程以 >> 追加模式持有文件句柄,
17+
# newsyslog 轮转后新文件同名,进程继续写入)
18+
#
19+
# 注意:日志路径必须与 ~/Library/LaunchAgents/com.coding2api.plist 的
20+
# StandardOutPath / StandardErrorPath 一致。改 plist 时同步改这里。
21+
# 本仓库的 plist 把两路日志分别写 launchd.out.log / launchd.err.log,
22+
# 因此这里给两条规则。
23+
24+
/Users/robbs/Develpment/PartTimeJob/coding2api/logs/launchd.out.log robbs:staff 644 7 10240 * JN
25+
/Users/robbs/Develpment/PartTimeJob/coding2api/logs/launchd.err.log robbs:staff 644 7 10240 * JN

‎deploy/systemd/coding2api.service‎

Lines changed: 57 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,57 @@
1+
# systemd unit 模板(Linux 生产部署)
2+
#
3+
# 安装:
4+
# sudo useradd --system --home /opt/coding2api coding2api
5+
# sudo cp deploy/systemd/coding2api.service /etc/systemd/system/
6+
# sudo systemctl daemon-reload && sudo systemctl enable --now coding2api
7+
# journalctl -u coding2api -f # 看日志
8+
#
9+
# 日志:走 journald(StandardOutput=journal),journald 自带容量轮转,
10+
# 无需 logrotate。全局限额在 /etc/systemd/journald.conf:
11+
# SystemMaxUse=500M
12+
# SystemMaxFileSize=50M
13+
# 也可按 unit 限制:
14+
# sudo systemctl edit coding2api
15+
# [Service]
16+
# LogRateLimitIntervalSec=30s
17+
# LogRateLimitBurst=1000
18+
#
19+
# 注意:应用只写 stdout/stderr,不自己写文件、不自己轮转
20+
# (见 src/webapp/logging.py 的原因说明)。
21+
22+
[Unit]
23+
Description=Coding2API — CodeBuddy / TRAE SOLO 统一 OpenAI 兼容出口
24+
After=network-online.target
25+
Wants=network-online.target
26+
27+
[Service]
28+
Type=exec
29+
User=coding2api
30+
Group=coding2api
31+
WorkingDirectory=/opt/coding2api
32+
33+
# 必填:凭证列加密密钥。放独立文件(权限 600,属主 coding2api),
34+
# 不要写在本 unit 里,否则 systemctl cat 会把密钥暴露给任何用户。
35+
EnvironmentFile=/opt/coding2api/.env
36+
Environment=HOST=127.0.0.1
37+
Environment=PORT=8000
38+
Environment=DATA_DIR=/opt/coding2api/data
39+
40+
ExecStart=/opt/coding2api/.venv/bin/python -m uvicorn src.main:build_app --factory
41+
Restart=always
42+
RestartSec=5
43+
44+
# 日志交给 journald(自带轮转)
45+
StandardOutput=journal
46+
StandardError=journal
47+
48+
# 安全加固:只需要写 data/ 与读 secrets/
49+
NoNewPrivileges=true
50+
PrivateTmp=true
51+
ProtectSystem=strict
52+
ProtectHome=true
53+
ReadWritePaths=/opt/coding2api/data
54+
ReadOnlyPaths=/opt/coding2api/secrets
55+
56+
[Install]
57+
WantedBy=multi-user.target

‎docker-compose.yml‎

Lines changed: 9 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -55,3 +55,12 @@ services:
5555
interval: 30s
5656
timeout: 5s
5757
retries: 3
58+
# 日志轮转(唯一声明式、无需运维动手的一层):json-file 驱动默认
59+
# **无上限**,长期运行会把宿主磁盘写满。应用只写 stdout/stderr,
60+
# 由 docker 采集,因此限额必须在这里给。
61+
# 查看:docker logs coding2api;宿主机路径见 docker inspect 的 LogPath
62+
logging:
63+
driver: json-file
64+
options:
65+
max-size: "10m"
66+
max-file: "5"

‎scripts/install-newsyslog.sh‎

Lines changed: 33 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,33 @@
1+
#!/usr/bin/env bash
2+
# 安装 macOS newsyslog 轮转规则(需 sudo:newsyslog 只读 /etc/newsyslog.d/)。
3+
#
4+
# ./scripts/install-newsyslog.sh # 安装 + 立即生效
5+
# ./scripts/install-newsyslog.sh --uninstall
6+
#
7+
# 日志路径取自 ~/Library/LaunchAgents/com.coding2api.plist,因此 plist 改了
8+
# 日志位置时需要重新跑本脚本。
9+
set -euo pipefail
10+
11+
RULES_SRC="$(cd "$(dirname "${BASH_SOURCE[0]}")/.." && pwd)/deploy/newsyslog/coding2api.conf"
12+
RULES_DST="/etc/newsyslog.d/coding2api.conf"
13+
14+
if [[ "${1:-}" == "--uninstall" ]]; then
15+
sudo rm -f "$RULES_DST"
16+
sudo launchctl kickstart -k system/com.apple.newsyslog
17+
echo "已移除 $RULES_DST"
18+
exit 0
19+
fi
20+
21+
if [[ ! -f "$RULES_SRC" ]]; then
22+
echo "找不到规则文件: $RULES_SRC" >&2
23+
exit 1
24+
fi
25+
26+
# 用规则里第一条路径做一次 dry-run 校验,避免装进坏规则导致 newsyslog 整体失败
27+
echo "== 规则内容 =="
28+
cat "$RULES_SRC"
29+
30+
sudo cp "$RULES_SRC" "$RULES_DST"
31+
sudo launchctl kickstart -k system/com.apple.newsyslog
32+
echo "已安装: $RULES_DST(单文件超 10MB 轮转,保留 7 份,bzip2 压缩)"
33+
echo "查看结果: ls -la $(dirname "$(awk 'NF && $1 !~ /^#/ {print $1; exit}' "$RULES_SRC")")"

‎src/main.py‎

Lines changed: 7 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -46,6 +46,7 @@
4646
from .webapp import static as _static
4747
from .webapp.handlers import register_exception_handlers
4848
from .webapp.limits import BodySizeLimitMiddleware
49+
from .webapp.logging import configure_logging
4950
from .webapp.security import host_allowed, security_middleware
5051

5152
logger = logging.getLogger(__name__)
@@ -108,6 +109,10 @@ def _forget_task(task: asyncio.Task, pending: list) -> None:
108109
def build_app(settings: Settings | None = None, *, providers: dict | None = None,
109110
users: object | None = None) -> FastAPI:
110111
config = settings or load_settings()
112+
# 这里必须配:生产路径是 `uvicorn src.main:build_app --factory`(launchd /
113+
# 容器 / systemd 均如此),不经过 run(),否则审计等 INFO 日志仍被丢弃。
114+
# 幂等,测试反复调用 build_app 不会叠加 handler。
115+
configure_logging(config.log_level)
111116
db = Database(config.db_path)
112117
apply_schema(db.connect())
113118
cipher = CredentialCipher(config.app_secret)
@@ -284,6 +289,8 @@ def run() -> None:
284289
import uvicorn
285290

286291
config = load_settings()
292+
# 应用日志(审计、上游错误等)在此之前无 handler 会被丢弃
293+
configure_logging(config.log_level)
287294
uvicorn.run(
288295
build_app(config), host=config.host, port=config.port, log_level=config.log_level.lower()
289296
)

‎src/webapp/logging.py‎

Lines changed: 71 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,71 @@
1+
"""日志配置:应用只写 stderr,轮转交给平台。
2+
3+
**为什么应用不自己写文件、不自己轮转**
4+
三种部署形态的日志采集方式完全不同,且都靠「进程的 stdout/stderr」这个
5+
统一接口对接:
6+
7+
- macOS launchd:`StandardOutPath` / `StandardErrorPath` 重定向到文件,
8+
轮转交给系统自带的 `newsyslog`(规则见 `deploy/newsyslog/`)
9+
- Linux systemd:journald 接管并自带轮转(`deploy/systemd/`)
10+
- Docker:json-file 驱动捕获,按 `logging.options` 限制大小
11+
(`docker-compose.yml` 已配,三平台统一)
12+
13+
应用自己写文件会把日志切成两份、与平台轮转争抢同一个文件,而且容器里
14+
写进镜像层重启即丢、`docker logs` 也看不到。所以这里只挂一个 stderr
15+
handler,文件与轮转全交给平台。
16+
17+
**为什么必须显式配置 root**
18+
uvicorn 的默认 `LOGGING_CONFIG` 只配置 `uvicorn` 与 `uvicorn.access`
19+
两个 logger(且 `propagate=false`),**从不配置 root**,而 root 默认
20+
`level=WARNING` 且无 handler。后果是应用里 `logging.getLogger(__name__)`
21+
的 INFO 被静默丢弃——`PROPOSAL §8` 要求的凭证审计日志(增删改/pin/
22+
账号切换)首当其冲,一条都不会落盘。
23+
"""
24+
25+
from __future__ import annotations
26+
27+
import logging
28+
import sys
29+
30+
# 带时间戳:launchd/newsyslog 重定向的文件里只有进程自己写的内容,
31+
# 没有 journald/docker 那种外部时间戳,格式必须自立
32+
LOG_FORMAT = "%(asctime)s %(levelname)-7s %(name)s: %(message)s"
33+
DATE_FORMAT = "%Y-%m-%d %H:%M:%S"
34+
35+
# 第三方库降噪:root 升到 INFO 后 httpx/httpcore 会给每个上游请求打一条
36+
# INFO,带完整 URL(可能含 query 参数,与 PROPOSAL §8「日志脱敏」冲突),
37+
# 且量级与请求数线性增长、把审计日志淡出视野。只保留它们的 WARNING+。
38+
_NOISY_LOGGERS = ("httpx", "httpcore")
39+
40+
41+
class _RootHandler(logging.StreamHandler):
42+
"""标记类:用于识别本模块已配置过的 handler,保证 configure_logging 幂等。
43+
44+
build_app 会被测试反复调用(每个用例一次),重复 addHandler 会让每条
45+
日志打印多遍,因此必须有可靠的「已配置」判定。
46+
"""
47+
48+
49+
def configure_logging(level: str = "INFO") -> None:
50+
"""配置 root logger:应用日志走 stderr(平台采集/轮转)。
51+
52+
幂等:重复调用只更新级别,不重复添加 handler。
53+
uvicorn 的 logger 不在此处配置——它自带的配置已经够用,且
54+
`disable_existing_loggers=false` 不会覆盖这里设置的 root。
55+
"""
56+
normalized = (level or "INFO").upper()
57+
root = logging.getLogger()
58+
root.setLevel(normalized)
59+
60+
handler = next((h for h in root.handlers if isinstance(h, _RootHandler)), None)
61+
if handler is None:
62+
handler = _RootHandler(sys.stderr)
63+
handler.setFormatter(logging.Formatter(LOG_FORMAT, DATE_FORMAT))
64+
root.addHandler(handler)
65+
handler.setLevel(normalized)
66+
67+
# 降噪而非禁用:默认(INFO 及以上)把这两个库压到 WARNING;
68+
# root 调到 DEBUG 时放开到 INFO,排查上游问题需要看请求详情
69+
noisy_level = logging.INFO if root.level <= logging.DEBUG else logging.WARNING
70+
for name in _NOISY_LOGGERS:
71+
logging.getLogger(name).setLevel(noisy_level)

0 commit comments

Comments
 (0)