Skip to content

Commit ca14a60

Browse files
RobbsLuoRobbsLuo
committed
fix(ops): 日志轮转改截断式，修 quota_probe 探死号与日志噪声
macOS 的 newsyslog 只做 rename 式轮转（flags 无 copytruncate），而 launchd 给进程的 fd 仍指向旧 inode —— 轮转后进程继续往已归档文件里写，新路径的文件 直到下次重启才出现。实测 mv 后进程仍写 .old、新路径不存在；本机因此丢过 21.7h / 19.6h / 2.0h / 1.2h 日志，每次都止于一次重启。 - 新增 scripts/rotate-logs.sh：拷贝 → 压缩成功 → 截断，任何一步失败都不 截断（宁可继续涨，不丢未归档日志）。只用 bash 3.2 语法（launchd 拿的是 系统 /bin/bash，没有 mapfile）。阈值 10MB / 保留 7 份，可用 ROTATE_MAX_KB / ROTATE_KEEP / ROTATE_LOGS_DIR 覆盖。 - 新增 launchd 定时任务 com.coding2api.logrotate（每 6 小时，无 KeepAlive） 与 scripts/install-logrotate.sh。 - 移除 deploy/newsyslog/coding2api.conf 与 install-newsyslog.sh。 - 测试全部走 ROTATE_LOGS_DIR 临时目录：脚本按自身位置解析仓库根，在别的 cwd 里跑照样作用于真实 logs/（这条坑本次实际踩过）。 quota_probe 是唯一没过滤 disabled / enabled=0 的任务（refresh / checkin / growth / activity 都有）。实测容器实例对一条 10-15 就过期的硬禁用号每小时 探一次、7 天 160 次必然 401，白打上游并刷 WARNING。 停机排空窗口 30s 短于实测 p99（57.7s），7 天 27 次请求超 120s，日志留下 38 次 Cancel running task(s)。抬到 90s，同步 compose stop_grace_period 与 systemd TimeoutStopSec 到 95s，并给 launchd plist 补 ExitTimeOut=95 （launchd 默认约 20s）。 qoder 的 null content 归一提示降 DEBUG：它是成功路径的自动修复，实测占 err.log 的 19%（7 天 10309 行），把真 WARNING 挤出视野。
1 parent 254c691 commit ca14a60

17 files changed

Lines changed: 529 additions & 175 deletions

‎README.en.md‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -814,8 +814,11 @@ The app writes **stdout / stderr** only, never files, and does not rotate.
814814
| Docker / compose | `docker logs coding2api` | json-file (10m × 5) | none |
815815
| Linux (systemd) | `journalctl -u coding2api` | journald | none |
816816
| Linux (non-systemd) | redirected to files | `logrotate` | `sudo cp deploy/logrotate/coding2api /etc/logrotate.d/` |
817+
| macOS (launchd) | `logs/launchd.{out,err}.log` | `scripts/rotate-logs.sh` | `./scripts/install-logrotate.sh` |
817818
| Bare process | terminal stderr | none | redirect and rotate yourself |
818819

820+
> **Do not use newsyslog on macOS**: it only does rename-based rotation, but the fd launchd handed the process still points at the old inode — after rotation the process keeps writing into the archived file, the new path only appears on the next restart, and everything in between is lost (21.7h observed locally). `rotate-logs.sh` copies → compresses → truncates, matching `copytruncate` on the Linux side.
821+
819822
Level via `LOG_LEVEL` (default `INFO`). **Audit logging is INFO** and disappears at `WARNING`.
820823

821824
### Request-level structured log

‎README.md‎

Lines changed: 3 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -843,8 +843,11 @@ launchctl print gui/$(id -u)/com.coding2api.frpc | grep -E 'state|pid'
843843
| Docker / compose | `docker logs coding2api` | json-file（10m × 5） | 无需操作 |
844844
| Linux（systemd） | `journalctl -u coding2api` | journald 自带 | 无需操作 |
845845
| Linux（非 systemd） | 重定向到文件 | `logrotate` | `sudo cp deploy/logrotate/coding2api /etc/logrotate.d/` |
846+
| macOS（launchd） | `logs/launchd.{out,err}.log` | `scripts/rotate-logs.sh` | `./scripts/install-logrotate.sh` |
846847
| 裸跑 | 终端 stderr | 无 | 自行重定向并轮转 |
847848

849+
> **macOS 不要用 newsyslog**：它只做 rename 式轮转，而 launchd 给进程的 fd 仍指向旧 inode —— 轮转后进程继续往已归档的文件里写，新路径的文件直到下次重启才出现，中间日志全丢（本机实测丢过 21.7h）。`rotate-logs.sh` 走「拷贝 → 压缩 → 截断」，与 Linux 侧 `copytruncate` 同语义。
850+
848851
级别用 `LOG_LEVEL`（默认 `INFO`）。**审计日志 = INFO 级**，调到 `WARNING` 一并关掉。
849852

850853
### 请求级结构化日志

‎TECHNICAL.md‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -44,7 +44,7 @@ PROPOSAL.md 定方向，本文定实现。只写**当前代码现状**。
4444
| `src/api/` | `deps.py` `endpoints.py` `chat.py` `responses.py` `messages.py` `context.py` `models.py` `model_merge.py` `model_catalog.py` `balance.py` `authorize.py` `admin_credentials.py` `admin_keys.py` `admin_settings.py` `admin_users.py` `admin_audit.py` `admin_alerts.py` `admin_badges.py` `admin_upstream.py` `admin_model_catalog.py` `admin_model_availability.py` `logs.py` `activate.py` `admin_stats.py` `admin_auth.py` `playground.py` `streaming.py` `metrics.py` | Services 容器 + 鉴权依赖／`dispatch_compat` 骨架／三个 /v1 出口／压缩接线／`GET /v1/models`（SWR + 落盘 + 白名单）／归一·合并·别名（纯函数）／目录快照／余额／TRAE 回调／凭证运维／Key CRUD／配置与任务／用户／审计／告警／角标／上游状态／模型目录 + 探活／激活／统计／登录 + 上游登录／Playground／SSE 包装／`/metrics` |
4545
| `src/audit/actions.py` | — | 审计动作常量 + 中文标签 |
4646
| `web/` | — | React 前端。**`.npmrc` 的 `auto-install-peers=false` 与 lock 的 `settings.autoInstallPeers` 强耦合**（避免拉 `@lobehub/ui`/`antd` 子树）；`Dockerfile` 必须 `COPY web/.npmrc`，否则 `ERR_PNPM_LOCKFILE_CONFIG_MISMATCH` |
47-
| `deploy/` | — | launchd / newsyslog / logrotate / systemd 模板 |
47+
| `deploy/` | — | launchd / logrotate / systemd 模板 |
4848
| `diagrams/` | — | 架构图 / 时序图 / 状态机（HTML + 源 JSON） |
4949
| `scripts/` | — | 建号、回填、运维脚本 |
5050
| `tests/` | — | 按 `src/` 子包镜像 |

‎deploy/launchd/com.coding2api.logrotate.plist‎

Lines changed: 60 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,60 @@
1+
<?xml version="1.0" encoding="UTF-8"?>
2+
<!DOCTYPE plist PUBLIC "-//Apple//DTD PLIST 1.0//EN" "http://www.apple.com/DTDs/PropertyList-1.0.dtd">
3+
<!-- 模板：绝对路径写成 __PROJECT_ROOT__ 占位符，避免把开发机的路径带进仓库。
4+
安装时用 scripts/install-logrotate.sh 渲染成本机路径，写入
5+
~/Library/LaunchAgents/ 并加载。
6+
7+
为什么要有这个任务：macOS 的 newsyslog 只做 rename 式轮转，而 launchd
8+
重定向给服务的 fd 仍指向旧 inode —— 轮转后进程继续往已归档的文件里写，
9+
新路径的文件直到下次重启才出现，中间的日志直接丢失（实测丢过 21.7h）。
10+
本任务定时跑 scripts/rotate-logs.sh 做截断式轮转，语义与 Linux 侧
11+
deploy/logrotate/coding2api 的 copytruncate 一致。
12+
13+
StartCalendarInterval 而非 StartInterval：日志增长是缓慢的，每 6 小时看
14+
一次足够（10MB 阈值 ≈ 3 天一轮）。按整点跑便于与日志时间戳对照。 -->
15+
<plist version="1.0">
16+
<dict>
17+
<key>Label</key>
18+
<string>com.coding2api.logrotate</string>
19+
20+
<key>ProgramArguments</key>
21+
<array>
22+
<string>/bin/bash</string>
23+
<string>__PROJECT_ROOT__/scripts/rotate-logs.sh</string>
24+
</array>
25+
26+
<key>WorkingDirectory</key>
27+
<string>__PROJECT_ROOT__</string>
28+
29+
<!-- 每 6 小时一次：00/06/12/18 点 -->
30+
<key>StartCalendarInterval</key>
31+
<array>
32+
<dict>
33+
<key>Hour</key><integer>0</integer>
34+
<key>Minute</key><integer>17</integer>
35+
</dict>
36+
<dict>
37+
<key>Hour</key><integer>6</integer>
38+
<key>Minute</key><integer>17</integer>
39+
</dict>
40+
<dict>
41+
<key>Hour</key><integer>12</integer>
42+
<key>Minute</key><integer>17</integer>
43+
</dict>
44+
<dict>
45+
<key>Hour</key><integer>18</integer>
46+
<key>Minute</key><integer>17</integer>
47+
</dict>
48+
</array>
49+
50+
<!-- 轮转是幂等的一次性任务，跑完即退：不要 KeepAlive（会被立刻重拉） -->
51+
<key>RunAtLoad</key>
52+
<false/>
53+
54+
<!-- 轮转自身的日志：只记结果行，几十字节/次，无需轮转 -->
55+
<key>StandardOutPath</key>
56+
<string>__PROJECT_ROOT__/logs/logrotate.out.log</string>
57+
<key>StandardErrorPath</key>
58+
<string>__PROJECT_ROOT__/logs/logrotate.err.log</string>
59+
</dict>
60+
</plist>

‎deploy/launchd/com.coding2api.plist‎

Lines changed: 8 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -34,6 +34,14 @@
3434
<key>ThrottleInterval</key>
3535
<integer>10</integer>
3636

37+
<!-- SIGTERM → SIGKILL 的等待窗口。launchd 默认约 20s，短于应用侧的
38+
排空窗口（src/main.py GRACEFUL_SHUTDOWN_SECONDS=90），长流请求会被
39+
硬断、统计落不下来。这里给 95s（= 排空窗口 + 5s 余量），与
40+
docker-compose 的 stop_grace_period、systemd 的 TimeoutStopSec 同口径。
41+
tests/deploy/test_assets.py 锁定三处 >= 应用侧窗口。 -->
42+
<key>ExitTimeOut</key>
43+
<integer>95</integer>
44+
3745
<key>StandardOutPath</key>
3846
<string>__PROJECT_ROOT__/logs/launchd.out.log</string>
3947
<key>StandardErrorPath</key>

‎deploy/newsyslog/coding2api.conf‎

Lines changed: 0 additions & 28 deletions
This file was deleted.

‎deploy/systemd/coding2api.service‎

Lines changed: 3 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -37,13 +37,13 @@ Environment=HOST=127.0.0.1
3737
Environment=PORT=8000
3838
Environment=DATA_DIR=/opt/coding2api/data
3939

40-
ExecStart=/opt/coding2api/.venv/bin/python -m uvicorn src.main:build_app --factory --timeout-graceful-shutdown 30
40+
ExecStart=/opt/coding2api/.venv/bin/python -m uvicorn src.main:build_app --factory --timeout-graceful-shutdown 90
4141
Restart=always
4242
RestartSec=5
4343

44-
# SIGTERM 后在途请求排空窗口：必须 >= uvicorn 的 --timeout-graceful-shutdown(30)，
44+
# SIGTERM 后在途请求排空窗口：必须 >= uvicorn 的 --timeout-graceful-shutdown(90)，
4545
# 否则 systemd 会在 uvicorn 排空完成前 SIGKILL，长流请求被硬断、统计落不下来。
46-
TimeoutStopSec=35
46+
TimeoutStopSec=95
4747

4848
# 日志交给 journald（自带轮转）
4949
StandardOutput=journal

‎docker-compose.yml‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -231,9 +231,9 @@ services:
231231
# 应用监听 9000、映射却指向 8000，容器永远不 healthy。
232232
- "${PORT:-8000}:${PORT:-8000}"
233233
# 停机排空窗口：docker 发 SIGTERM 后等这么久再 SIGKILL。必须 >= 应用侧
234-
# uvicorn --timeout-graceful-shutdown(30，见 src/main.py GRACEFUL_SHUTDOWN_SECONDS)，
234+
# uvicorn --timeout-graceful-shutdown(90，见 src/main.py GRACEFUL_SHUTDOWN_SECONDS)，
235235
# 留 5s 余量让 uvicorn 排空完成、统计落库，再被强杀。
236-
stop_grace_period: 35s
236+
stop_grace_period: 95s
237237
volumes:
238238
# 凭证与统计（SQLite）与用户文件分开挂载
239239
- ./data:/app/data

‎scripts/install-logrotate.sh‎

Lines changed: 68 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,68 @@
1+
#!/usr/bin/env bash
2+
# 安装 macOS 日志轮转定时任务（launchd，无需 sudo）。
3+
#
4+
# ./scripts/install-logrotate.sh # 渲染 + 安装 + 加载
5+
# ./scripts/install-logrotate.sh --uninstall # 停止并移除
6+
# ./scripts/install-logrotate.sh --now # 安装后立即跑一次轮转
7+
#
8+
# 为什么不用 newsyslog：
9+
# macOS 的 newsyslog 只有 rename 式轮转（flags 无 copytruncate），而 launchd
10+
# 重定向给服务的 fd 仍指向旧 inode → 轮转后进程继续写已归档的文件，新路径
11+
# 的文件直到重启才出现，中间日志全丢（实测丢过 21.7h）。详见
12+
# scripts/rotate-logs.sh 顶部说明。
13+
#
14+
# 模板 deploy/launchd/com.coding2api.logrotate.plist 用 __PROJECT_ROOT__
15+
# 占位符；launchd 不展开环境变量，路径只能在安装时渲染成绝对路径。
16+
set -euo pipefail
17+
18+
ROOT="$(cd "$(dirname "${BASH_SOURCE[0]}")/.." && pwd)"
19+
LABEL="com.coding2api.logrotate"
20+
TEMPLATE="$ROOT/deploy/launchd/$LABEL.plist"
21+
DEST="$HOME/Library/LaunchAgents/$LABEL.plist"
22+
DOMAIN="gui/$(id -u)"
23+
24+
if [[ "${1:-}" == "--uninstall" ]]; then
25+
launchctl bootout "$DOMAIN/$LABEL" 2>/dev/null || true
26+
rm -f "$DEST"
27+
echo "已卸载 $LABEL 并移除 $DEST"
28+
exit 0
29+
fi
30+
31+
if [[ ! -f "$TEMPLATE" ]]; then
32+
echo "找不到模板: $TEMPLATE" >&2
33+
exit 1
34+
fi
35+
36+
mkdir -p "$(dirname "$DEST")"
37+
# LC_ALL=C：模板含中文注释，按字节替换占位符，避免 locale 改坏 UTF-8。
38+
LC_ALL=C sed "s|__PROJECT_ROOT__|$ROOT|g" "$TEMPLATE" > "$DEST"
39+
40+
if ! plutil -lint "$DEST" >/dev/null; then
41+
echo "渲染后的 plist 非法，已保留现场: $DEST" >&2
42+
exit 1
43+
fi
44+
45+
# 先卸载旧的（未加载时 bootout 会失败，忽略），再加载新定义。
46+
# bootout 是异步的：立即 bootstrap 会撞上「Input/output error」，小睡重试。
47+
launchctl bootout "$DOMAIN/$LABEL" 2>/dev/null || true
48+
loaded=1
49+
for _ in 1 2 3 4 5; do
50+
sleep 1
51+
if launchctl bootstrap "$DOMAIN" "$DEST" 2>/dev/null; then
52+
loaded=0
53+
break
54+
fi
55+
done
56+
if [[ "$loaded" -ne 0 ]]; then
57+
echo "bootstrap 失败：launchd 迟迟未释放旧实例，稍后手动重跑本脚本" >&2
58+
exit 1
59+
fi
60+
echo "已安装: $DEST（每 6 小时按阈值截断式轮转）"
61+
echo "查看状态: launchctl print $DOMAIN/$LABEL | grep -E 'state|last exit'"
62+
echo "手动跑一次: launchctl kickstart $DOMAIN/$LABEL"
63+
64+
if [[ "${1:-}" == "--now" ]]; then
65+
echo "== 立即执行一次 =="
66+
"$ROOT/scripts/rotate-logs.sh" --dry-run
67+
echo "（上面是 dry-run；真要轮转请直接跑 ./scripts/rotate-logs.sh）"
68+
fi

‎scripts/install-newsyslog.sh‎

Lines changed: 0 additions & 55 deletions
This file was deleted.

0 commit comments

Comments
 (0)