Files
tamabox/outputs/TamaBox-v4-keyset-pagination-timezone-incident-2026-09-05.md
T
tamakyi e3e59e7c69 chore: baseline snapshot before moderation-strictness feature
Repo .git was damaged (refs/ missing, index truncated, object store near-empty).
Repaired via git init (rebuilt refs), stale index preserved as .git/index.corrupt-20260910.bak,
then full worktree committed as a rollback baseline.
2026-09-10 10:56:27 +08:00

147 lines
9.9 KiB
Markdown
Raw Blame History

This file contains ambiguous Unicode characters
This file contains Unicode characters that might be confused with other characters. If you think that this is intentional, you can safely ignore this warning. Use the Escape button to reveal them.
# TamaBox 提问箱「加载更多」翻页重复事故复盘(时区偏移根因 + timestamptz 迁移修正)
- **日期**:2026-09-05(排查 01:57–04:35 左右,约 2.5 小时闭环)
- **影响范围**:线上 `box.tama.guru` 全部「提问箱历史」列表(单题页 `/_/{domain}/{id}` 与用户主页底部内嵌同一列表)
- **最终结论**:两层缺陷叠加——① 服务端游标解析的时区偏移导致 keyset 分页失效(直接根因);② 为根治而做的 timestamptz 迁移解释基准选错,导致存量时间整体 +8h(次生事故,已二次修正)
- **状态**:✅ 全部修复并线上验证通过
---
## 一、现象与影响
| 现象 | 影响 |
|---|---|
| 提问列表首屏 20 条加载完后「加载更多」按钮仍存在 | 点击后**追加与首页完全相同的内容** |
| 按钮永不消失,可无限点击重复 | 用户困惑;若服务端异常则无限膨胀 DOM |
线上 API 实测复现:携带首页返回的 `next_cursor` 再次请求,返回**完全相同的第 1 页 20 条**,`has_more=true`、游标不变。
---
## 二、关键环境事实(排查中确认)
| 项 | 值 | 备注 |
|---|---|---|
| 线上 schema | `nekobox`(非 public,默认 search_path 找不到) | 首版诊断脚本"关系不存在"根因 |
| `questions` 表 | `id numeric`(seq)、`user_id bigint`、`answer text`、`is_private/is_pinned/is_read boolean` | 与源码 GORM 模型基本一致 |
| **时间列** | `created_at/updated_at/deleted_at = timestamp WITHOUT time zone`(6) | **与源码 AutoMigrate 默认 timestamptz 不一致**——本次两大事故的共同土壤 |
| 实际含无时区时间列的表 | 仅 4 张:`questions / users / censor_logs / upload_images`(12 列) | 其余表(messages/conversations/votes 等)本为 timestamptz |
| 服务端进程/会话时区 | Asia/Shanghai(+08:00) | 与无时区列叠加构成偏移 |
| aoi 箱 | user_id=329,已答公开 38 条 | 与线上 API 总数一致 |
分页链路:前端 `templates/question/history-template.html`(Alpine fetch)→ `route/question/page.go ListAPI` → `internal/db/questions.go GetByUserID`,PinFirst 复合键集游标 `<isPinned>.<UnixNano>.<id>`,排序 `is_pinned DESC, created_at DESC, id DESC`,`page_size=20` 多取 1 条探测 `has_more`。
---
## 三、排查时间线
| 时间(约) | 事件 | 结果/判断 |
|---|---|---|
| 01:57–02:30 | 线上复现 + 全链路代码走查 | 前端模板与 0904 源码逐字符一致;排除 CDN 缓存(回源 MISS);**服务端游标被无视** |
| ~02:30 | 对照实验 | 任意格式游标均返回首页/个别怪异结果(空集、固定 6 条、38 条全量)——源码逻辑无法解释,疑似版本不一致 |
| 02:39 | 产出 v1 PG 诊断脚本 | 用户执行报"关系不存在"→ 定位 schema=nekobox |
| ~03:00 | 产出 v2 诊断脚本(search_path + 无时区列 + 时区诊断) | **DB 层洗清**:38 条 keyset 翻页不重不漏、无时区列读写文本对称、nano 指纹精确命中 |
| ~03:10 | 首次部署 0904(含防重兜底)后复测 | **仍复现**——推翻"部署版本旧"假设 |
| ~03:15 | 读 `parsePinCursor` 源码 + 本地 tz 实验 | 🔴 **真根因**:`time.Unix(0, nano)` 按服务器本地时区还原,+8h 墙钟发给无时区列比较恒真 → keyset 失效 |
| ~03:25 | 修复 `.UTC()` + 编译测试 | `go build`/`go vet` PASS |
| ~03:30 | 用户重新部署 | 线上翻页**38 条唯一收敛** ✓;非法/旧格式游标返回空+`has_more=false` ✓ |
| ~03:40 | 克隆库 timestamptz 迁移全套验证 | epoch 前后 0 差异、指纹一致、翻页同款、回滚路径无损 |
| 04:02 | 线上执行迁移 | 4 表 12 列转 timestamptz,验收 3.1–3.4 全绿(epoch 一致、残余 0) |
| ~04:20 | 端到端验收 | 38 条唯一收敛 ✓,但**发现 created_at 文本从 Z 变 +08:00** |
| 04:27 | 用户反馈「真实本地 00:01 的提问页面显示 08:01」 | 🟠 **次生事故确认**:迁移解释基准用错(见第五节) |
| 04:30–04:35 | 克隆库验证反向修正 → 线上执行 → API 验收 | created_at 回到本地墙钟、`next_cursor` nano 变化、38 条收敛 ✓ |
---
## 四、直接根因(第一层):游标解析时区偏移
```go
// 修改前(internal/db/questions.go parsePinCursor)
return isPinned, time.Unix(0, nano), uint(idVal), true
// ↑ 返回「服务器本地时区」的时间
```
**机制**:
1. 服务端把某行 `created_at`(无时区列读出后带 UTC 标记)转 `UnixNano` 下发(nano = UTC 绝对时刻)。
2. 解析时 `time.Unix(0, nano)` 返回 **Local(Asia/Shanghai)** 时间 → 墙钟数字 +8h(00:01 → 08:01)。
3. 驱动把该参数发往 **无时区列** 比较时按墙钟直发 → `created_at < '2026-09-05 08:01:16'` 对库内全部 `00:xx` 行**恒为真** → keyset 条件退化为"全部行" → **永远返回第一页 + has_more=true → 无限重复**。
4. 之前线上"空集 / 固定 6 条 / 38 条全量"等怪异现象,均为偏移后游标落在数据窗口不同位置的表现。
**修复**:`time.Unix(0, nano)` → `time.Unix(0, nano).UTC()`(绝对时刻语义,与列值墙钟对齐)。同时补充两层防重兜底:
| 文件 | 改动 |
|---|---|
| `internal/db/questions.go` `parsePinCursor` | `time.Unix(0, nano).UTC()` ← **根治一行**(附时区约定注释) |
| `internal/db/questions.go` `GetByUserID` | 游标解析失败**不再静默回退首页**,返回空列表 → `has_more=false` 收敛 |
| `internal/db/questions.go` `getBy`(旧路径) | 同步改为解析失败返回空,保持一致 |
| `templates/question/history-template.html` | SSR/JS 条目都带 `data-qid`;点击时按已渲染 id 集合**过滤重复**,无新增即 `more=false` 隐藏按钮 |
> 注:其余 `UnixNano` 用途(随机种子/文件名)无 keyset 风险,未受影响。
---
## 五、次生事故(第二层):timestamptz 迁移基准选错,存量 +8h
### 5.1 数据真实语义的判定
存量无时区列存的是**上海本地墙钟**(如 `00:01:16` = 用户凌晨 00:01 提问)。证据:用户以现实锚点反馈"真实本地 00:01 的提问页面显示 08:01"。
**此前 v2 诊断的认知盲区**:`DB 墙钟 == 线上 JSON Z 文本` 只能证明**读路径文本一致**——驱动把无时区列读出值标记为 UTC 输出,文本恰好等于库内墙钟数字,形成"读写对称"假象;它**不能证明**墙钟的世界语义是 UTC。而驱动写入无时区列时按进程本地墙钟落库 → 真实语义其实是**上海墙钟**。
### 5.2 错误迁移及其后果
首版迁移用 `USING created_at AT TIME ZONE 'UTC'`(把墙钟当 UTC 解释)→ 存量绝对时刻整体 **+8h** → 页面显示比真实晚 8 小时。迁移前页面显示"00:01"(无时区列按 UTC 直显,文本恰巧等于上海墙钟)反而是对的。
### 5.3 反向修正
```sql
ALTER TABLE nekobox.questions
ALTER COLUMN created_at TYPE timestamptz
USING (created_at AT TIME ZONE 'UTC' AT TIME ZONE 'Asia/Shanghai');
-- 净效果:绝对时刻 -8h;语义 = 原墙钟按 Asia/Shanghai 解释;与会话时区无关
```
克隆库整段演练通过后线上执行,API 验证:
| 验证点 | 修正前(错误) | 修正后(正确) |
|---|---|---|
| 3089 会话显示 | `2026-09-05 08:01:16.678885+08` | `2026-09-05 00:01:16.678885+08` |
| 3089 epoch | `1788566476678885000` | `1788537676678885000` |
| 3109 | `08:49:38+08` | `00:49:38.648502+08` |
| 2411 | `06-18 06:30:19+08` | `2026-06-17 22:30:19.615754+08` |
| API `next_cursor` nano 段 | `0.1788566476678885000` | `0.1788537676678885000` |
| 翻页收敛 | — | 38 条唯一 ✓ |
---
## 六、经验教训(预防清单)
| 级别 | 教训 | 落地动作 |
|---|---|---|
| 🔴 P0 | **无时区时间列与带时区应用代码混用是事故土壤** | 代码约定:所有时间列应统一 timestamptz;任何 `time.Unix`/`time.Parse` 进 keyset/SQL 比较路径必须显式 `.UTC()` 并在注释写明约定 |
| 🔴 P0 | **迁移解释基准必须先锚定数据真实语义**,不能只看"转换前后 epoch 一致" | 迁移前用 1–2 条**用户可确认真实时刻**的记录做锚点(如"这条我实际几点发的"),或写一条测试数据核对显示 |
| 🟠 P1 | "DB 墙钟 == JSON 文本"不能证明世界语义 | 读路径文本一致 ≠ 写路径语义正确;需结合写入方(驱动对无时区列的落库行为)判断 |
| 🟠 P1 | 线上行为无法用源码解释时,先怀疑**时区/列类型**再怀疑部署版本 | 本次"部署后仍复现"正是锁定 `.UTC()` 的关键转折 |
| 🟡 P2 | psql `\i` 长输出会进分页器截断 | 运维长脚本建议开头 `\pset pager off`,或分段执行 |
---
## 七、脚本/文档产物清单(`outputs/`)
| 文件 | 用途 | 状态 |
|---|---|---|
| `pg-cursor-pagination-diagnose.sql` | v1 诊断(默认 public schema,被 schema 问题阻住) | 已被 v2 取代 |
| `pg-cursor-diagnose-v2-nekobox.sql` | v2 诊断(search_path=nekobox,洗清 DB 层) | 完成使命 |
| `timestamptz-migration-online.sql` | 首版迁移(UTC 基准)——**含错误基准,勿复用** | ⚠️ 已被 fix-8h 修正 |
| `timestamptz-migration-fix-8h.sql` | 反向修正(Asia/Shanghai 基准) | ✅ 线上已执行;**不可重跑**(会再 -8h) |
| 本文档 | 事故复盘留档 | ✅ |
## 八、最终状态与遗留建议
- **线上已闭环**:翻页 38 条唯一收敛;存量时间回到真实本地墙钟;timestamptz 类型层根治,keyset 不再依赖进程时区。
- **遗留建议(按需排期)**:
1. 页面强刷后人工抽查时间显示(SSR 与「加载更多」追加项应一致)。
2. 可选:应用层 JSON 序列化统一 `.UTC()` 输出 Z(若存在外部消费者依赖 UTC 文本)。
3. 本地克隆测试实例(127.0.0.1:5433)与 dump 副本已无用途,可清理。
4. 生产库 `DROP SCHEMA diag_test CASCADE;` 清理诊断快照表。