第 9 周：trace 存到哪？用 Go 写一个能收、能存、能查的后端

上一讲做了一个 trace 查看器，读的是本地 JSON 文件。BugHunt-Bench 一晚上跑几百个任务，每个任务一条 trace，总得有个地方收、存、查。这一讲用 Go 写这个后端：三个 HTTP 接口，SQLite 存储，go test 覆盖。

接口本身几十行就能写完。值得花时间的是边界：请求体能有多大，字段拼错了怎么办，模型输出里带个单引号会不会把 SQL 弄坏，客户端超时重发会不会写出两份，8 个 worker 同时写会不会互相报 BUSY，翻页时有新数据进来会不会读到重复。每一条都对应一类线上事故，也都能用测试确定地复现。

讲解视频

互动演示

三个演示。第一个是请求流水线：用 JS 重写了服务端同样的校验和幂等逻辑，选一个预设（正常、原样重发、同 id 改内容、字段拼错、parent 成环、超大请求……）或者直接改请求体，看它停在哪一关、返回什么状态码，“数据库"里多了什么。第二个是注入对照：同一个 model 过滤值，字符串拼接和参数化各查出几条，几个预设的结果和真实 SQLite 跑出来的一致。第三个是翻页：OFFSET 和 keyset 并排翻，中途插入或删除数据，数重复和漏读。页面底部有自动判分的练习。

代码和环境

代码在学习目录的 week09_全栈/code/trace_server/，Go module 名 traced：

本机环境：Go 1.24.5（darwin/arm64），SQLite 驱动 modernc.org/sqlite v1.45.0（内置 SQLite 3.51.2），除它和它的间接依赖外只用标准库。所有数据都是合成的，不调任何模型 API。

数据格式是第 9 周三讲共用的约定（week09_全栈/code/trace_schema.md）：OTel 风格的 span，trace_id 32 位、span_id 16 位小写十六进制，根 span 的 parent_span_id 是空串，时间是 Unix 纳秒整数，status 是 {code, message}，attributes 是扁平的键值对，token 用 OTel GenAI 约定的 gen_ai.usage.input_tokens / gen_ai.usage.output_tokens。这些名字的来源见第 2 周「Agent 做错了，你怎么知道它错在哪一步？」。

驱动选哪个：modernc 还是 mattn

我选了 modernc：下一讲要把服务装进一个没有 C 运行库的极简镜像，纯 Go 省掉了 cgo 交叉编译这一摊事。

但这个选择有一个代价，查资料时才发现。SQLite 官网 WAL 文档第 11 节记了一个 “WAL-reset bug”：2026-03-03 发现，会在罕见情况下损坏数据库。官方说它可能存在于 3.7.0 到 3.51.2 的所有版本（3.44.6、3.50.7 两个回移版本已修复），3.51.3 修复。触发条件是 WAL 模式、同一个文件上开着两个以上连接、两个连接在同一瞬间写或者做 checkpoint。官网的原话是 “this is not an emergency”，但建议升级。modernc 从 v1.46.2 开始内置 3.51.3，而 v1.46.2 要求 Go 1.25（v1.46.0 / v1.46.1 仍是 Go 1.24、内置 3.51.2；以上看的是 goproxy 上各版本的 go.mod 和 v1.46.1 源码里的 SQLITE_VERSION）。也就是说，本机 Go 1.24 能用的 modernc 版本内置的 SQLite 都在受影响范围里。

为什么停在 v1.45.0 而不升到 v1.46.1：两者内置同一个 SQLite 3.51.2，升级对 WAL-reset bug 没有任何帮助；本文所有实验、测试和变异测试都是在 v1.45.0 上跑的，换版本就得全部重跑一遍，却换不来安全收益。真要解决这个问题，要升的是 Go 本身（见下段）。

我的处理：服务的写连接池只有 1 条连接（下面会讲为什么），读连接池加了 query_only，读连接不写数据。注意 query_only 并不阻止 checkpoint，pragma 文档的原话是 “the database is not truly read-only. You can still run a checkpoint or a COMMIT”。读连接不会触发自动 checkpoint，是因为自动 checkpoint 发生在"committing a transaction"之后（sqlite3_wal_autocheckpoint 文档），而读连接从不提交写事务。笔者分析：这样同一时刻只有一个连接会提交事务、触发自动 checkpoint，不满足"两个连接同时写或 checkpoint"的条件；但这是我按官方描述做的推断，官方没有这样的保证。真上线应该把 Go 升到 1.25 以上、用 modernc v1.46.2 以后的版本，或者换 mattn。

接口设计

路由用标准库。Go 1.22 的发布说明：net/http.ServeMux 的模式可以带方法和通配符，"POST /items/create" 只匹配 POST，/items/{id} 里的值用 Request.PathValue 取；注册 GET 也会同时注册 HEAD；两个模式重叠时更具体的优先，和注册顺序无关。

func (s *Server) Routes() http.Handler {
	mux := http.NewServeMux()
	mux.HandleFunc("POST /api/traces", s.postTrace)
	mux.HandleFunc("GET /api/traces", s.listTraces)
	mux.HandleFunc("GET /api/traces/{id}", s.getTrace)
	mux.HandleFunc("GET /healthz", s.healthz)
	mux.HandleFunc("GET /readyz", s.readyz)
	return s.logRequests(jsonMuxErrors(mux))
}

路径对上、方法不对时，ServeMux 自己回 405 并带上 Allow 头（Go 1.24.5 源码 net/http/server.go:2707-2708）。测试里 DELETE /api/traces/<id> 得到 Allow: GET, HEAD，PUT /api/traces 得到 Allow: GET, HEAD, POST。两个注意点：

• 这套新语义由 GODEBUG httpmuxgo121 控制（internal/godebugs/table.go:42，Changed: 22）。按 Go 的 GODEBUG 规则，默认值跟着主模块 go.mod 里的 go 版本走，go.mod 写的低于 1.22 时会退回旧行为：不只是 {id} 不再是通配符，带方法前缀的模式也不再按方法解析，整套路由都会失效。我用 Go 1.24.5 实测了同样两条路由：go.mod 写 go 1.21 时 POST /api/traces、GET /api/traces/abc 全部 404；改成 go 1.22 分别是 201 和 200（PathValue("id") 是 abc）。本项目写的是 go 1.24.0。
• ServeMux 自己回的 404 / 405 是纯文本。三讲约定错误一律是 {"error": "..."}，所以包了一层 jsonMuxErrors：先用 mux.Handler(r) 看有没有匹配到模式，没有就让 ServeMux 写进一个只记状态码和头的 writer，再按约定改写成 JSON，Allow 头原样保留。

列表接口的分页用游标而不是页码，后面单独讲。

五道校验：便宜的放前面

POST 的 handler 按代价从低到高排：

func (s *Server) postTrace(w http.ResponseWriter, r *http.Request) {
	if !s.authorized(r) {
		w.Header().Set("WWW-Authenticate", "Bearer")
		writeError(w, http.StatusUnauthorized, "缺少或错误的 Bearer token")
		return
	}
	if mt, _, err := mime.ParseMediaType(r.Header.Get("Content-Type")); err != nil || mt != "application/json" {
		writeError(w, http.StatusUnsupportedMediaType, "Content-Type 必须是 application/json")
		return
	}
	r.Body = http.MaxBytesReader(w, r.Body, s.cfg.MaxBodyBytes)
	t, err := trace.Decode(r.Body)
	if err != nil {
		var tooBig *http.MaxBytesError
		if errors.As(err, &tooBig) {
			writeError(w, http.StatusRequestEntityTooLarge, fmt.Sprintf("请求体超过 %d 字节", tooBig.Limit))
			return
		}
		writeError(w, http.StatusBadRequest, "请求体解析失败："+err.Error())
		return
	}
	if err := trace.Validate(t); err != nil {
		writeError(w, http.StatusBadRequest, err.Error())
		return
	}
	// ……幂等写入，见下文

1. 鉴权：配置了 TRACE_API_TOKEN_FILE 时，POST 要带 Authorization: Bearer <token>，用 crypto/subtle.ConstantTimeCompare 比较。GET 不鉴权（这是三讲约定的取舍，下一讲在部署层面再收口）。

2. Content-Type：用 mime.ParseMediaType 解析，application/json; charset=utf-8 也算对。

3. 体积上限：http.MaxBytesReader 包住 body。go doc 的说法：读超限时返回 *MaxBytesError（Go 1.19 加入，见 api/go1.19.txt），并且"如果可能"让 ResponseWriter 在超限后关闭连接。它不会替你回 413，状态码要自己用 errors.As 判断。上限默认 1 MiB，由 TRACE_MAX_BODY_BYTES 配置。

4. 严格解析：

   dec := json.NewDecoder(r)
   dec.DisallowUnknownFields()
   dec.UseNumber()
   

   DisallowUnknownFields：字段名拼错（nmae）直接 400，而不是被悄悄丢掉、存进去一条没有名字的 trace。UseNumber：属性里的数字保留原文（json.Number）。不开它的话数字会变成 float64，1.5 仍然能被 math.Trunc 判成非整数，但 80.0 或 1e3 会变成整数 80、1000 混过检查；开了以后原文 80.0 的 Int64() 会失败，被判成"不是整数”。另一个好处是超过 2^53 的整数不会被 float64 舍入。TestDecodeKeepsNumberText 经过真正的 Decode 测这两条：80.0 被拒，属性 9007199254740993 解码后原文不变；TestReplacedTraceKeepsAttributesExact 再测一遍存储往返保留原文。解码完再解一次，必须是 io.EOF，否则说明后面还有第二个 JSON 值。

5. schema 校验：trace_id / span_id 格式且不全为 0（OTel Trace API 规范：有效的 TraceId 是至少有一个非零字节的 16 字节数组，SpanId 是 8 字节，十六进制形式必须小写），span 数 1–2000，span_id 不重复，恰好一个根，parent 都存在且从根能走到每个 span（无环），name 非空且不超过 256 个字符，kind 是 OTel 的五种 SpanKind 之一，status.code 是 UNSET / OK / ERROR，end ≥ start，属性最多 128 个、值只能是标量，gen_ai.usage.* 必须是非负整数。错误消息带字段路径，比如 spans[1].end_time_unix_nano: 不能早于 start_time_unix_nano，调用方不用猜错在哪。

体积上限一定要在解析之前：先 io.ReadAll 再看长度，内存已经花出去了。还有一个不显眼的细节：一个合法的 JSON 后面跟一大串空白，第一次 Decode 不会超限，第二次（检查尾部）才读到上限。所以"检查尾部"那一步也要把 MaxBytesError 原样传出来，测试用例"合法 JSON 后面跟着超限的垃圾"专门测这一条。

还有一层在 handler 之外：http.Server 设了 ReadHeaderTimeout: 5s、ReadTimeout: 30s，防止客户端很慢地发请求头或请求体、一直占着连接。体积上限管"多大"，超时管"多慢"。

参数化 SQL：trace 里装的是模型输出

第 8 周「找 Bug 的测试 Agent，会踩到 OWASP LLM Top 10 的哪几条？」讲过 LLM10:2026 Improper Output Handling（2025 版编号是 LLM05）。它在常见漏洞里列了"LLM-generated SQL queries are executed without proper parameterization, leading to SQL injection."，预防措施第 5 条是 “Use parameterized queries or prepared statements for all database operations involving LLM output."（ 2026/final/LLM10_ImproperOutputHandling.md:23,35 ；这两句和 2025 版 LLM05 第 21、31 行逐字相同）。trace 服务正好是这种场景：span 名、模型名、工具参数、模型生成的文字都会进库，也都会被拿来当过滤条件。

列表的过滤条件是可选的，WHERE 子句只能动态拼。规则一句话：拼的只能是代码里写死的 SQL 片段，用户给的值一律走 ?。

if f.Model != "" {
	where = append(where, "EXISTS (SELECT 1 FROM spans s WHERE s.trace_id = traces.trace_id AND s.model = ?)")
	args = append(args, f.Model)
}
// ……status、name、since/until、游标同理
q := `SELECT trace_id, name, span_count, error_count, start_ns, end_ns, input_tokens, output_tokens FROM traces`
if len(where) > 0 {
	q += " WHERE " + strings.Join(where, " AND ")
}
q += " ORDER BY start_ns DESC, trace_id DESC LIMIT ?"

? 的值由驱动用 sqlite3_bind_text / sqlite3_bind_int64 绑定（modernc v1.45.0 conn.go:429、conn.go:463），作为值参与比较，永远不会被当成 SQL 解析。status 只允许 ok / error 两个值，映射到写死的 error_count > 0 / = 0，用户的字符串根本不进 SQL。游标也一样：它是 base64url 编码的"开始时间:trace_id”，解码后先校验格式（trace_id 必须是合法的 32 位十六进制），再作为参数绑定；被篡改的游标返回 400。

测试里放了一个反面教材（只在 _test.go 里，不会编进二进制）：

q := "SELECT count(*) FROM traces WHERE EXISTS (SELECT 1 FROM spans s WHERE s.trace_id = traces.trace_id AND s.model = '" + model + "')"

TestModelFilterIsNotInjectable 用同一个载荷 x' OR '1'='1 分别查：参数化版返回 0 条，拼接版返回全部 3 条。互动演示 2 里还能看到另外两种情况：x' OR 1=1 -- 让拼接版直接报 incomplete input（注释吃掉了收尾的括号），一个正常的模型名 o'neil-7b 也会让拼接版报语法错误。这些结果我在本机 Python sqlite3（SQLite 3.51.2）上对真实的表跑过，和演示一致。

GET /api/traces/{id} 的 id 在进数据库之前就按格式校验了，/api/traces/x' OR '1'='1 直接 400。这不是"防注入"（那条查询本来也是参数化的），而是不让明显无效的输入去占数据库的时间。

幂等写入：同一个 trace_id 发两次

第 5 周「超时了，再发一次安全吗？」用 Idempotency-Key 请求头做幂等，因为提交 Bug 报告这个操作本身没有天然的唯一标识。trace 不一样：trace_id 本身就是天然的幂等键，客户端生成一次，重试时不会变。

三讲约定写的是"同一 trace_id 重复上传时整条覆盖"。实现上多做一步指纹比较：

指纹是规范化 JSON 的 SHA-256：span 按开始时间、再按 span_id 排序，encoding/json 序列化 map 时按键排序，所以客户端换了 span 顺序、换了属性顺序也认得出是同一份。原样重发什么都不写，replaced 才说明内容真的变了。

err = s.inWriteTx(ctx, func(conn *sql.Conn) error {
	var old string
	err := conn.QueryRowContext(ctx, "SELECT fingerprint FROM traces WHERE trace_id = ?", c.TraceID).Scan(&old)
	switch {
	case errors.Is(err, sql.ErrNoRows):
		result = Created
	case err != nil:
		return fmt.Errorf("查询指纹: %w", err)
	case old == fp:
		result = Unchanged
		return nil // 什么都没写，提交一个空事务
	default:
		result = Replaced
		if err := deleteTrace(ctx, conn, c.TraceID); err != nil {
			return err
		}
	}
	return insertTrace(ctx, conn, c, fp)
})

“查指纹 → 删 → 写"在同一个 BEGIN IMMEDIATE 事务里。两个并发请求带着同一个 trace_id 进来，第二个要等第一个提交后才能开始读，不会两个都以为自己是"第一次”。TestConcurrentWritersAndReaders 让 16 个 goroutine 同时写同一条 trace：恰好 1 次 created、15 次 unchanged。

和第 5 周的取舍不同。第 5 周按 IETF 草案的建议，同键不同请求体回 422，拒绝；这里是覆盖，后到的赢。覆盖适合"客户端补全了属性后重发同一条 trace"。代价是：两个不同的运行如果撞了 trace_id（随机 128 位，正常不会撞；客户端 Bug 写死了 id 就会），前一条会被静默替换。所以响应里带 result，监控 replaced 的比例，异常升高时报警。代价之二：旧版本的请求如果因为网络延迟晚到，会覆盖已经写入的新版本（丢失更新）。需要时可以带版本号或 end_time，只接受更新的那份；本文的服务没有做这一步。

还有一个和指纹有关的跨端问题：纳秒时间戳约 1.76×10^18，超过 2^53。浏览器 JSON.parse 成 double 以后，这个量级上相邻两个 double 相差 256 ns（Python math.ulp(1759300000000000000.0) 核对过；在 Node 里 JSON.parse 末尾是 123 的时间戳，读出来末尾变成了 000）。前端显示毫秒级耗时没问题，但把解析后的数字再传回服务端，内容就变了，指纹也就变了。所以前端只该读这些时间戳，不该把解析后的数字原样回传。

WAL 与并发写：BUSY 从哪来

服务的连接配置：

q.Add("_pragma", fmt.Sprintf("busy_timeout(%d)", o.BusyTimeoutMS))
q.Add("_pragma", "foreign_keys(1)")
q.Add("_pragma", "synchronous(NORMAL)")

写连接池再加 journal_mode(WAL)、SetMaxOpenConns(1)，读连接池加 query_only(1)。modernc 在新建每一条连接时执行这些 _pragma（v1.45.0 conn.go:74 调 sqlite.go:136 的 applyQueryParams，busy_timeout 排在最前），连接池里的连接设置都一样。这一点要紧：busy_timeout 是连接级的设置，只在一条连接上执行一次 PRAGMA 的话，池里其他连接没有。

SQLite 官方文档里的几条事实：

• WAL 模式下"readers do not block writers and a writer does not block readers"，但 “since there is only one WAL file, there can only be one writer at a time”。
• journal_mode=WAL 是持久的，写进数据库文件，重新打开还是 WAL。
• WAL 要求所有进程在同一台机器上（共享内存），不能用在网络文件系统上。
• DEFERRED 事务先读后写时，“Subsequent write statements will upgrade the transaction to a write transaction if possible, or return SQLITE_BUSY”。
• busy handler 的文档：“If SQLite determines that invoking the busy handler could result in a deadlock, it will go ahead and return SQLITE_BUSY to the application instead of invoking the busy handler.”
• 扩展错误码 517 SQLITE_BUSY_SNAPSHOT：WAL 模式下读事务想升级成写事务，却发现别的连接已经写过、之前读到的快照作废了。

把这几条放到一起，我的推断是：只开 WAL、只加 busy_timeout，挡不住"先读后写"的并发写。为了验证，cmd/walbench 用服务真实的 Store.Put，换六种连接配置跑同样的负载：8 个 goroutine 各写 150 条 trace（每条 4 个 span），4 个 goroutine 同时不停地翻列表第一页，每种配置 3 轮。合成负载，数字只代表这台机器（Apple M1 Pro，10 核）这一次运行：

$ go run ./cmd/walbench
合成负载：8 个写 goroutine × 150 条 = 1200 次写入（每条 4 个 span），4 个读 goroutine 持续翻第一页；每种配置 3 轮

A rollback(DELETE) · 8 写连接 · busy=0 · DEFERRED
  第 1 轮：写成功    3  BUSY 1197  其他错 0 │     30 写/秒 │ 读  1901 次  BUSY  508  p99   0.94 ms
           错误码（主码 5 = SQLITE_BUSY，517 = BUSY_SNAPSHOT）：写 5×1197  读 5×508
  第 2 轮：写成功    1  BUSY 1199  其他错 0 │     10 写/秒 │ 读  1874 次  BUSY  521  p99   1.28 ms
           错误码（主码 5 = SQLITE_BUSY，517 = BUSY_SNAPSHOT）：写 5×1199  读 5×521
  第 3 轮：写成功    3  BUSY 1197  其他错 0 │     30 写/秒 │ 读  2331 次  BUSY  607  p99   1.00 ms
           错误码（主码 5 = SQLITE_BUSY，517 = BUSY_SNAPSHOT）：写 5×1197  读 5×607
B WAL · 8 写连接 · busy=0 · DEFERRED
  第 1 轮：写成功   98  BUSY 1102  其他错 0 │    899 写/秒 │ 读   970 次  BUSY    0  p99   1.60 ms
           错误码（主码 5 = SQLITE_BUSY，517 = BUSY_SNAPSHOT）：写 5×1037  写 517×65
  第 2 轮：写成功  105  BUSY 1095  其他错 0 │    992 写/秒 │ 读  1043 次  BUSY    0  p99   1.29 ms
           错误码（主码 5 = SQLITE_BUSY，517 = BUSY_SNAPSHOT）：写 5×1032  写 517×63
  第 3 轮：写成功  103  BUSY 1097  其他错 0 │    924 写/秒 │ 读   995 次  BUSY    0  p99   1.74 ms
           错误码（主码 5 = SQLITE_BUSY，517 = BUSY_SNAPSHOT）：写 5×1023  写 517×74
C WAL · 8 写连接 · busy=5s · DEFERRED
  第 1 轮：写成功   91  BUSY 1109  其他错 0 │    844 写/秒 │ 读   933 次  BUSY    0  p99   1.81 ms
           错误码（主码 5 = SQLITE_BUSY，517 = BUSY_SNAPSHOT）：写 5×1043  写 517×66
  第 2 轮：写成功   87  BUSY 1113  其他错 0 │    834 写/秒 │ 读   975 次  BUSY    0  p99   1.45 ms
           错误码（主码 5 = SQLITE_BUSY，517 = BUSY_SNAPSHOT）：写 5×1042  写 517×71
  第 3 轮：写成功  112  BUSY 1088  其他错 0 │    978 写/秒 │ 读  1084 次  BUSY    0  p99   1.54 ms
           错误码（主码 5 = SQLITE_BUSY，517 = BUSY_SNAPSHOT）：写 5×1026  写 517×62
D WAL · 8 写连接 · busy=5s · IMMEDIATE
  第 1 轮：写成功 1200  BUSY    0  其他错 0 │   1813 写/秒 │ 读 10897 次  BUSY    0  p99   0.69 ms
  第 2 轮：写成功 1200  BUSY    0  其他错 0 │   1741 写/秒 │ 读 10262 次  BUSY    0  p99   0.84 ms
  第 3 轮：写成功 1200  BUSY    0  其他错 0 │   1591 写/秒 │ 读 11767 次  BUSY    0  p99   0.92 ms
E WAL · 1 写连接 · busy=5s · IMMEDIATE（服务默认）
  第 1 轮：写成功 1200  BUSY    0  其他错 0 │   1904 写/秒 │ 读  9546 次  BUSY    0  p99   0.79 ms
  第 2 轮：写成功 1200  BUSY    0  其他错 0 │   1683 写/秒 │ 读 10717 次  BUSY    0  p99   0.86 ms
  第 3 轮：写成功 1200  BUSY    0  其他错 0 │   1835 写/秒 │ 读  9847 次  BUSY    0  p99   0.72 ms
F rollback(DELETE) · 1 写连接 · busy=5s · IMMEDIATE
  第 1 轮：写成功 1200  BUSY    0  其他错 0 │   1070 写/秒 │ 读  1906 次  BUSY    0  p99   9.88 ms
  第 2 轮：写成功 1200  BUSY    0  其他错 0 │   1061 写/秒 │ 读  1981 次  BUSY    0  p99  18.71 ms
  第 3 轮：写成功 1200  BUSY    0  其他错 0 │   1058 写/秒 │ 读  1816 次  BUSY    0  p99  10.31 ms

怎么读（都是在这个合成设定下）：

• A：rollback 日志、不等锁。1200 次写只成功 1–3 次，读也有 26%–28% 返回 BUSY。rollback 日志下写者提交时要等读者放锁，读者也会撞上写者。
• B：只开 WAL。读不再 BUSY 了，但写仍然九成以上失败（1095–1102 次）。错误里大部分是 5，少部分是 517：Put 先 SELECT 指纹再 INSERT，DEFERRED 事务从读升级到写的时候，别的连接已经在写或者已经写完。
• C：再加 5 秒 busy_timeout。失败数和 B 差不多（1088–1113）。这正是 busy handler 文档说的情况：可能死锁时不调用 busy handler，直接返回 BUSY。等多久都没用。
• D：改成 BEGIN IMMEDIATE。事务一开始就拿写锁，拿不到时才按 busy_timeout 排队，3 轮都是 0 失败。
• E：写连接只留 1 条。同样 0 失败，写/秒和 D 在同一个范围（D 1591–1813，E 1683–1904）。写本来就是串行的，多开写连接不会更快，只是把排队从 Go 的连接池挪到了 SQLite 的锁上。服务默认用 E，再加 IMMEDIATE 兜底：将来如果有别的进程也写这个文件，排队靠的仍然是 SQLite 的锁。
• F：rollback 日志、其他和 E 一样。写也是 0 失败，但读 p99 是 9.88–18.71 ms，E 是 0.72–0.86 ms。rollback 日志下读者要等写者提交。这个数波动很大，另一次运行同一配置是 34.32–79.02 ms。

B、C 的"读次数"只有 D、E 的十分之一左右，主要是整轮结束得早：写很快就失败了，读的时间窗口只有 0.10–0.12 秒（D、E 是 0.63–0.75 秒）。按每秒读次数算（本文推导：用打印出来的写成功数 ÷ 写/秒 反推每轮时长），B、C 每秒约 8650–9850 次，D、E 约 14890–16460 次，B、C 约为 D、E 的 53%–66%；p99 也高一倍左右（1.29–1.81 ms 对 0.69–0.92 ms）。笔者分析：8 条写连接在争锁，读也受影响。F 的读 p99 逐轮是 E 的 12.5、21.8、14.3 倍。

synchronous=NORMAL 也是一个取舍。SQLite pragma 文档：“WAL mode is safe from corruption with synchronous=NORMAL”，“A transaction committed in WAL mode with synchronous=NORMAL might roll back following a power loss or system crash. Transactions are durable across application crashes regardless of the synchronous setting or journal mode.” 也就是进程崩溃不丢数据，断电可能丢最近提交的几个事务。trace 丢了可以由客户端按 trace_id 重发（幂等），我认为可以接受；如果存的是不能重发的数据，就该用 FULL。

实验顺带抓到一个真 Bug：失败的 COMMIT 污染连接池

上面 A 配置第一次跑的时候，结果不是现在这样。1200 次写全部失败，而且有一半以上的错误是：

开始事务: SQL logic error: cannot start a transaction within a transaction (1)

一条连接上已经有一个没结束的事务，又被拿去开新事务。原因是两份文档放在一起：

• SQLite 事务文档：COMMIT 在 rollback 日志下可能因为有读者而返回 SQLITE_BUSY，“When COMMIT fails in this way, the transaction remains active and the COMMIT can be retried later”。
• Go 的 database/sql：Tx.Commit 一开始就把 tx.done 置为 true，然后调驱动的 Commit，不管成败都 tx.close(err) 把连接还回池里（Go 1.24.5 database/sql/sql.go:2287-2320）。之后再调 tx.Rollback() 只会返回 ErrTxDone，不会真的发 ROLLBACK。modernc 的 Commit 只是执行一句 commit（v1.45.0 tx.go:34-37），失败了也不收尾。

所以常见的 defer tx.Rollback() 写法在这里兜不住：COMMIT 返回 BUSY 以后，SQLite 那边的事务还开着、锁还占着，连接却回到了池里。下一个请求拿到它就是上面那个错误，而且它占着的锁让其他连接也写不进去。

先写一个确定性的测试把它复现出来（TestFailedCommitDoesNotPoisonConnection）：用 rollback 日志、busy_timeout=0，另开一个连接开读事务、真的读一行，拿住共享锁；这时 Put 的 COMMIT 必然 BUSY；然后放掉读者，再写一次，期望成功。修之前：

--- FAIL: TestFailedCommitDoesNotPoisonConnection (0.01s)
    commit_busy_test.go:52: COMMIT 失败之后的下一次写入："", 开始事务: SQL logic error: cannot start a transaction within a transaction (1)（连接被没结束的事务污染了）
FAIL

修法是不用 sql.Tx，在一条专用的 *sql.Conn 上手写 BEGIN / COMMIT，任何一步失败都补发 ROLLBACK：

func (s *Store) inWriteTx(ctx context.Context, fn func(*sql.Conn) error) (err error) {
	conn, err := s.w.Conn(ctx)
	if err != nil {
		return fmt.Errorf("取写连接: %w", err)
	}
	defer conn.Close()
	if _, err := conn.ExecContext(ctx, "BEGIN "+s.txLock); err != nil {
		return fmt.Errorf("开始事务: %w", err)
	}
	defer func() {
		if err == nil {
			return
		}
		// 用不会被取消的 context：请求已经超时或断开时也要把事务收掉
		if _, rbErr := conn.ExecContext(context.WithoutCancel(ctx), "ROLLBACK"); rbErr != nil {
			_ = conn.Raw(func(any) error { return driver.ErrBadConn }) // 让连接池丢弃这条连接
		}
	}()
	if err := fn(conn); err != nil {
		return err
	}
	if _, err := conn.ExecContext(ctx, "COMMIT"); err != nil {
		return fmt.Errorf("提交: %w", err)
	}
	return nil
}

ROLLBACK 也失败时，conn.Raw 回调返回 driver.ErrBadConn，database/sql 会关掉这条连接而不是放回池里（sql.go:2072-2097、2120-2125）。修完以后测试变绿，A 配置也从"全部失败"变成了上面的"偶尔成功"。

服务默认的 E 配置下这个 Bug 不太会触发：WAL 模式下提交不需要等读者。但"不太会"不等于不会，WAL 文档也写了 “there are some obscure cases where a query against a WAL-mode database can return SQLITE_BUSY”。这类问题平时不出现，一出现就是连接池里的连接一条条坏掉，排查起来很难，值得用一个确定性的测试钉住。

分页：为什么用游标不用 OFFSET

列表按开始时间倒序，同一时刻按 trace_id 倒序。下一页的条件是：

WHERE (start_ns, trace_id) < (?, ?)   -- 上一页最后一条
ORDER BY start_ns DESC, trace_id DESC LIMIT ?

(a, b) < (?, ?) 是 SQLite 3.15.0 起支持的行值比较。LIMIT 绑定的是 limit + 1：多取一条，用来判断有没有下一页，有就返回 next_cursor。本机 EXPLAIN QUERY PLAN（TestListUsesIndex 里打印）：

SEARCH traces USING INDEX traces_by_start ((start_ns,trace_id)<(?,?))

直接走 (start_ns DESC, trace_id DESC) 索引定位，没有出现 USE TEMP B-TREE FOR ORDER BY，不需要额外排序。

为什么不用 LIMIT 5 OFFSET 10？TestKeysetVsOffsetWhileInserting 造了 23 条 trace（每 3 条共用一个开始时间，专门制造并列），每页 5 条，读完第 1 页后插入 4 条更新的：

keyset 看到 23 条、无重复；OFFSET 看到 23 个不同 id、重复 4 条

新数据排在最前，把旧数据整体往后挤了 4 位，OFFSET 的第 2 页开头就是第 1 页的末尾。反过来，翻页期间删掉一条已经读过的，后面的数据整体前移，OFFSET 会漏读一条（互动演示 3 里可以点出来；服务目前没有删除接口，这一条只在演示里展示）。keyset 只看"上一页最后一条之后"，前面插入、删除都不影响。代价是不能直接跳到第 N 页，对 trace 列表这种"往下翻"的场景不是问题。

一个边界：replaced 时如果新内容的开始时间变了，这条 trace 在排序里的位置也变了，翻页过程中可能读到两次或者读不到。这是"覆盖"语义带来的，测试没有覆盖，记在这里。

测试：httptest、表驱动、-race

测试分三层：

HTTP 层大部分用 httptest.NewRecorder 直接调 handler，不经过网络，快而且确定；TestEndToEndOverHTTP 用 httptest.NewServer 起一个真实的本地端口，8 个客户端并发上传 40 条，再按 next_cursor 翻 6 页读回来，断言不重复、不遗漏。POST 的表驱动测试按顺序发到同一个 server 上，前面的请求会影响后面的结果，幂等那几条就是这样串起来的：

{"第一次上传", req{body: goodJSON}, 201, `"result":"created"`},
{"原样重发（客户端超时重试）", req{body: goodJSON}, 201, `"result":"unchanged"`},
{"同一 trace_id、内容变了", req{body: tracetest.JSON(tracetest.WithError(good))}, 201, `"result":"replaced"`},
// ……
{"超过体积上限", req{body: tracetest.JSON(big)}, 413, "超过 4096 字节"},
{"合法 JSON 后面跟着超限的垃圾", req{body: append(append([]byte{}, goodJSON...), bytes.Repeat([]byte(" "), limit)...)}, 413, "超过"},
{"不认识的字段", req{body: []byte(`{"trace_id":"` + tracetest.ID(2) + `","spans":[],"extra":1}`)}, 400, `unknown field \"extra\"`},

每个用例除了状态码，还断言错误响应的 Content-Type 也是 JSON。

运行结果

$ go version
go version go1.24.5 darwin/arm64
$ go vet ./... && go test -race -count=1 ./...
ok  	traced/cmd/traced	4.700s
?   	traced/cmd/walbench	[no test files]
ok  	traced/internal/api	5.365s
ok  	traced/internal/store	5.630s
ok  	traced/internal/trace	4.849s
?   	traced/internal/tracetest	[no test files]

go test -race -count=1 -v ./... 一共 26 个顶层测试（含 fuzz 的种子用例）、76 个子用例，全部通过，-race 没有报数据竞争。几个关键测试的输出：

--- PASS: TestRunServesAndShutsDownOnSIGTERM (0.03s)
--- PASS: TestEndToEndOverHTTP (0.11s)
--- PASS: TestFailedCommitDoesNotPoisonConnection (0.03s)
    pagination_test.go:80: keyset 看到 23 条、无重复；OFFSET 看到 23 个不同 id、重复 4 条
--- PASS: TestKeysetVsOffsetWhileInserting (0.18s)
    pagination_test.go:104: query plan: SEARCH traces USING INDEX traces_by_start ((start_ns,trace_id)<(?,?))
--- PASS: TestListUsesIndex (0.01s)
--- PASS: TestConcurrentWritersAndReaders (0.92s)
--- PASS: TestModelFilterIsNotInjectable (0.02s)

覆盖率（-coverpkg=traced/internal/...,traced/cmd/traced，不算实验程序 walbench）：

total:	(statements)	85.2%

低于 70% 的函数：main（0%，逻辑都在被测的 run 里）、readyz（57.1%，没测数据库不可写的 503 分支）、OpenWith（65.0%，打开失败的分支）、deleteTrace（60.0%，删除出错的分支）、intAttr、validateAttr（不经过解码、直接构造的 float64 / int 分支）。还有一条没覆盖的路径值得点名：inWriteTx 里 ROLLBACK 也失败、丢弃连接的分支，没有找到确定的办法触发它。

fuzz 跑了 20 秒：

$ go test -run '^$' -fuzz FuzzDecodeValidate -fuzztime 20s ./internal/trace/
fuzz: elapsed: 21s, execs: 643383 (0/sec), new interesting: 43 (total: 223)
PASS
ok  	traced/internal/trace	21.898s

约 64 万个输入（Go 在种子和已积累语料的基础上变异生成），Decode + Validate 没有 panic，通过校验的 trace 都能算出指纹。

测试会不会变红：变异测试

测试全绿只说明代码和测试一致，不说明测试能抓到 Bug。第 5 周的做法是先让测试在已知有 Bug 的实现上变红。这里反过来：把正确的实现故意改坏，看有没有测试变红。脚本每次复制一份代码、只改一处、跑 go test ./...：

$ python3 scripts/mutate.py
抓到  去掉 http.MaxBytesReader  <- TestPostTraces
抓到  去掉 DisallowUnknownFields  <- TestDecode, TestPostTraces
抓到  去掉 UseNumber  <- TestDecodeKeepsNumberText, TestGetRoundTripAndNotFound, TestPutIsIdempotent
抓到  model 过滤改成字符串拼接  <- TestModelFilterIsNotInjectable
抓到  默认改成 DEFERRED + 8 写连接  <- TestConcurrentWritersAndReaders, TestEndToEndOverHTTP
抓到  指纹不做规范化  <- TestFingerprintIgnoresOrder
抓到  失败时不补 ROLLBACK  <- TestFailedCommitDoesNotPoisonConnection
抓到  token 汇总所有 span  <- TestSummarizeCountsInferenceTokensOnly
抓到  token 只取根 span  <- TestSummarizeCountsInferenceTokensOnly
抓到  游标比较写成 <=  <- TestConcurrentWritersAndReaders, TestEndToEndOverHTTP, TestKeysetVsOffsetWhileInserting
抓到  不检查环  <- TestValidate
共 11 处：抓到 11，漏掉 0，变异无效 0

11 处都抓到了。脚本随代码提供：trace_server/scripts/mutate.py，在 trace_server 目录下 python3 scripts/mutate.py 直接运行，只用标准库，改动只发生在临时目录里。退出码非 0 但没有任何 --- FAIL（比如改坏后编译不过）记为"变异无效"，不算抓到。“默认改成 DEFERRED + 8 写连接"被并发测试抓到，说明上面 walbench 的结论在测试里也能复现，不只是一次实验。“token 汇总所有 span"那一条值得说一下：OTel GenAI 约定里 invoke_agent span 也可以带 gen_ai.usage.*（ model/gen-ai/spans.yaml:113-119 ）。笔者理解：在 agent span 上记的通常是它下面各次模型调用的汇总，规范本身没有规定这一点。把所有 span 的 token 加起来就可能重复计算，所以摘要只累加 gen_ai.operation.name 是 chat、text_completion、generate_content 的 span。合成样本的根 span 上故意放了 3500 / 260 的汇总值（故意和两个 chat span 之和不相等），两个 chat span 是 1200 + 1800、80 + 120，期望结果是 3000 / 200：全部相加会得到 6500 / 460，“只取根 span"会得到 3500 / 260，两种错误实现都会被测出来。

和上一讲、下一讲的接口

• 上一讲的查看器：GET /api/traces/{id} 返回的就是约定格式，可以直接画瀑布图。我把查看器 samples/ 里的合成 trace 逐个 POST 过，run07、run08、run09、run11 四个都是 201；codex_notifications.json 和 run10_otlp.json 是别的格式（Codex 通知流、OTLP），按约定返回 400。后端不返回 CORS 头，查看器通过下一讲的反向代理同源访问。
• 下一讲的部署：TRACE_ADDR、TRACE_DB_PATH、TRACE_MAX_BODY_BYTES、TRACE_API_TOKEN_FILE 四个环境变量；/readyz 真的往 health 表写一行，磁盘只读或满了会返回 503（它和 Put 共用唯一的写连接，有长事务时 2 秒超时可能误报 503，健康检查的阈值别设得太敏感）；traced healthcheck 子命令请求本机 /readyz，给没有 curl 的镜像做健康检查；收到 SIGTERM 时 http.Server.Shutdown 等进行中的请求做完再关库（TestRunServesAndShutsDownOnSIGTERM）。WAL 不能放在网络文件系统上、写只有一个，所以这个服务只能单副本运行，数据卷挂本地磁盘。

常见错误说法

• “开了 WAL 就能并发写”：WAL 让读写互不阻塞，写者同一时刻仍然只有一个。合成实验里只开 WAL，九成以上的并发写还是 BUSY。
• “设了 busy_timeout 就不会 BUSY”：DEFERRED 事务从读升级到写时，SQLite 可能不调用 busy handler，直接返回 BUSY。要用 BEGIN IMMEDIATE。
• "http.MaxBytesReader 会自动回 413”：它只返回 *http.MaxBytesError，状态码要自己判断。
• “把单引号转义了就不怕注入”：用参数绑定，值根本不进 SQL 文本；动态 WHERE 只拼代码里写死的片段。
• "defer tx.Rollback() 能兜住 Commit 失败”：database/sql 里 Commit 之后 Rollback 只返回 ErrTxDone；SQLite 的 COMMIT 返回 BUSY 时事务还开着，连接会带着它回到池里。
• “OFFSET 分页没问题，数据又不怎么变”：翻页期间有一条插入就会重复，有一条删除就会漏。
• “重复上传同一个 trace_id 就报错”：客户端超时重发是正常情况，按指纹判断是不是同一份，相同就当成功。

下一讲把这个服务和查看器装进容器，配好健康检查、配置和数据卷。