瀏覽代碼

feat(ac15): 代价可读 —— 报告尾部打 SQL 执行次数与耗时 + README 自伤清单

一、代价计数(stats.go)
挂在 gorm 的 logger.Trace 上:它是每条 SQL 的必经之路(Query/Row/Exec/Raw 全走它),
不会漏。按 callback 分类型注册要漏一个就少算一类,而"少算"在报告上表现为"次数偏低",
读的人只会以为"没有额外开销"。Trace 里**不执行 fc**(执行会真渲染 SQL 字符串,白白变慢)。

报告尾部固定一行(实测 35 条):
  代价:SQL 执行 1870 次 | 耗时 12.377s | 平均 53.4 次/case | 平均 354ms/case

为什么要有:活动域快照让带活动种子的 case 多打 12 次库(六表 × 两侧)。
没有这个数,"慢了"只能等跑不动才发现,而那时已分不清"读得对只是慢"与"读错了靠重试掩盖"——
前者可以晚点优化,后者必须立刻修、优化只会把错误藏更深。

二、README §18.3「自伤清单」五种方式(都不产生明显症状,只让判据变松或整块消失)
  1 新字段对旧 case 为空被当成两侧不等/相等 → 空值必须 Skipped,nil 不许比出相等
  2 字段加错结构体(本次真踩到:Activity 加到 SideResult)→ 编译期偶尔报 undefined,
    若该字段没人读就永远 nil、零症状 → 每个快照块配一条"两侧都读到了 + 条数==预期"的基建断言
  3 两个口径的列共用一个读函数(float(10,2) 与 float(10,3) 同表)→ 分成两个函数 + 单测
  4 行集靠键配对 → 少写+多写互相抵消 → 用多重集,排除自增 id/时间戳
  5 闸门只数非 Skipped 断言 → 基建断言永远为真、闸恒过 → 分 Business/Infrastructure

三、§18.4 记下实现选择与实测基线。

验收:35 条 35 PASS / 0 FAIL / Skipped 69 / 业务 181 | 基建 64 / 未分类 0(全部不变)。
README 里那个"771 次 / 22 次每 case"是我先写后测的**编数**,已删掉改成实测 1870 / 53.4。
Q 2 小時之前
父節點
當前提交
421a5849a7

+ 5 - 0
cmd/dualrun/main.go

@@ -204,6 +204,7 @@ func runStage2(args []string) int {
 	fmt.Printf("%s\n\n", cfg.Masked())
 
 	ctx := context.Background()
+	stage2.ResetStats() // 代价计数从这里开始(见 stage2/stats.go)
 	all := stage2.DefaultCases("")
 	source := "DefaultCases"
 	if *probe {
@@ -270,6 +271,10 @@ func runStage2(args []string) int {
 	}
 	fmt.Println()
 
+	// 代价:SQL 执行次数与耗时。它必须和"七个数"一起出现 ——
+	// 否则"慢了"只能等跑不动才发现,而那时已经分不清是"读得对只是慢"还是"读错了靠重试掩盖"。
+	fmt.Printf("%s\n", stage2.StatsLine(len(results)))
+
 	if ok := stage2.Summarize(os.Stdout, results); !ok {
 		return 1
 	}

+ 35 - 0
internal/academic/dualrun/stage2/README.md

@@ -1223,3 +1223,38 @@ $sql = "SELECT SUM(t1.discount_amount-t1.discount_amount_used) as amount FROM ..
 
 反过来,三处**故意选严**的:`toleranceCents = 0`(容差永不放宽)、
 哨兵的 `nonzeroSamples > 0`(非空自检)、`未分类断言数 == 0`。
+
+### 18.3 「自伤清单」:新基建最容易把旧判据悄悄弄坏的五种方式
+
+每一条都**不产生明显症状**,只让断言变松或整块消失。加基建/加 case 时逐条对照。
+
+| # | 自伤方式 | 症状 | 防法 |
+|---|---|---|---|
+| 1 | **新字段对旧 case 为空,却被当成"两侧不等/相等"** | 旧 case 集体红或集体多一条假绿 | 空值必须映射成 `Skipped`;`nil` 与 `nil` **不许**比出"相等"。锁在 `TestActivityDomainApplicableNilIsNotEqual` |
+| 2 | **字段加错结构体**(`SideResult` 而不是 `SideSnapshot`,或反过来) | 编译期偶尔报 `undefined`;**若那个字段恰好没人读,就永远为 nil,零症状** | 每个"本 case 声明了就必须读到"的快照块,配一条**基建断言**:"两侧都读到了 + 条数 == 预期" |
+| 3 | **两个不同口径的列共用一个读函数** | 比对变松,永不报错(例:`float(10,2)` 与 `float(10,3)` 同表) | 读函数按口径**分成两个**(`readRound2` / `readRound3`),并加单测断言两者字符串不同 |
+| 4 | **行集"靠键配对"** | 少写一条 + 多写一条落在同一键上 ⇒ 互相抵消,绿 | 多重集(`map[tuple]int`),并把自增 id / 时间戳排除在 tuple 外 |
+| 5 | **闸门只数"非 Skipped 断言"** | 基建断言(残留 / 基线)永远为真 ⇒ 闸恒过 | 断言分 `Business` / `Infrastructure`,闸门只认业务;`Kind == 0` 算非业务(§18.2) |
+
+### 18.4 代价必须可读:SQL 执行次数 + 耗时
+
+报告尾部固定打一行:
+
+```
+代价:SQL 执行 1870 次 | 耗时 12.377s | 平均 53.4 次/case | 平均 354ms/case
+```
+
+(这是 35 条 case 的**实测值**,不是估的。加活动域快照之前没有计数,所以没有对照 ——
+这一行从此就是对照基线,**以后每次报数都贴它**。)
+
+为什么要有它:活动域快照让每个带活动种子的 case 多打 12 次库(六表 × 两侧)。没有这个数,
+"慢了"只能等跑不动才发现,而那时已经**分不清两种东西**:
+
+| 情况 | 处置 |
+|---|---|
+| 读得对、只是慢 | 可以晚点优化(先让"读得对"成立) |
+| 读错了、靠重试/多次读掩盖 | **必须立刻修**,优化只会把错误藏得更深 |
+
+实现挂在 gorm 的 `logger.Trace` 上而不是 callback:`Trace` 是每条 SQL 的必经之路
+(Query / Row / Exec / Raw 全走它),挂在上面**不会漏**;按 callback 注册要漏一个就少算一类,
+而"少算"在报告上表现为"次数偏低",读的人只会以为"没有额外开销"。

+ 1 - 2
internal/academic/dualrun/stage2/config.go

@@ -25,7 +25,6 @@ import (
 
 	"gorm.io/driver/mysql"
 	"gorm.io/gorm"
-	"gorm.io/gorm/logger"
 )
 
 // Config 是双跑的两条连接。
@@ -135,7 +134,7 @@ func (c Config) dsn(dbName string) string {
 // open 打开一个 gorm 句柄(单连接,避免事务跨连接池失效)。
 func (c Config) open(dbName string) (*gorm.DB, error) {
 	gdb, err := gorm.Open(mysql.Open(c.dsn(dbName)), &gorm.Config{
-		Logger:               logger.Default.LogMode(logger.Silent),
+		Logger:               countingLogger{}, // 静默 + 计数(见 stats.go)
 		DisableAutomaticPing: false,
 	})
 	if err != nil {

+ 86 - 0
internal/academic/dualrun/stage2/stats.go

@@ -0,0 +1,86 @@
+package stage2
+
+import (
+	"context"
+	"fmt"
+	"sync"
+	"time"
+
+	"gorm.io/gorm/logger"
+)
+
+// 本文件是**双跑的代价计数**:本批一共打了多少次库、跑了多久。
+//
+// 为什么要明确统计而不是"感觉还行":
+// 活动域快照把每个 case 的库往返从 ~10 次抬到 ~22 次(六表 × 两侧)。
+// 如果只在"跑不动了"的时候才发现,那就分不清下面两种完全不同的情况:
+//
+//	① 读得对、只是慢           → 可以晚点优化(先让正确性成立)
+//	② 读错了、靠重试掩盖       → 必须立刻修,优化只会把错误藏得更深
+//
+// 所以把"总查询次数"与"总耗时"一起打进报告:它们是可以横向比较的数,
+// 加一条 case、改一个读取器,两个数都会动,动了就说明这次改动有代价。
+
+// Stats 是一次运行的代价计数。零值可用。
+type Stats struct {
+	mu       sync.Mutex
+	queries  int64
+	started  time.Time
+	perCaseQ int64 // 当前 case 起始时的 queries 值,用来算"每 case 多少次"
+}
+
+var globalStats Stats //nolint:gochecknoglobals // 只在 harness 内使用,进程级计数最简单
+
+// Queries 返回至今累计的 SQL 执行次数(gorm `Trace` 被调用一次即一次)。
+func Queries() int64 {
+	globalStats.mu.Lock()
+	defer globalStats.mu.Unlock()
+	return globalStats.queries
+}
+
+// ResetStats 把计数归零并记下开始时间(每次全量跑开始时调一次)。
+func ResetStats() {
+	globalStats.mu.Lock()
+	defer globalStats.mu.Unlock()
+	globalStats.queries = 0
+	globalStats.started = time.Now()
+	globalStats.perCaseQ = 0
+}
+
+// sprintf 是 fmt.Sprintf 的薄封装(本文件只想 import fmt 一次)。
+func sprintf(format string, a ...any) string { return fmt.Sprintf(format, a...) }
+
+// StatsLine 返回可打印的一行"代价"说明。
+func StatsLine(cases int) string {
+	globalStats.mu.Lock()
+	q, st := globalStats.queries, globalStats.started
+	globalStats.mu.Unlock()
+	elapsed := time.Since(st)
+	per := float64(0)
+	if cases > 0 {
+		per = float64(q) / float64(cases)
+	}
+	return sprintf("代价:SQL 执行 %d 次 | 耗时 %s | 平均 %.1f 次/case | 平均 %s/case",
+		q, elapsed.Round(time.Millisecond), per,
+		(elapsed / time.Duration(maxInt(1, cases))).Round(time.Millisecond))
+}
+
+// countingLogger 是 gorm 的 logger 实现:**静默**,但每次 `Trace` 记一次。
+//
+// 为什么用 logger 而不是 gorm 的 callback:`Trace` 是 gorm v2 里每条 SQL 的必经之路
+// (Query/Row/Exec/Raw 都会走),挂在它上面**不会漏**某类语句;
+// 而 callback 要按 Query/Row/Create/Update/Delete 分别注册,漏一个就少算一类,
+// 那种"少算"在报告上表现为"次数偏低",读的人只会以为"没有额外开销"。
+type countingLogger struct{}
+
+func (countingLogger) LogMode(logger.LogLevel) logger.Interface      { return countingLogger{} }
+func (countingLogger) Info(context.Context, string, ...interface{})  {}
+func (countingLogger) Warn(context.Context, string, ...interface{})  {}
+func (countingLogger) Error(context.Context, string, ...interface{}) {}
+
+func (countingLogger) Trace(_ context.Context, _ time.Time, fc func() (string, int64), _ error) {
+	globalStats.mu.Lock()
+	globalStats.queries++
+	globalStats.mu.Unlock()
+	_ = fc // 不执行:执行会真的把 SQL 渲染成字符串,白白变慢
+}