Files
dsh_ai1net_server/dsh-server-docs/04-调整方案/129-日志采集与巡检-方案C实现.md
T

227 lines
14 KiB
Markdown
Raw Normal View History

# 日志采集 · 实时巡检 · 事后溯源(方案 C 实现)
- 版本:**v1 实现稿**(2026-09-18)
- 状态:✅ **已实现 · 本机实测通过**(工具 = 代码仓 `scripts/dshlog.mjs`)
- 上游决策:**方案 C** —— 不装新日志服务(不装 Amber / 不装 Loki+Alloy),靠现有 journald + 自研观测面
- 取消的候选:Amber(无预编译产物 / 单维护者 / 落盘异步不去重 ⇒ 与"日志原文行数"类判据冲突)· Loki+Alloy(组件数与内存代价,规模未到)
- 复跑入口:`"E:/ProgramData/.workbuddy/binaries/node/versions/22.22.2-3/node.exe" scripts/dshlog.mjs help`
---
## 0. 一句话
**一条 CLI 把 47 / 106 的 journald 拉回本机按天归档;跨机时间线一键重建;巡检规则命中即出判据表与非零退出码。** 服务器侧**零安装、零新增端口、零常驻进程** —— 远端只用系统自带的 `journalctl`。
---
## 1. 现状取证(为什么只能走这条路)
| 事实 | 实测值(2026-09-18) | 含义 |
|---|---|---|
| 47 日志分布(当日) | `dshs` 29274 · `dshs-worker` 7312 · `sshd` 3830 · `init.scope` 3155 · `dshs-relay` 830 | 主角是**四层单元**:Manager / Worker / relay / PG |
| 106 日志分布 | `user@0` 2604 · `init` 1575 · `crond` 728 · `sshd` 339 | 同一套单元命名,靠 `host` 字段区分 |
| journald 形态 | 两机均 **persistent**(`/var/log/journal/<machine-id>/`);47 = 769 MB · 106 = 130 MB | 可直接增量拉取;**但两机都没设上限**(默认吃磁盘 10%) |
| 时钟 | 两机 **NTP 均已同步**(`timedatectl NTPSynchronized=yes`) | 跨机时间线**不需要自造校时** |
| 用户实例(`dsh --profile`) | `_SYSTEMD_UNIT=dsh-<uid>-<hash>.scope` **无任何条目**;`journalctl _PID=<实例pid>` **无条目**;实例 `fd/1` 指向 `socket:[…]` | 🔴 **实例 stdout 不进 journald** —— 它被 Worker 用 socket 接管,只有 Worker 愿意转发的那部分才落在 `dshs-worker` 里 |
| journalctl 版本 | 47 = systemd **239** · 106 = 255 | `--output-fields` 两机都支持(用 `awk NR==1` 取版本号,别用正则猜) |
---
## 2. 架构(三层,无新增常驻组件)
```text
[采集] 47 / 106 的 journalctl -o json ← 远端只读,不写任何文件
│ ssh -C(压缩,见 §6.1)
▼
[归档] E:/dsh-logs/<host>/<YYYY-MM-DD>.ndjson.gz ← gzip 多成员追加,按天分片
E:/dsh-logs/state.json ← 每节点 cursor / lastTs / NTP 状态
E:/dsh-logs/hosts.json ←(可选)节点清单,缺省用内置
▼
[使用] q(查询)· timeline(溯源)· watch(巡检)· stats / ls / prune(运维)
```
**三条不可让步的设计约束**
1. **零新增常驻服务 / 零新增监听口** —— 不装 agent、不开端口、远端不落任何脚本(`bash -s` 走 stdin);符合 R5 的"权限只准收窄"。
2. **日志原文保真** —— `msg` 字段逐字落盘(本项目大量判据依赖日志原文的行数/字节数);非 UTF-8 字节转义为 `\xNN` 保留。
3. **"拉取失败" 与 "确无日志" 永不混淆** —— 数据走 stdout、元信息走 stderr 哨兵 `__DSHLOG_EOF__ rc= errbytes=` + `__DSHLOG_LINES__ n`;两条通道物理分离。
---
## 3. 三个目标 → 怎么满足
| 目标 | 命令 | 判据 |
|---|---|---|
| **不同节点/设备的日志存储** | `collect`(增量 cursor 续拉 / `--since` 回填) | 四态:`OK` / `EMPTY` / `MISMATCH`(远端报数与本地解析数不等) / `FAIL`;非 OK 即退出码 2 |
| **快速排查线上运行问题** | `q <词\|/正则/>` · `timeline` | `q` 支持跨机跨单元、时间窗、正则;`timeline` 把多机日志按时间戳合并成单条时间线 |
| **实时 bug 监控** | `watch`(默认先自动增量续拉再巡检) | 8 条规则 → 判据表 `PASS/FAIL`;有 FAIL ⇒ 退出码 2(可作自动化判据) |
| **事后溯源分析** | `timeline --from --to --grep --out` | 带毫秒排序 + `host/unit` 归属 + `pri`;输出可落文件归档 |
---
## 4. 用法
```bash
N="E:/ProgramData/.workbuddy/binaries/node/versions/22.22.2-3/node.exe"
# ① 拉取:首次回填 / 之后增量
$N scripts/dshlog.mjs collect --since 6h --chunk 2h # 回填(自动去重)
$N scripts/dshlog.mjs collect # 增量:只搬 cursor 之后的新行
# ② 查询
$N scripts/dshlog.mjs q "EADDRINUSE" --since 24h
$N scripts/dshlog.mjs q "/no-trusted-keys|信任链/" --host 106 --limit 20
# ③ 事后溯源(把一次故障从两机日志里拼出来)
$N scripts/dshlog.mjs timeline --from 2026-09-18T16:00 --to 2026-09-18T17:00 \
--grep "overlay|relay" --out E:/dsh-logs/tl-1617.log
# ④ 巡检(实时监控入口)
$N scripts/dshlog.mjs watch --since 30m --report # 有 FAIL ⇒ rc=2
$N scripts/dshlog.mjs watch --since 30m --json # 机器可读
# ⑤ 运维
$N scripts/dshlog.mjs stats --detail # 归档分布(按节点/日期/单元 top4)
$N scripts/dshlog.mjs prune --keep 14 # 保留策略(默认干跑,--apply 才删)
```
**扩展新节点**(用户说的"不同设备"):在 `E:/dsh-logs/hosts.json` 加一条即可,命令无需改动。
```json
{ "47": { "ssh": ["-p", "22", "[email protected]"], "label": "Manager + w-47" },
"106": { "ssh": ["-p", "22", "test106"], "label": "w-106" } }
```
---
## 5. 实测基线(2026-09-18 21:0x–21:2x)
| 项 | 实测 |
|---|---|
| 当日归档量 | 47 = **35,603 行** · 106 = **5,988 行**(gzip 后 47 ≈ 0.3 MB) |
| 回填 6 h(3 块 × 2 h) | **2 分 28 秒**(含首次去重重读);单块上限受链路带宽支配 |
| 增量续拉(1 块,含去重) | **19.5 秒** |
| 单块原始体积 | 47 ≈ 1.6 MB / 小时(未压缩,全字段) |
| 巡检扫描 41,226 行(6 h 窗口) | **< 3 秒**(纯本地 gzip 顺序扫) |
| 跨机时间线 | 6 h 窗口内 41k 行,毫秒级排序,秒级完成 |
**压缩是最大杠杆**(见 §6.1):47 出方向未压缩实测 **~20 KB/s**(1.6 MB 要 84 秒),开 `ssh -C` 后同样数据 **11 秒**。
---
## 6. 关键设计(每条都有实测出处,别改回去)
### 6.1 🔴 `ssh -C` 不可省 —— 7.6× 提速
实测同一块数据(1 h,1.6 MB)真传到本机:**不带 `-C` = 84 s** vs **带 `-C` = 11 s**。
JSON 日志压缩率极高;`-C` 的开销是两端 CPU(1.6 MB 约几十毫秒),完全值得。
⚠️ 不加 `-C` 时表现为"像是卡死了"(第一版跑 3 h 回填超过 5 分钟被外层超时杀掉,误判为代码 hang)。
### 6.2 数据/元信息**双通道**
远端脚本把 `journalctl` 的 stdout 逐行 `awk` 转发(数据),同时把**行数**写 stderr(`__DSHLOG_LINES__`),末尾再补 `__DSHLOG_EOF__ rc=… errbytes=…`(元信息)。
⇒ `"确无日志"(0 行)` 与 `"拉取失败"(无哨兵 / rc≠0)` 在同一份输出里**天然可分** —— 这是本项目反复踩过的坑,此处按机制而非纪律解决。
### 6.3 归档是 **gzip 多成员**追加,且必须**同步写**
- 每次 `appendFileSync` 追加一个完整 gzip 成员 ⇒ `gunzip` / node `createGunzip` 都能顺序读回(已实测:596 + 248 两个成员读出 844 行)。
- ⛔ 不能用 `createWriteStream` 异步管道 —— 进程收尾时可能未 flush,**静默丢最后一批**。
### 6.4 回填必须去重,续拉必须用 cursor
- **续拉**(无 `--since`):`journalctl --after-cursor=<cursor>` —— 精确、不重不漏。
- **回填**(有 `--since`):先把已有分片的 `__CURSOR` 读进 Set,落盘时跳过 ⇒ 实测一次回填跳过 8100 行重复。
⛔ 不去重会让"行数类判据"直接失真。
### 6.5 校时用 **NTP 状态**,不要自造往返估算
第一版用 `(远端date + 本地往返/2)` 估偏移,实测给出 **+1337 ms** 的假偏移(47 的 ssh RTT 达 3.7 s 且往返不对称)⇒ 拿它做校正会**制造**错序。
改为读 `timedatectl show -p NTPSynchronized`:两机都是 `yes` ⇒ **不校正**,`timeline` 默认输出原始系统时间戳,并把 NTP 状态打在末尾。
### 6.6 版本号解析必须 `awk 'NR==1{…}'`
`journalctl --version` 是**多行**输出;不限定行会让变量变成 `"239\n0"` ⇒ `[: integer expression expected` ⇒ 静默退回全字段(体积翻倍)。
症状是"结果没错但慢一倍",只在 `err:` 里留一行噪声。
### 6.7 巡检规则要**收紧到指向本项目故障**(误报比漏报更贵)
实测踩过的两条反例:
- `fatal` 裸写 ⇒ sshd 的 `ssh_dispatch_run_fatal`(客户端网络断)天天命中 ⇒ 收紧为 `PANIC|FATAL ERROR|unhandled…` + 排除 `sshd/crond/systemd-logind` 噪声单元。
- `Stopped .*` 裸写 ⇒ 实例**正常退出**(用户关会话)会打 `Stopped /usr/bin/bwrap …` ⇒ 收紧为 `Failed with result|start request repeated|Main process exited, code=…`。
当前 8 条规则:进程级致命 / 内存被杀 / 端口连接失败 / 权限属主 / 磁盘写入 / **覆盖网络信任链被拒** / HTTP 5xx / 服务异常终止。
> 实测有效:WATCH-06 在 106 上命中 `⚠ 取目录全部失败 ⇒ 回落到内置种子地址本身` —— 正是**序 ㉗ 记录的 E3 缺口**(106 候选链退化为单点),属真报。
---
## 7. 边界(红线遵守情况)
| 项 | 状态 |
|---|---|
| 新增公网监听口 | ⛔ **0 个**(只读 ssh,未改 nft / nginx / 任何监听) |
| 服务器侧新增常驻进程 / 安装 | ⛔ **0 个**(只用系统自带 `journalctl`;脚本走 `bash -s` stdin,不在远端落文件) |
| 生产值改动 | ⛔ **0 处** |
| 权限 | 只读:`journalctl` 读取无需提权以外的任何放行;ssh 用既有连接 |
| 归档位置 | `E:/dsh-logs/`(E 盘;**不在** git 仓库内) |
---
## 8. 已知限制与未做项(如实登记)
1. 🔴 **实例层(`dsh --profile`)日志目前抓不到** —— 实例 stdout 被 Worker 用 socket 接管,**不进 journald**(`_SYSTEMD_UNIT=…scope` 与 `_PID=` 均为空,已双重取证)。当前只能拿到 Worker 转发的部分。
⇒ **这是本方案最大的剩余缺口**;要补需改 Worker 的 stdout 接管方式(属改代码,另立一单),或让实例自己写日志文件(需确认官方 dsh 是否支持日志落文件,受 R2 约束)。
2. **本机(WorkBuddy 开发机)未纳入** —— 本机是 Windows,无 journald;其日志在 `~/.workbuddy/logs/`,与"线上运行"关联弱,暂不入归档。
3. **全文检索是线性扫描** —— 当前量级(每日 4 万行)毫秒级;若到 GB 级需换索引(届时正是上 Loki 的信号,见上游评估的触发条件)。
4. **未设置 journald 上限** —— 两机 `/etc/systemd/journald.conf` 均为空(默认 10% 磁盘)。47 已 769 MB。建议后续加 `SystemMaxUse=`,避免日志本身成为磁盘事故源。
5. `--threshold` 目前是**全规则统一阈值**,未做逐规则独立阈值。
### 8.1 日志保留策略 = 3 天(2026-09-18 落地)
**服务器侧**(两机均写 drop-in,⛔ 不覆盖主配置 `/etc/systemd/journald.conf`):
```ini
# /etc/systemd/journald.conf.d/10-retention.conf
[Journal]
MaxRetentionSec=3d # 时间上限(用户口径"只保留3天的日志")
SystemMaxUse=512M # 47 / 106 用 192M —— 容量兜底,防单日风暴吃满磁盘
SystemMaxFileSize=32M # 47 / 106 用 8M —— 压小分片,提高"3 天"判定精度
```
**本机归档**:`dshlog prune --keep 3 --apply`(默认干跑;默认保留 3 天,与服务器同口径)。
**🔴 关键实测:`--vacuum-time` 的判据是「分片起始记录时间」,且按**整片**删除**
⇒ 实际保留期 = **3 天 −(0 ~ 一片跨度)**。分片越大,"3 天"缩水越严重。
这解释了为什么必须同时压小 `SystemMaxFileSize`:
| 机 | 分片跨度(默认 128M 时) | 清理后实际保留 | 压小分片后预期 |
|---|---|---|---|
| 47 | ~128M ≈ **1.5 天/片** | **1.35 天** ❌ | 32M ≈ 6h/片 ⇒ 2.75~3 天 |
| 106 | ~47M ≈ **3 天/片** | **2.44 天** ❌ | 8M ≈ 9h/片 ⇒ 2.6~3 天 |
⚠️ **一次执行的偏差记录(如实留档)**:首次清理**未预判该判据**,按"末记录时间"估算,实测多删了一片 ——
47 释放 608 MB(768→160 MB)、106 释放 59.5 MB(130→70 MB),但**保留期分别只有 1.35 天 / 2.44 天**,未达 3 天。
受影响而**永久丢失**的区间:47 = 09-15 13:33 ~ 09-17 13:05;106 = 09-13 12:54 ~ 09-16 11:29(本机归档当时也尚未覆盖该区间 ⇒ 无副本)。
⇒ **47 的保留跨度会随新数据每日增长约 1 天,约 1.7 天后自然恢复到 3 天并稳定**(无需人工干预)。
---
## 9. 待你拍板
**是否挂周期自动化做"实时"巡检**:
**A. 挂 automation 每 30 分钟跑一次 `watch`,仅 FAIL 时出报告(推荐)**
优点:真"实时",异常半小时内可见,且只在有 FAIL 时才有可读产出。
缺点:每天 48 次新会话,按本项目实测的自动化成本(每轮 5–9 积分)估算约 **250–430 积分/天**,成本可观。
**B. 挂 automation 每天 1 次汇总(如 08:00)**
优点:成本低(约 5–9 积分/天),能发现"过夜积累"的问题。
缺点:不是实时;白天的突发故障要等次日,或靠人工跑 `watch`。
**C. 不挂,保持按需手动执行**
优点:**零成本**,需要时一条命令 10–20 秒出结果;当前平台规模小(47 仅 0–2 实例),"现拉现看"足够。
缺点:无人自动发现问题,依赖你或我主动去查。
我的倾向:**先 C,等出现一次"事后才发现"的线上问题再上 A** —— 理由是本项目已有 `overlay-probe.cjs` 这类主动探针承担"判据式巡检",`watch` 的价值主要在**事后取证**;而实时性的成本(积分)与当前规模不匹配。若你认为线上稳定性优先于积分,直接上 A(我按"每 30 分钟 + 仅 FAIL 出报告"落地)。