#!/usr/bin/env bash # 从网关 access log 判定「SSE 那批邮件到底投没投出去」——**只读**,不碰数据、不碰服务。 # # ## 为什么它必须在版本控制里(而不是 .tmp/) # # `.tmp/` 在 .gitignore:12 ⇒ 写在 `.tmp/stress-test.sh` 里的判据**下一轮就没了**, # 而 `docs/DEBTS.json` 里 `stress-sse-delivered-but-silent-no-assertion` 那笔债会长期裸着。 # 判据和账本必须同寿命,所以它住 scripts/。 # # ## 它替代的是什么 # # 原判据只有两个读数:「起了 worker」(桥日志「命名同步」)与「真没投出」。 # 2026-09-28 那轮把两者拆开后,仍漏一档:**worker 起来之后有没有把正文取到手里**。 # 本脚本产出**三个分开的读数**,外加一条「取信是否被归档阻断」的判据。 # # ## ★ 三个读数必须分开报,不能合成一个「成功率」 # # ① 投递成立 = 有 mail_reads 行(markDelivered 的指纹,间隔 ~4~12ms) # ② 起了 worker = 桥日志有「命名同步」 # ③ 取到正文 = access log 里 `GET /agent/mail/{id}` 返回 200 **且响应大小与 body 长度相关** # # 「投了但没人回信」是**协议设计**(Agent 来信不自动转发),不是丢信 —— # 它与「没投出」在库里**同形**(都只有一封、都 status=read、都有 reader_name='pi' 一行)。 # ⇒ 只看库永远分不开,必须靠 ② ③ 这类库外读数。 # # 用法: # ALIASES='stress-sse-1-18730,stress-sse-2-24857' bash scripts/sse-delivery-audit.sh # SINCE='2026-09-28 10:05' UNTIL='2026-09-28 10:40' DB=/opt/agentmail/data/agentmail.db \ # bash scripts/sse-delivery-audit.sh set -euo pipefail DB="${DB:-/opt/agentmail/data/agentmail.db}" UNIT="${UNIT:-agentmail-gateway}" SINCE="${SINCE:-1 hour ago}" UNTIL="${UNTIL:-now}" BRIDGE_LOG="${BRIDGE_LOG:-}" # 可选:桥日志路径,给读数 ② ALIASES="${ALIASES:-}" # 可选:逗号分隔别名;不给则自动取 stress-sse% 全部 command -v sqlite3 >/dev/null || { echo "需要 sqlite3" >&2; exit 2; } command -v journalctl >/dev/null || { echo "需要 journalctl" >&2; exit 2; } [ -r "$DB" ] || { echo "读不到 $DB" >&2; exit 2; } # ───────────────────────────────────────────────────────────── # 0b. 落临时文件前先证明「临时目录写得进去」 # # ★★★ 同一个坑的第二个器官(2026-09-28 实撞): # /tmp 那个 tmpfs 涨到 100% 满时,mktemp 与重定向**双双失败**, # 而下面那行 `|| true` 会把「写不进去」和「一条都没投出」**变成同一个 0**。 # 症状:脚本 exit 1、stdout/stderr **各 0 字节**,连 `bash -x` 都没有 trace。 # ⇒ 曾经我据此以为「脚本自己有 bug」,其实是磁盘满。 # ⇒ 所以:先自检可写,失败就 **exit 2**(环境问题),绝不留一个 0 让下游推理。 # ───────────────────────────────────────────────────────────── tmp_probe=$(mktemp 2>/dev/null) || tmp_probe="" if [ -z "$tmp_probe" ] || ! printf 'x' > "$tmp_probe" 2>/dev/null; then { echo "❌ 临时目录不可写(mktemp/重定向失败)——**这不是「没投出」,是环境问题**。" echo " 症状会伪装成:第 1 档输出「取信请求 0 条」、且本档**不出读数**。" echo " TMPDIR=${TMPDIR:-<未设,走 /tmp>}" echo " 排查: df -h \$(df -d /tmp --output=target 2>/dev/null || echo /tmp)" echo " 临时绕过: TMPDIR=\$PWD/.tmp-audit bash \$0" } >&2 [ -n "$tmp_probe" ] && rm -f "$tmp_probe" 2>/dev/null exit 2 fi rm -f "$tmp_probe" # ───────────────────────────────────────────────────────────── # 0. 先证明「这条判据本身能命中」——否则后面所有 0 都不可信 # ───────────────────────────────────────────────────────────── echo "=== 0. 判据自检(命中 0 时不许把 0 写进结论)===" # ⚠ 这条路径的 query 有五种形态,见下。**不要假设参数顺序**。 # ?workspace=…&session_id=… / ?session_id=…(无 workspace) / ?session_id=…&workspace=… # /thread?workspace=…&session_id=… / /thread?offset=…&session_id=… # 写成 grep '…?workspace' 会静默漏掉 43 条(2026-09-28 实测)。 # # ★★ 另一个坑(这个脚本第一版就踩了,且症状与「没投出」**完全一样**): # access log 的行尾形状是 # "GET HTTP/1.1" from 127.0.0.1:PORT - 200 956B in 9.17ms # URL 与状态码之间隔着 `" from 127.0.0.1:PORT`。 # ⇒ 写成 `\?[^ ]* - 200` **匹配不到**(`[^ ]*` 撞在空格上就停了), # 第 1 档会静默输出「取信请求 0 条」。 # ⇒ 必须用 `\?.* - ` 让它跨过那段。 FETCH_RE='GET http://[^ ]*/api/v1/agent/mail/[0-9a-f-]{36}\?.* - ([0-9]{3}) ([0-9]+)B' # /thread 单独排除:它取的是往来树,不是正文。 THREAD_RE='agent/mail/[0-9a-f-]{36}/thread\?' log_all() { journalctl -u "$UNIT" --since "$SINCE" --until "$UNTIL" --no-pager 2>/dev/null; } probe=$(log_all | grep -cE 'api/v1/agent/mail/[0-9a-f-]{36}\?' || true) if [ "$probe" -eq 0 ]; then cat >&2 <<'EOF' ❌ 自检失败:该窗口内 `/api/v1/agent/mail/{id}?` 一条都没有。 在断定「没投出」之前,先排除这三种「静默归零」: 1) 路径写错(人类侧 /mail/{id} 本来就没有流量,Agent 走 /agent/mail/{id}) 2) 窗口不对(★ DB 存 UTC、journalctl 打印本地时区,本项目差 8 小时; 按本地时间写 SQL 会整段落空 —— 10:09 本地 = 02:09 UTC) 3) unit 名不对(systemd 服务名不是 agentmail-gateway) 三者都排除后,才可以说「0」。 EOF exit 3 fi echo " 自检通过:该窗口有 $probe 条 /agent/mail/{id}? 取信请求(判据能命中)" cat <<'EOF' 口径(2026-09-28 那轮实测,用来对照别把数读歪): 全部 /agent/mail/*(含 /thread) 347 其中非 thread 203 ← 真正的「取全文」 非 thread 且 UUID 合法 202 ← 本脚本报的数 差 1 条 = UUID 畸形的请求(服务端 400) 非 thread 的 query 形态:?workspace=…&session_id=… 159 / ?session_id=…(无 workspace)43 / ?session_id=…&workspace=… 1 EOF # ───────────────────────────────────────────────────────────── # 1. 读数 ③ 取信是否成功(含「是否被归档阻断」这条独立判据) # ───────────────────────────────────────────────────────────── echo echo "=== 1. 读数 ③:取信(GET /agent/mail/{id},不含 /thread)===" tmp_fetches=$(mktemp) || { echo "❌ mktemp 失败(临时目录不可写)" >&2; exit 2; } trap 'rm -f "$tmp_fetches"' EXIT log_all | grep -E "$FETCH_RE" | grep -vE "$THREAD_RE" \ | sed -E 's/.* ([0-9]{2}:[0-9]{2}:[0-9]{2}).*agent\/mail\/([0-9a-f-]{36})\?.* - ([0-9]{3}) ([0-9]+)B.*/\1 \2 \3 \4/' \ > "$tmp_fetches" || { echo "❌ 写入 $tmp_fetches 失败(磁盘满?)——**不是「没投出」**" >&2; exit 2; } # ⚠ 不要加 `|| true`:那会把「写失败」和「窗口内一条都没有」压成同一个 0。 # grep 无匹配本来就会 exit 1,那是**合法**的 0 —— 交给第 0 档自检去判。 total=$(wc -l < "$tmp_fetches" | tr -d ' ') echo " 取信请求 $total 条,状态码分布:" awk '{print " " $3}' "$tmp_fetches" | sort | uniq -c | sort -rn ok200=$(awk '$3==200' "$tmp_fetches" | wc -l | tr -d ' ') not200=$(awk '$3!=200' "$tmp_fetches" | wc -l | tr -d ' ') echo " 200 = $ok200,非 200 = $not200" if [ "$not200" -gt 0 ]; then echo " ⚠ 非 200 的 mail_id 是否还在库里?**不在 ⇒ 是发信失败回滚(DeleteMailByID),与归档无关**" echo " (2026-09-28 实测 4 条即如此:3×404 + 1×400,那 4 个 mail_id 库里已不存在)" fi # ───────────────────────────────────────────────────────────── # 2. 读数 ①:投递成立(mail_reads = markDelivered 指纹) # ───────────────────────────────────────────────────────────── echo echo "=== 2. 读数 ①:投递成立(mail_reads 行)===" if [ -n "$ALIASES" ]; then inlist=$(printf ",%s," "$ALIASES" | sed 's/^,//; s/,$//' | sed "s/'/''/g; s/[^,']*/'&'/g") scope="s.session_alias IN ($inlist)" else # ⚠ 别名有「带字面引号」和「不带」两种形态(2026-09-28:33 条含 ",其中 26 条是 stress-sse)。 # 只查其中一种会得到一个**真实但无关**的数字。LIKE '%…%' 两种都覆盖。 scope="s.session_alias LIKE '%stress-sse%'" fi sqlite3 -header -column "$DB" " SELECT COUNT(*) AS 会话数, SUM(EXISTS(SELECT 1 FROM mails m WHERE m.session_id=s.session_id)) AS 有信, SUM(EXISTS(SELECT 1 FROM mails m WHERE m.session_id=s.session_id AND EXISTS(SELECT 1 FROM mail_reads r WHERE r.mail_id=m.mail_id))) AS 有投递标记 FROM sessions s WHERE $scope;" echo " ⇒ 有投递标记 = 投递成立(markDelivered 紧跟投递打,间隔 ~4~12ms)" # ───────────────────────────────────────────────────────────── # 3. 读数 ③的强度:响应大小 vs body 长度 # ★ 别把「~950B」当逐封正文到手的证明 —— 那是**路径的通用信封大小**。 # 真判据是**相关性**:若 body 不在响应里,r 应 ≈ 0。 # ───────────────────────────────────────────────────────────── echo echo "=== 3. 读数 ③的强度:pearson(body 长度, 响应字节数) ===" echo " (2026-09-28 实测 n=164 时 r=0.9968 ⇒ 响应确实带 body)" if command -v python3 >/dev/null; then python3 - "$DB" "$tmp_fetches" <<'PY' import sqlite3, sys, math db = sqlite3.connect(sys.argv[1]); pairs = [] for line in open(sys.argv[2]): p = line.split() if len(p) != 4 or p[2] != '200': continue r = db.execute("SELECT length(body) FROM mails WHERE mail_id=?", (p[1],)).fetchone() if r and r[0] is not None: pairs.append((r[0], int(p[3]))) if len(pairs) < 8: print(f" 样本不足(n={len(pairs)},需 ≥8)⇒ 本档**不出读数**,别硬凑") sys.exit(0) n = len(pairs); mx = sum(a for a, _ in pairs)/n; my = sum(b for _, b in pairs)/n cov = sum((a-mx)*(b-my) for a, b in pairs) sx = math.sqrt(sum((a-mx)**2 for a, _ in pairs)); sy = math.sqrt(sum((b-my)**2 for _, b in pairs)) r = cov/(sx*sy) if sx and sy else 0.0 print(f" n={n} r={r:.4f} body {min(a for a,_ in pairs)}..{max(a for a,_ in pairs)}B" f" 响应 {min(b for _,b in pairs)}..{max(b for _,b in pairs)}B") print(" ⇒ r 高 ⇒ 响应带 body(非空壳)。**这证明「服务端发出了 body」," "不证明「worker 交给了模型」** —— 后者只有桥侧证据。") PY else echo " (无 python3,跳过本档)" fi # ───────────────────────────────────────────────────────────── # 4. 读数 ②:起了 worker(桥日志「命名同步」) # ───────────────────────────────────────────────────────────── echo echo "=== 4. 读数 ②:起了 worker(桥日志「命名同步」)===" if [ -n "$BRIDGE_LOG" ] && [ -r "$BRIDGE_LOG" ]; then grep -c "命名同步" "$BRIDGE_LOG" | sed 's/^/ 命名同步条数:/' echo " ⚠ 这只证明 worker 起来了,**不证明它取到了正文**(那是上面第 3 档)" else echo " 未提供 BRIDGE_LOG,跳过。传 BRIDGE_LOG=<桥日志路径> 启用。" echo " ⚠ 没有这一档时,② 与 ③ 不可互相替代 —— 两者是不同的失败模式。" fi # ───────────────────────────────────────────────────────────── # 5. 归档这条独立判据(不与上面任何一档混) # ───────────────────────────────────────────────────────────── echo echo "=== 5. 归档:别名寻址是否已死 ===" sqlite3 -header -column "$DB" " SELECT s.status AS 会话状态, COUNT(*) AS 条数, SUM(NOT EXISTS(SELECT 1 FROM mails m WHERE m.session_id=s.session_id AND m.status <> 'archived')) AS 会案内仍有非归档邮件 FROM sessions s WHERE $scope GROUP BY 1;" cat <<'EOF' ⇒ 取信(AgentGetMail → AgentMayReadSession)**不**看 sessions.status ⇒ 归档不阻断取信 (判据在源码:repo/session_workspace.go 的 AgentMayReadSession 只比 scope == target)。 ⇒ 但**收件箱**(ListInboxScoped)与**别名寻址**(FindNamedSessionFor)都带 status <> 'archived' ⇒ 归档后原地址是**死信地址,回信投不进去**。后果更重,别与「取不到信」混为一谈。 EOF # ───────────────────────────────────────────────────────────── # 6. 半活会话:归档是否被「复活」 # 签名唯一 —— 旧 TouchSession 只盖 sessions.status,不碰 mails; # ArchiveSession 两条都盖。⇒ sessions=active 而 mails=archived 只可能来自 # 「先归档、后 touch」。这比读 updated_at 可靠:updated_at 会被任何写入改, # 这张两表状态分叉不会。 # ───────────────────────────────────────────────────────────── echo echo "=== 6. 半活会话(sess=active 但 mail=archived ⇒ 归档后被复活)===" sqlite3 -header -column "$DB" " SELECT s.session_alias, s.updated_at, COUNT(*) AS 归档邮件数 FROM sessions s JOIN mails m ON m.session_id = s.session_id WHERE $scope AND s.status = 'active' AND m.status = 'archived' GROUP BY 1,2 ORDER BY s.updated_at;" half=$(sqlite3 "$DB" " SELECT COUNT(*) FROM (SELECT 1 FROM sessions s JOIN mails m ON m.session_id=s.session_id WHERE $scope AND s.status='active' AND m.status='archived' GROUP BY s.session_id);") echo " 半活会话数:$half" if [ "$half" = "0" ]; then echo " ⇒ 该范围内无半活会话。" else cat <<'EOF' ⚠ **非 0 就说明归档被绕过了**:这批会话的 mails 已是 archived(归档确实发生过), 但 sessions.status 又是 active。后果 = 别名寻址/收件箱里它又「活着」, 而它的信已被归档 —— **「已归档」与「还活着」并存**。 ⇒ 别用 `sessions.status` 单表判断归档是否生效,要连 mails.status 一起看。 EOF fi # ───────────────────────────────────────────────────────────── # 6b. ★ 反向分叉:sess=archived 而 mail<>'archived' # 这是 6 的**镜像**,而且**成因至今是活的**: # deploy/archive-stale-sessions.sh:105 归档时只 UPDATE sessions, # 同一个事务里没有 UPDATE mails ⇒ 每跑一次 sweeper 就多一批。 # 它的回滚脚本(:147)同样只写 sessions ⇒ 回滚会把这些邮件一次性放回收件箱。 # ⚠ session_status_invariant_test.go:70 查的正是这个方向,但只在 t.TempDir() # 的空库上跑 ⇒ 存量分叉它永远看不见(实测生产已有 28 会话 / 431 封)。 # 两个方向要一起查:s.status 与 mails.status 的四种组合里, # 只有「全 active」和「全 archived」自洽,另两种都是分叉。 # ───────────────────────────────────────────────────────────── echo echo "=== 6b. 反向分叉(sess=archived 但有非 archived 邮件 ⇒ 归档没盖到 mails)===" sqlite3 -header -column "$DB" " SELECT s.session_alias, COUNT(*) AS 总邮件, SUM(m.status <> 'archived') AS 非归档邮件, SUM(m.status = 'unread') AS 其中未读 FROM sessions s JOIN mails m ON m.session_id = s.session_id WHERE $scope AND s.status = 'archived' AND m.status <> 'archived' GROUP BY 1 ORDER BY 非归档邮件 DESC;" rev=$(sqlite3 "$DB" " SELECT COUNT(*) FROM (SELECT 1 FROM sessions s JOIN mails m ON m.session_id=s.session_id WHERE $scope AND s.status='archived' AND m.status<>'archived' GROUP BY s.session_id);") revmail=$(sqlite3 "$DB" " SELECT COUNT(*) FROM sessions s JOIN mails m ON m.session_id=s.session_id WHERE $scope AND s.status='archived' AND m.status<>'archived';") echo " 反向分叉会话数:$rev 涉及非归档邮件:$revmail 封" if [ "$rev" = "0" ]; then echo " ⇒ 该范围内无反向分叉。" else cat <<'EOF' ⚠ **非 0 说明归档只盖了 sessions、没盖 mails**。后果比半活更直接: · 收件箱 ListInboxScoped 带 `s.status <> 'archived'` ⇒ 这些信**完全不可见**; · 别名寻址 FindNamedSessionFor 同样带该谓词 ⇒ **回信投不进去**(死信地址); · 但 sweeper 的回滚脚本只把 sessions 改回 active ⇒ 回滚会**一次性把它们全放回来**, 「回滚」在这里是放大器而不是修复。 ⇒ 归档语义必须两表一起判:`ArchiveSession` 已经是对的(两条 UPDATE), 缺的是 `deploy/archive-stale-sessions.sh`(归档与回滚都只写 sessions)。 EOF fi