Files
dygou_go/internal/seckill/scheduler_test.go
T
yml2213 dce9ce2a5a 优化日志系统:网络请求降噪并按接口聚合,补齐双时间说明与实例标识,发布0.3.2
- 逐条网络日志(请求完成 / 接口返回异常 / 响应刷新CSRF已同步)从 info/warn 降为 debug:
  实测一次 6 账号的模拟抢购里 233 条日志有 174 条(74%)属于这类;真实抢购会产生几千条,
  把界面仅 800 条的内存日志冲掉,反而看不到关键信息。HTTP/解析/传输层错误仍为 error 级
- 新增按接口聚合的网络统计,抢购任务结束时输出一行,替代逐条刷屏:
  "接口统计: 锁定兑换商品 ×341 失败341 平均=95ms 最慢=312ms 最后错误=活动火爆,请稍后再试"
- 日志文件开头新增表头:实例名、数据目录、双时间格式说明(本地时间 + D 斗鱼估算时间)、
  并说明"校准完成前偏移为 0,只显示本地时间"。双时间一直存在却没有任何地方解释过,
  多实例日志复制或汇总后也分不清来源
- 界面日志面板:显示日志级别并按级别着色(此前级别只存在于 CSS class,复制出去就丢);
  新增"复制"按钮,按与日志文件一致的单行格式导出(此前直接复制会变成 5 行一条、
  1204 行里其实只有 233 条日志)
- 设置页"日志显示等级"补充说明:Info 起只显示关键日志,需要逐请求细节时切到 Debug
- 新增测试:TestRequestStatsAggregatesByLabel、TestLogFileHeaderDocumentsFormat、
  TestRunNowLogsAggregateInsteadOfPerRequest(断言必须有聚合行、且不得出现逐条请求日志)
2026-10-03 19:33:14 +08:00

993 lines
37 KiB
Go

package seckill
import (
"errors"
"fmt"
"net/http"
"net/http/httptest"
"os"
"path/filepath"
"strings"
"sync"
"sync/atomic"
"testing"
"time"
"douyu_go/internal/activity"
"douyu_go/internal/client"
"douyu_go/internal/logger"
"douyu_go/internal/trace"
"douyu_go/internal/types"
)
func makeAttempts(names ...string) []types.ExchangeAttempt {
out := make([]types.ExchangeAttempt, 0, len(names))
for i, n := range names {
out = append(out, types.ExchangeAttempt{
Account: types.Account{Name: n},
Index: i + 1,
})
}
return out
}
// speedUpPeace 把锁单/支付前后的抖动压到 0,并缩短抢购窗口,
// 让测试只关注重试逻辑本身。
func speedUpPeace(t *testing.T) {
t.Helper()
oldPayMin, oldPayMax := peaceLockPayMin, peaceLockPayMax
oldDuration := seckillMaxDuration
peaceLockPayMin, peaceLockPayMax = 0, 0
seckillMaxDuration = 2 * time.Second
t.Cleanup(func() {
peaceLockPayMin, peaceLockPayMax = oldPayMin, oldPayMax
seckillMaxDuration = oldDuration
})
}
// newOrderTestScheduler 用测试服务器替换锁单/支付/角色接口。
func newOrderTestScheduler(t *testing.T, handler http.HandlerFunc) *Scheduler {
t.Helper()
server := httptest.NewServer(handler)
t.Cleanup(server.Close)
act := *activity.Get("peace")
act.CreateOrderURL = server.URL + "/create"
act.PayOrderURL = server.URL + "/pay"
act.BindInfoURL = server.URL + "/bind"
act.CSRFURL = server.URL + "/csrf"
cli := client.New(&act, "", &trace.Recorder{})
cli.HTTPClient = server.Client()
return New(cli, types.AppPaths{}, nil, 8, 1, nil, types.SeckillModeAggressive)
}
// requestAccount 取出请求对应的测试账号标识(csrfToken 等于账号名)。
func requestAccount(t *testing.T, r *http.Request) string {
t.Helper()
if err := r.ParseMultipartForm(1 << 20); err != nil {
t.Errorf("ParseMultipartForm() error = %v", err)
return ""
}
if v := r.MultipartForm.Value["csrfToken"]; len(v) > 0 {
return v[0]
}
return ""
}
func peaceAttempt(name string) types.ExchangeAttempt {
return types.ExchangeAttempt{
Account: types.Account{Name: name, Cookie: "cvl_csrf_token=" + name},
Product: types.Product{CommodityID: "goods-1", CommodityName: "测试商品"},
Index: 1,
}
}
func writeAccountFile(t *testing.T, names ...string) types.AppPaths {
t.Helper()
dir := t.TempDir()
path := filepath.Join(dir, "accounts.txt")
var b strings.Builder
for _, name := range names {
b.WriteString(name + "----pw----cvl_csrf_token=" + name + "\n")
}
if err := os.WriteFile(path, []byte(b.String()), 0600); err != nil {
t.Fatal(err)
}
return types.AppPaths{AccountFile: path}
}
// ========== 错误分类 ==========
func TestOrderErrorClassification(t *testing.T) {
lockCases := []struct {
err error
want orderErrorKind
}{
{&client.OrderError{Kind: "锁定兑换商品失败", Code: apiActivityHot, Msg: "活动火爆,请稍后再试"}, orderErrThrottled},
{&client.OrderError{Kind: "锁定兑换商品失败", Code: apiClickTooFast, Msg: "您点击太快,请稍等再试"}, orderErrThrottled},
{&client.OrderError{Kind: "锁定兑换商品失败", Code: apiStockExhausted, Msg: "商品本次活动库存已耗完"}, orderErrStockOut},
{&client.OrderError{Kind: "锁定兑换商品失败", Code: 1, Msg: "您已达本次活动兑换上限"}, orderErrTerminal},
{&client.OrderError{Kind: "锁定兑换商品失败", Code: 1, Msg: "未绑定账号"}, orderErrTerminal},
{errors.New("锁定兑换商品失败: 请求太频繁"), orderErrRateLimited},
{errors.New("dial tcp: connection reset"), orderErrTransient},
}
for _, c := range lockCases {
if got := lockErrorKind(c.err); got != c.want {
t.Errorf("lockErrorKind(%v) = %v, want %v", c.err, got, c.want)
}
}
// 支付链路上"订单已受理、结果未定"的三种表现都必须算在途,而不是频控。
payCases := []struct {
err error
want orderErrorKind
}{
{&client.OrderError{Kind: "支付锁单失败", Code: apiOrderInProgress, Msg: "订单操作进行中,请稍后再试"}, orderErrInFlight},
{&client.OrderError{Kind: "支付锁单失败", Code: apiServerTimeout, Msg: "context deadline exceeded"}, orderErrInFlight},
{&client.OrderError{Kind: "支付锁单失败", Code: apiServiceUnavail, Msg: "服务当前不可用"}, orderErrInFlight},
{&client.OrderError{Kind: "支付锁单失败", Code: 1, Msg: "订单已过期"}, orderErrTerminal},
{&client.OrderError{Kind: "支付锁单失败", Code: 1, Msg: "操作频繁,请稍后再试"}, orderErrRateLimited},
}
for _, c := range payCases {
if got := payErrorKind(c.err); got != c.want {
t.Errorf("payErrorKind(%v) = %v, want %v", c.err, got, c.want)
}
}
}
// TestPayRetryDelayStaysShort 锁住"不再出现 30s/60s 长退避"这一关键修复。
// 覆盖到很大的重试序号,确认阶梯只封顶不增长。
func TestPayRetryDelayStaysShort(t *testing.T) {
for try := 1; try <= 500; try++ {
inFlight := payRetryDelay(orderErrInFlight, try)
if inFlight > 1300*time.Millisecond {
t.Fatalf("在途重试第%d次退避 %v,太长了", try, inFlight)
}
rateLimited := payRetryDelay(orderErrRateLimited, try)
if rateLimited > 2600*time.Millisecond {
t.Fatalf("频控重试第%d次退避 %v,太长了", try, rateLimited)
}
}
// 首次在途重试必须在 200-500ms 区间(用户选定的快重试档位)。
if got := payRetryDelay(orderErrInFlight, 1); got < 300*time.Millisecond || got > 400*time.Millisecond {
t.Fatalf("首次在途重试 = %v, want 300ms±抖动", got)
}
}
// speedUpPayLadder 把支付退避阶梯与总预算压到毫秒级,便于测试长时间重试路径。
func speedUpPayLadder(t *testing.T) {
t.Helper()
oldInFlight, oldRate, oldOther := payRetryInFlight, payRetryRate, payRetryOther
oldBudget := maxPayDuration
payRetryInFlight = retryLadder{base: time.Millisecond, limit: 2 * time.Millisecond}
payRetryRate = retryLadder{base: time.Millisecond, limit: 2 * time.Millisecond}
payRetryOther = retryLadder{base: time.Millisecond, limit: 2 * time.Millisecond}
t.Cleanup(func() {
payRetryInFlight, payRetryRate, payRetryOther = oldInFlight, oldRate, oldOther
maxPayDuration = oldBudget
})
}
// TestPayKeepsRetryingBeyondOldAttemptCap 回归复核发现的严重缺陷:
// 之前用 maxPayAttempts=30 做上限,而 2026-10-03 斗鱼的支付处理堵塞了约 65 秒
// 才结算(137 单全部在 18:01:07 左右才确认),30 次会在 ~37 秒就放弃,
// 把已经锁到、也确实支付成功的订单报成"结果未知"。
func TestPayKeepsRetryingBeyondOldAttemptCap(t *testing.T) {
speedUpPeace(t)
speedUpPayLadder(t)
const inFlightTimes = 45 // 明显超过旧上限 30
var payCalls int32
scheduler := newOrderTestScheduler(t, func(w http.ResponseWriter, r *http.Request) {
w.Header().Set("Content-Type", "application/json")
switch r.URL.Path {
case "/create":
_, _ = w.Write([]byte(`{"error":0,"data":{"orderId":"order-1","expireSeconds":300}}`))
case "/pay":
if atomic.AddInt32(&payCalls, 1) <= inFlightTimes {
_, _ = w.Write([]byte(`{"error":1644430001,"msg":"订单操作进行中,请稍后再试"}`))
return
}
_, _ = w.Write([]byte(`{"error":0,"data":{"exchangeId":9,"exchangeNum":"1"}}`))
case "/bind":
_, _ = w.Write([]byte(`{"error":0,"data":{"gameRole":{"roleName":"测试角色"}}}`))
}
})
ctl := newRunControl(scheduler, time.Now(), time.Now().Add(30*time.Second), 4, 1)
out := scheduler.runPeaceLockPay(peaceAttempt("a"), ctl)
if !out.result.OK {
t.Fatalf("服务端在 %d 次「处理中」之后结算,应当继续重试到成功, result=%#v", inFlightTimes, out.result)
}
if got := atomic.LoadInt32(&payCalls); got != inFlightTimes+1 {
t.Fatalf("支付请求 = %d, want %d", got, inFlightTimes+1)
}
}
// TestPayGivesUpHonestlyAtBudget 超过时间预算时必须如实报"结果未知",
// 而不是让用户以为订单一定失败了。
func TestPayGivesUpHonestlyAtBudget(t *testing.T) {
speedUpPeace(t)
speedUpPayLadder(t)
maxPayDuration = 20 * time.Millisecond
var payCalls int32
scheduler := newOrderTestScheduler(t, func(w http.ResponseWriter, r *http.Request) {
w.Header().Set("Content-Type", "application/json")
switch r.URL.Path {
case "/create":
_, _ = w.Write([]byte(`{"error":0,"data":{"orderId":"order-1","expireSeconds":300}}`))
case "/pay":
atomic.AddInt32(&payCalls, 1)
_, _ = w.Write([]byte(`{"error":1644430001,"msg":"订单操作进行中,请稍后再试"}`))
}
})
ctl := newRunControl(scheduler, time.Now(), time.Now().Add(30*time.Second), 4, 1)
out := scheduler.runPeaceLockPay(peaceAttempt("a"), ctl)
if out.result.OK {
t.Fatal("预算内不可能成功,不应报成功")
}
if !strings.Contains(out.result.Message, "支付结果未知") || !strings.Contains(out.result.Message, "可能已支付") {
t.Fatalf("结果 = %q, want 提示支付结果未知", out.result.Message)
}
if atomic.LoadInt32(&payCalls) == 0 {
t.Fatal("应当至少尝试过一次支付")
}
}
// ========== 重试节奏 ==========
func TestRetryDelayFollowsConfiguredStages(t *testing.T) {
stages := []types.RetryStage{
{MaxElapsed: 4, Interval: 120},
{MaxElapsed: 12, Interval: 200},
{MaxElapsed: 30, Interval: 500},
{MaxElapsed: 75, Interval: 1000},
}
cases := []struct {
elapsed time.Duration
streak int
min time.Duration
max time.Duration
}{
{1 * time.Second, 0, 120 * time.Millisecond, 180 * time.Millisecond},
{5 * time.Second, 0, 200 * time.Millisecond, 300 * time.Millisecond},
{31 * time.Second, 0, time.Second, 1500 * time.Millisecond},
// 连续失败成倍放大,但不超过 maxRetryDelay
{1 * time.Second, 3, 480 * time.Millisecond, 620 * time.Millisecond},
{31 * time.Second, 10, 1500 * time.Millisecond, 1900 * time.Millisecond},
}
for _, c := range cases {
got := retryDelay(stages, c.elapsed, c.streak)
if got < c.min || got > c.max {
t.Errorf("retryDelay(elapsed=%v, streak=%d) = %v, want [%v,%v]", c.elapsed, c.streak, got, c.min, c.max)
}
}
// 空配置也要给出可用节奏,不能是 0(0 会变成忙等)。
if got := retryDelay(nil, time.Second, 0); got < minRetryDelay {
t.Errorf("retryDelay(nil) = %v, want >= %v", got, minRetryDelay)
}
}
// TestRetryDelayNeverBacksOffLong 抢购是争分夺秒的:任何一次退避都必须压在
// 2 秒以内。2026-10-03 的日志里,库存只活了约 1.1 秒(PC2 四个实例
// 18:00:00.171~18:00:01.101 一直在成功锁单),超过 2 秒的等待就可能正好错过库存回流。
func TestRetryDelayNeverBacksOffLong(t *testing.T) {
stages := []types.RetryStage{
{MaxElapsed: 4, Interval: 120},
{MaxElapsed: 12, Interval: 200},
{MaxElapsed: 30, Interval: 500},
{MaxElapsed: 75, Interval: 1000},
}
worst := time.Duration(0)
for elapsed := time.Duration(0); elapsed <= 75*time.Second; elapsed += 250 * time.Millisecond {
for streak := 0; streak <= 40; streak++ {
if got := retryDelay(stages, elapsed, streak); got > worst {
worst = got
}
}
}
if worst >= 2*time.Second {
t.Fatalf("最大退避 = %v,必须小于 2 秒", worst)
}
// 也要覆盖用户把阶段间隔调到很大值的极端配置。
extreme := []types.RetryStage{{MaxElapsed: 75, Interval: 5000}}
if got := retryDelay(extreme, 40*time.Second, 10); got >= 2*time.Second {
t.Fatalf("极端配置下退避 = %v,仍必须小于 2 秒", got)
}
}
func TestRetryIntervalFor(t *testing.T) {
stages := []types.RetryStage{
{MaxElapsed: 4, Interval: 120},
{MaxElapsed: 12, Interval: 200},
{MaxElapsed: 30, Interval: 500},
{MaxElapsed: 75, Interval: 1000},
}
cases := []struct {
elapsed time.Duration
want time.Duration
}{
{1 * time.Second, 120 * time.Millisecond},
{5 * time.Second, 200 * time.Millisecond},
{13 * time.Second, 500 * time.Millisecond},
{31 * time.Second, 1000 * time.Millisecond},
{100 * time.Second, 900 * time.Millisecond}, // 超出所有阶段,用默认值
}
for _, c := range cases {
if got := retryIntervalFor(stages, c.elapsed); got != c.want {
t.Errorf("retryIntervalFor(%v) = %v, want %v", c.elapsed, got, c.want)
}
}
}
func TestRetryIntervalForEmpty(t *testing.T) {
if got := retryIntervalFor(nil, 1*time.Second); got != 900*time.Millisecond {
t.Errorf("retryIntervalFor(nil) = %v, want 900ms", got)
}
if got := retryIntervalFor([]types.RetryStage{{MaxElapsed: 0, Interval: 0}}, 1*time.Second); got != 900*time.Millisecond {
t.Errorf("retryIntervalFor(invalid) = %v, want 900ms", got)
}
}
// ========== 锁单 + 支付 ==========
func TestPeacePurchaseLocksThenPaysWithoutChecks(t *testing.T) {
speedUpPeace(t)
var calls []string
var mu sync.Mutex
scheduler := newOrderTestScheduler(t, func(w http.ResponseWriter, r *http.Request) {
mu.Lock()
calls = append(calls, r.URL.Path)
mu.Unlock()
w.Header().Set("Content-Type", "application/json")
switch r.URL.Path {
case "/create":
if err := r.ParseMultipartForm(1 << 20); err != nil {
t.Errorf("ParseMultipartForm() error = %v", err)
return
}
if _, ok := r.MultipartForm.Value["orderID"]; ok {
t.Error("锁单请求不应携带支付订单号")
}
_, _ = w.Write([]byte(`{"error":0,"data":{"orderId":"order-9","expireSeconds":300}}`))
case "/pay":
if err := r.ParseMultipartForm(1 << 20); err != nil {
t.Errorf("ParseMultipartForm() error = %v", err)
return
}
if got := r.MultipartForm.Value["orderID"][0]; got != "order-9" {
t.Errorf("orderID = %q", got)
}
_, _ = w.Write([]byte(`{"error":0,"data":{"exchangeId":9,"exchangeNum":"1"}}`))
case "/bind":
_, _ = w.Write([]byte(`{"error":0,"data":{"gameRole":{"roleName":"测试角色"}}}`))
default:
t.Errorf("不应请求预检或单步兑换接口: %s", r.URL.Path)
http.NotFound(w, r)
}
})
ctl := newRunControl(scheduler, time.Now(), time.Now().Add(time.Minute), 4, 1)
out := scheduler.runPeaceLockPay(peaceAttempt("a"), ctl)
if !out.result.OK || out.result.RoleName != "测试角色" {
t.Fatalf("result = %#v", out)
}
mu.Lock()
defer mu.Unlock()
if len(calls) < 2 || calls[0] != "/create" || calls[1] != "/pay" {
t.Fatalf("calls = %v, want create then pay", calls)
}
for _, path := range calls {
switch path {
case "/create", "/pay", "/bind":
default:
t.Fatalf("unexpected call %s in %v", path, calls)
}
}
}
// TestPayInFlightRetriesQuickly 复现线上形态:
// 第一次支付被斗鱼服务端 3 秒超时打断,第二次返回"订单操作进行中",
// 第三次成功。修复前这两次会退避 2s + 60s,修复后应在 1 秒出头完成。
func TestPayInFlightRetriesQuickly(t *testing.T) {
speedUpPeace(t)
var payCalls int32
scheduler := newOrderTestScheduler(t, func(w http.ResponseWriter, r *http.Request) {
w.Header().Set("Content-Type", "application/json")
switch r.URL.Path {
case "/create":
_, _ = w.Write([]byte(`{"error":0,"data":{"orderId":"order-1","expireSeconds":300}}`))
case "/pay":
switch atomic.AddInt32(&payCalls, 1) {
case 1:
_, _ = w.Write([]byte(`{"error":1644400002,"msg":"context deadline exceeded"}`))
case 2:
_, _ = w.Write([]byte(`{"error":1644430001,"msg":"订单操作进行中,请稍后再试"}`))
default:
_, _ = w.Write([]byte(`{"error":0,"data":{"exchangeId":9,"exchangeNum":"1"}}`))
}
case "/bind":
_, _ = w.Write([]byte(`{"error":0,"data":{"gameRole":{"roleName":"测试角色"}}}`))
}
})
ctl := newRunControl(scheduler, time.Now(), time.Now().Add(30*time.Second), 4, 1)
start := time.Now()
out := scheduler.runPeaceLockPay(peaceAttempt("a"), ctl)
elapsed := time.Since(start)
if !out.result.OK {
t.Fatalf("应支付成功, result=%#v", out.result)
}
if got := atomic.LoadInt32(&payCalls); got != 3 {
t.Fatalf("支付请求 = %d, want 3", got)
}
if elapsed > 3*time.Second {
t.Fatalf("两次在途重试耗时 %v;历史 bug 会退避 2s+60s", elapsed)
}
}
// TestPayFinishesAfterWindowClosed 抢购窗口在支付期间到期时,
// 已锁单的订单仍必须支付完(放弃等于白锁)。
func TestPayFinishesAfterWindowClosed(t *testing.T) {
speedUpPeace(t)
var payCalls int32
scheduler := newOrderTestScheduler(t, func(w http.ResponseWriter, r *http.Request) {
w.Header().Set("Content-Type", "application/json")
switch r.URL.Path {
case "/create":
_, _ = w.Write([]byte(`{"error":0,"data":{"orderId":"order-1","expireSeconds":300}}`))
case "/pay":
if atomic.AddInt32(&payCalls, 1) == 1 {
time.Sleep(300 * time.Millisecond) // 让抢购窗口在这笔支付期间过期
_, _ = w.Write([]byte(`{"error":1644400014,"msg":"服务当前不可用"}`))
return
}
_, _ = w.Write([]byte(`{"error":0,"data":{"exchangeId":9,"exchangeNum":"1"}}`))
case "/bind":
_, _ = w.Write([]byte(`{"error":0,"data":{"gameRole":{"roleName":"测试角色"}}}`))
}
})
ctl := newRunControl(scheduler, time.Now(), time.Now().Add(50*time.Millisecond), 4, 1)
out := scheduler.runPeaceLockPay(peaceAttempt("a"), ctl)
if !out.result.OK {
t.Fatalf("窗口到期后仍应把已锁订单支付完, result=%#v", out.result)
}
if got := atomic.LoadInt32(&payCalls); got != 2 {
t.Fatalf("支付请求 = %d, want 2", got)
}
if !ctl.expired() {
t.Fatal("测试前提不成立:抢购窗口应当已经在支付期间过期")
}
}
// TestSlowPayDoesNotBlockOtherAccounts 回归"轮次屏障"缺陷:
// 一个账号卡在慢支付时,其它账号必须继续按自己的节奏重试。
func TestSlowPayDoesNotBlockOtherAccounts(t *testing.T) {
speedUpPeace(t)
var bCreate, aPay int32
scheduler := newOrderTestScheduler(t, func(w http.ResponseWriter, r *http.Request) {
w.Header().Set("Content-Type", "application/json")
switch r.URL.Path {
case "/create":
if requestAccount(t, r) == "a" {
_, _ = w.Write([]byte(`{"error":0,"data":{"orderId":"order-a","expireSeconds":300}}`))
return
}
atomic.AddInt32(&bCreate, 1)
_, _ = w.Write([]byte(`{"error":1644400007,"msg":"活动火爆,请稍后再试"}`))
case "/pay":
// 账号 a 的支付一直在途,旧实现会让整轮在这里干等。
time.Sleep(200 * time.Millisecond)
if atomic.AddInt32(&aPay, 1) >= 3 {
_, _ = w.Write([]byte(`{"error":1644430009,"msg":"订单已过期"}`))
return
}
_, _ = w.Write([]byte(`{"error":1644430001,"msg":"订单操作进行中,请稍后再试"}`))
}
})
start := time.Now()
ctl := newRunControl(scheduler, start, start.Add(2500*time.Millisecond), 8, 1)
settings := runSettings{
concurrency: 8,
seckillMode: types.SeckillModeAggressive,
retryStages: []types.RetryStage{{MaxElapsed: 75, Interval: 50}},
}
var wg sync.WaitGroup
for _, name := range []string{"a", "b"} {
wg.Add(1)
go func(name string) {
defer wg.Done()
scheduler.runAccountLoop(peaceAttempt(name), settings, ctl)
}(name)
}
wg.Wait()
if got := atomic.LoadInt32(&bCreate); got < 4 {
t.Fatalf("账号 b 在窗口内只尝试了 %d 次;慢支付账号不应阻塞其它账号", got)
}
if !ctl.expired() {
t.Fatal("账号 b 应当一直重试到窗口结束")
}
}
// TestStockOutKeepsProbingToWindowEnd 售罄不是终态:别人锁单后支付失败或锁单过期,
// 占用的库存会回流,所以窗口内必须继续探测,只在结束时把结论分类上报。
func TestStockOutKeepsProbingToWindowEnd(t *testing.T) {
speedUpPeace(t)
var creates int32
scheduler := newOrderTestScheduler(t, func(w http.ResponseWriter, r *http.Request) {
w.Header().Set("Content-Type", "application/json")
if r.URL.Path == "/create" {
atomic.AddInt32(&creates, 1)
_, _ = w.Write([]byte(`{"error":1644402023,"msg":"商品本次活动库存已耗完"}`))
}
})
start := time.Now()
ctl := newRunControl(scheduler, start, start.Add(1200*time.Millisecond), 4, 1)
settings := runSettings{
concurrency: 4,
seckillMode: types.SeckillModeAggressive,
retryStages: []types.RetryStage{{MaxElapsed: 75, Interval: 20}},
}
out := scheduler.runAccountLoop(peaceAttempt("a"), settings, ctl)
if out.kind != outcomeRejected {
t.Fatalf("kind = %q, want %q (reason=%s)", out.kind, outcomeRejected, out.reason)
}
if !strings.Contains(out.reason, "售罄") || !strings.Contains(out.reason, "库存已耗完") {
t.Fatalf("结束原因应说明商品始终售罄: %q", out.reason)
}
if !ctl.expired() {
t.Fatal("售罄后应当一直探测到窗口结束")
}
if got := atomic.LoadInt32(&creates); got < 3 {
t.Fatalf("锁单请求 = %d,售罄后仍应持续探测", got)
}
}
// TestStockOutAfterThrottleStillReported 复现 PC1 实例3 的形态:
// 先被限流("活动火爆"),随后服务端改口"库存已耗完"。两种情况都不能提前停止,
// 结束时要能区分出"商品始终售罄"而不是含糊的失败。
func TestStockOutAfterThrottleStillReported(t *testing.T) {
speedUpPeace(t)
var creates int32
scheduler := newOrderTestScheduler(t, func(w http.ResponseWriter, r *http.Request) {
w.Header().Set("Content-Type", "application/json")
if r.URL.Path != "/create" {
return
}
if n := atomic.AddInt32(&creates, 1); n <= 2 {
_, _ = w.Write([]byte(`{"error":1644400007,"msg":"活动火爆,请稍后再试"}`))
return
}
_, _ = w.Write([]byte(`{"error":1644402023,"msg":"商品本次活动库存已耗完"}`))
})
start := time.Now()
ctl := newRunControl(scheduler, start, start.Add(1200*time.Millisecond), 4, 1)
settings := runSettings{
concurrency: 4,
seckillMode: types.SeckillModeAggressive,
retryStages: []types.RetryStage{{MaxElapsed: 75, Interval: 20}},
}
out := scheduler.runAccountLoop(peaceAttempt("a"), settings, ctl)
if out.kind != outcomeRejected {
t.Fatalf("kind = %q, want %q (reason=%s)", out.kind, outcomeRejected, out.reason)
}
if !strings.Contains(out.reason, "售罄") || !strings.Contains(out.reason, "库存已耗完") {
t.Fatalf("结束原因应说明商品始终售罄: %q", out.reason)
}
if got := int(atomic.LoadInt32(&creates)); got <= 2 {
t.Fatalf("锁单请求 = %d,跨入售罄后仍应持续探测", got)
}
}
// TestThrottledKeepsRetryingToWindowEnd 限流(活动火爆)不能触发"商品不可抢":
// 日志证明同一秒内同实例别的账号还能锁单成功,说明那只是请求级限流。
// 阈值故意调到 2,账号仍必须重试到窗口结束,并在结束原因里说明是被限流。
func TestThrottledKeepsRetryingToWindowEnd(t *testing.T) {
speedUpPeace(t)
var creates int32
scheduler := newOrderTestScheduler(t, func(w http.ResponseWriter, r *http.Request) {
w.Header().Set("Content-Type", "application/json")
if r.URL.Path == "/create" {
atomic.AddInt32(&creates, 1)
_, _ = w.Write([]byte(`{"error":1644400007,"msg":"活动火爆,请稍后再试"}`))
}
})
start := time.Now()
ctl := newRunControl(scheduler, start, start.Add(1200*time.Millisecond), 4, 1)
settings := runSettings{
concurrency: 4,
seckillMode: types.SeckillModeAggressive,
retryStages: []types.RetryStage{{MaxElapsed: 75, Interval: 20}},
}
out := scheduler.runAccountLoop(peaceAttempt("a"), settings, ctl)
if out.kind != outcomeThrottled {
t.Fatalf("kind = %q, want %q (reason=%s)", out.kind, outcomeThrottled, out.reason)
}
if !strings.Contains(out.reason, "被限流") {
t.Fatalf("结束原因应说明被限流: %q", out.reason)
}
if got := atomic.LoadInt32(&creates); got < 3 {
t.Fatalf("锁单请求 = %d,限流后仍应持续探测到窗口结束", got)
}
if !ctl.expired() {
t.Fatal("被限流的账号应当一直重试到窗口结束")
}
}
// TestFirstWaveStartsImmediately 首发是整场最关键的一波:第 0 个账号必须立即发出
// (定时器已提前约 100ms 补偿 RTT,不能再自己抖几百毫秒),其余按小步长错开,
// 整批铺开时间有上限。
func TestFirstWaveStartsImmediately(t *testing.T) {
if got := firstWaveStepFor(1); got != 0 {
t.Fatalf("单账号步长 = %v, want 0(必须立即发出)", got)
}
for _, count := range []int{2, 34, 100, 500, 2000} {
step := firstWaveStepFor(count)
if step > firstWaveMaxStep {
t.Fatalf("账号数 %d 的步长 = %v, 超过上限 %v", count, step, firstWaveMaxStep)
}
spread := time.Duration(count-1) * step
if spread > firstWaveSpread+step {
t.Fatalf("账号数 %d 整批铺开 %v, 超过上限 %v", count, spread, firstWaveSpread)
}
}
// 位次必须从 0 开始且逐个递增,保证总有账号在 0 延时首发。
s := &Scheduler{}
ctl := newRunControl(s, time.Now(), time.Now().Add(time.Minute), 4, 4)
for want := 0; want < 4; want++ {
got, step := ctl.firstWaveSlot()
if got != want {
t.Fatalf("第%d个位次 = %d", want, got)
}
if step <= 0 {
t.Fatalf("4 个账号时步长应为正数, got %v", step)
}
}
if got, _ := ctl.firstWaveSlot(); got != 4 {
t.Fatalf("位次应继续递增, got %d", got)
}
}
// ========== RunNow 端到端 ==========
func TestRunNowEndToEnd(t *testing.T) {
speedUpPeace(t)
seckillMaxDuration = 1500 * time.Millisecond
scheduler := newOrderTestScheduler(t, func(w http.ResponseWriter, r *http.Request) {
w.Header().Set("Content-Type", "application/json")
name := ""
if r.URL.Path != "/bind" {
name = requestAccount(t, r)
}
switch r.URL.Path {
case "/create":
if name == "winner" {
_, _ = w.Write([]byte(`{"error":0,"data":{"orderId":"order-w","expireSeconds":300}}`))
return
}
_, _ = w.Write([]byte(`{"error":1644402023,"msg":"商品本次活动库存已耗完"}`))
case "/pay":
_, _ = w.Write([]byte(`{"error":0,"data":{"exchangeId":9,"exchangeNum":"1"}}`))
case "/bind":
_, _ = w.Write([]byte(`{"error":0,"data":{"gameRole":{"roleName":"测试角色"}}}`))
}
})
scheduler.paths = writeAccountFile(t, "winner", "loser")
scheduler.accounts = NewAccountStore(scheduler.paths.AccountFile)
scheduler.LoadAccounts()
scheduler.UpdateProducts([]types.Product{{CommodityID: "goods-1", CommodityName: "测试商品"}})
start := time.Now()
scheduler.RunNow(map[string]string{"winner": "goods-1", "loser": "goods-1"})
elapsed := time.Since(start)
// 售罄的账号会一直探测到窗口结束,但必须及时收手、不能拖长。
if elapsed > seckillMaxDuration+2*time.Second {
t.Fatalf("窗口结束后应及时收手,实际耗时 %v(窗口 %v)", elapsed, seckillMaxDuration)
}
results := scheduler.Results()
winnerKey := resultKey(types.ExchangeAttempt{Account: types.Account{Name: "winner"}, Index: 1})
if got := results[winnerKey]; !strings.HasPrefix(got, "成功|") {
t.Fatalf("winner 结果 = %q, want 成功", got)
}
loserKey := resultKey(types.ExchangeAttempt{Account: types.Account{Name: "loser"}})
if got := results[loserKey]; !strings.Contains(got, "售罄") || !strings.Contains(got, "库存已耗完") {
t.Fatalf("loser 结果 = %q, want 售罄判定", got)
}
}
// TestBuildTasksOnePerAccount 每个账号只生成一个任务。
// 历史实现按"包数"为同一账号重复生成任务,把预热缓存日志打了两遍。
func TestBuildTasksOnePerAccount(t *testing.T) {
scheduler := New(nil, writeAccountFile(t, "a", "b", "c"), nil, 8, 2, nil, types.SeckillModeAggressive)
scheduler.LoadAccounts()
scheduler.UpdateProducts([]types.Product{{CommodityID: "goods-1", CommodityName: "测试商品"}})
tasks := scheduler.buildTasks(map[string]string{"a": "goods-1", "b": "goods-1"})
if len(tasks) != 2 {
t.Fatalf("buildTasks 生成 %d 个任务, want 2", len(tasks))
}
for _, task := range tasks {
if task.Index != 1 {
t.Fatalf("每个账号应只有一个任务, got 第%d次 for %s", task.Index, task.Account.Name)
}
}
}
// TestRunNowMatchesPCLogShape 用 2026-10-03 日志里实测到的形态做端到端回归:
// 锁单全部秒成,支付需要 3 步(服务端 3 秒超时 → 订单操作进行中 → 成功)。
// 修复前每一单要 68 秒才确认,12 个账号会拖到 1 分多钟。
func TestRunNowMatchesPCLogShape(t *testing.T) {
speedUpPeace(t)
seckillMaxDuration = 30 * time.Second
const accounts = 12
names := make([]string, 0, accounts)
accountProducts := make(map[string]string, accounts)
for i := 0; i < accounts; i++ {
name := fmt.Sprintf("acct-%02d", i)
names = append(names, name)
accountProducts[name] = "goods-1"
}
var mu sync.Mutex
payTries := make(map[string]int, accounts)
scheduler := newOrderTestScheduler(t, func(w http.ResponseWriter, r *http.Request) {
w.Header().Set("Content-Type", "application/json")
switch r.URL.Path {
case "/create":
name := requestAccount(t, r)
_, _ = w.Write([]byte(`{"error":0,"data":{"orderId":"order-` + name + `","expireSeconds":300}}`))
case "/pay":
name := requestAccount(t, r)
mu.Lock()
payTries[name]++
try := payTries[name]
mu.Unlock()
switch try {
case 1:
// 斗鱼服务端自己的 3 秒超时(日志里耗时恒为 3.05s)
time.Sleep(150 * time.Millisecond)
_, _ = w.Write([]byte(`{"error":1644400002,"msg":"context deadline exceeded"}`))
case 2:
_, _ = w.Write([]byte(`{"error":1644430001,"msg":"订单操作进行中,请稍后再试"}`))
default:
_, _ = w.Write([]byte(`{"error":0,"data":{"exchangeId":9,"exchangeNum":"1"}}`))
}
case "/bind":
_, _ = w.Write([]byte(`{"error":0,"data":{"gameRole":{"roleName":"测试角色"}}}`))
}
})
scheduler.paths = writeAccountFile(t, names...)
scheduler.accounts = NewAccountStore(scheduler.paths.AccountFile)
scheduler.LoadAccounts()
scheduler.UpdateProducts([]types.Product{{CommodityID: "goods-1", CommodityName: "测试商品"}})
start := time.Now()
scheduler.RunNow(accountProducts)
elapsed := time.Since(start)
results := scheduler.Results()
if got := len(results); got != accounts {
t.Fatalf("结果条目 = %d, want %d(每个账号只应占一条)", got, accounts)
}
for _, name := range names {
key := resultKey(types.ExchangeAttempt{Account: types.Account{Name: name}})
if got := results[key]; !strings.HasPrefix(got, "成功|") {
t.Fatalf("%s 结果 = %q, want 成功", name, got)
}
mu.Lock()
tries := payTries[name]
mu.Unlock()
if tries != 3 {
t.Fatalf("%s 支付请求 = %d, want 3", name, tries)
}
}
// 12 个账号并发,每个约 (0.15s + 0.3s + 0.6s) ≈ 1.1s;留足余量也不要 68 秒。
if elapsed > 8*time.Second {
t.Fatalf("端到端耗时 %v;支付退避又变长了(历史 bug 是每单 68 秒)", elapsed)
}
}
// ========== 和平小店链路(改动面之外,保留回归覆盖) ==========
func TestNormalizeXiaodianRun(t *testing.T) {
attempts, delay := normalizeXiaodianRun(0, 0, 4)
if attempts != 4 || delay != xiaodianDefaultDelay {
t.Fatalf("normalizeXiaodianRun fallback = (%d,%v), want (4,%v)", attempts, delay, xiaodianDefaultDelay)
}
attempts, delay = normalizeXiaodianRun(100001, 70000, 0)
if attempts != 100000 || delay != 60*time.Second {
t.Fatalf("normalizeXiaodianRun clamp = (%d,%v), want (100000,60s)", attempts, delay)
}
attempts, delay = normalizeXiaodianRun(2, 150, 0)
if attempts != 2 || delay != 150*time.Millisecond {
t.Fatalf("normalizeXiaodianRun explicit = (%d,%v), want (2,150ms)", attempts, delay)
}
}
func TestRetryCooldownDuration(t *testing.T) {
cases := []struct {
msg string
want time.Duration
}{
{"用户行为异常,请稍后再试", exchangeRateCooldown},
{"点击太快了", exchangeRateCooldown},
{"操作频繁请稍后", exchangeRateCooldown},
{"请求过多", exchangeRateCooldown},
{"请求太频繁", exchangeRateCooldown},
{"当前活动太火爆", exchangeRateCooldown},
{"兑换成功", 0},
{"库存不足", 0},
}
for _, c := range cases {
if got := retryCooldownDuration(c.msg); got != c.want {
t.Errorf("retryCooldownDuration(%q) = %v, want %v", c.msg, got, c.want)
}
}
}
func TestClassifyRetryStop(t *testing.T) {
acc, prod, reason := classifyRetryStop("您已达本次活动兑换上限")
if !acc || prod || reason != "已达兑换上限" {
t.Errorf("classifyRetryStop(兑换上限) = (%v,%v,%q), want (true,false,'已达兑换上限')", acc, prod, reason)
}
acc, prod, reason = classifyRetryStop("未绑定账号")
if !acc || prod || reason != "账号未绑定角色" {
t.Errorf("classifyRetryStop(未绑定) = (%v,%v,%q), want (true,false,'账号未绑定角色')", acc, prod, reason)
}
acc, prod, reason = classifyRetryStop("需要开通精英手册")
if !acc || prod || reason != "账号不满足精英手册条件" {
t.Errorf("classifyRetryStop(精英手册) = (%v,%v,%q), want (true,false,'账号不满足精英手册条件')", acc, prod, reason)
}
// 库存耗尽不立即停止:由"连续被拒上限"决定何时收手
acc, prod, reason = classifyRetryStop("商品本次活动库存已耗完")
if acc || prod || reason != "" {
t.Errorf("classifyRetryStop(库存耗完) = (%v,%v,%q), want (false,false,'')", acc, prod, reason)
}
acc, prod, reason = classifyRetryStop("网络超时")
if acc || prod || reason != "" {
t.Errorf("classifyRetryStop(普通错误) = (%v,%v,%q), want (false,false,'')", acc, prod, reason)
}
}
func TestClassifyXiaodianRetryStopOwnedItem(t *testing.T) {
for _, message := range []string{"您已拥有该道具!", "已经拥有该道具", "账号已拥有该商品"} {
acc, prod, reason := classifyXiaodianRetryStop(message)
if !acc || prod || reason != "账号已拥有该道具" {
t.Errorf("classifyXiaodianRetryStop(%q) = (%v,%v,%q), want (true,false,'账号已拥有该道具')", message, acc, prod, reason)
}
}
}
func TestClassifyXiaodianRetryStop(t *testing.T) {
cases := []struct {
message string
account bool
product bool
reason string
}{
{"对不起,Livelink登录态校验失败!", true, false, "和平小店绑定已失效,需重新绑定"},
{"不好意思,您的余额不足~", true, false, "点券余额不足"},
{"点券不足,请充值后重试", true, false, "点券余额不足"},
{"未绑定账号", true, false, "账号未绑定角色"},
{"商品不存在", false, true, "商品不可兑换"},
{"已达限量", false, false, ""},
{"已达本次活动兑换上限", false, false, ""},
{"库存不足", false, false, ""},
}
for _, tc := range cases {
account, product, reason := classifyXiaodianRetryStop(tc.message)
if account != tc.account || product != tc.product || reason != tc.reason {
t.Errorf("classifyXiaodianRetryStop(%q) = (%v,%v,%q), want (%v,%v,%q)",
tc.message, account, product, reason, tc.account, tc.product, tc.reason)
}
}
}
func TestFilterCooldownAttempts(t *testing.T) {
attempts := makeAttempts("a", "b", "c")
now := time.Now()
cooldown := map[string]time.Time{
"a": now.Add(5 * time.Second), // 仍在冷却
"b": now.Add(-5 * time.Second), // 已过期
}
out, nextReady := filterCooldownAttempts(attempts, cooldown, now)
if len(out) != 2 {
t.Fatalf("filterCooldownAttempts out length = %d, want 2", len(out))
}
for _, a := range out {
if a.Account.Name == "a" {
t.Errorf("account 'a' should be filtered out")
}
}
if nextReady.IsZero() {
t.Errorf("nextReady should not be zero")
}
if !nextReady.After(now) {
t.Errorf("nextReady should be after now")
}
}
// TestRunNowLogsAggregateInsteadOfPerRequest 锁住日志降噪:
// 默认 info 级下,逐条网络请求不应进入日志,但任务结束要有一行按接口聚合的统计。
func TestRunNowLogsAggregateInsteadOfPerRequest(t *testing.T) {
speedUpPeace(t)
seckillMaxDuration = 1200 * time.Millisecond
scheduler := newOrderTestScheduler(t, func(w http.ResponseWriter, r *http.Request) {
w.Header().Set("Content-Type", "application/json")
switch r.URL.Path {
case "/create":
_, _ = w.Write([]byte(`{"error":1644402023,"msg":"商品本次活动库存已耗完"}`))
case "/bind":
_, _ = w.Write([]byte(`{"error":0,"data":{"gameRole":{"roleName":"测试角色"}}}`))
}
})
scheduler.paths = writeAccountFile(t, "a", "b")
scheduler.accounts = NewAccountStore(scheduler.paths.AccountFile)
scheduler.LoadAccounts()
scheduler.UpdateProducts([]types.Product{{CommodityID: "goods-1", CommodityName: "测试商品"}})
store := logger.NewMemoryLogStore(4000)
cleanup := logger.InitLogging(store, t.TempDir(), "测试实例", "/tmp/douyu-go-test")
defer cleanup()
scheduler.RunNow(map[string]string{"a": "goods-1", "b": "goods-1"})
var aggregate, perRequest, summary string
for _, entry := range store.Since(0) {
switch {
case strings.Contains(entry.Message, "接口统计: 锁定兑换商品"):
aggregate = entry.Message
case strings.Contains(entry.Message, "请求完成:"):
perRequest = entry.Message
case strings.Contains(entry.Message, "抢购任务结束:"):
summary = entry.Message
}
}
if aggregate == "" {
t.Fatalf("缺少按接口聚合的统计行;实际日志:\n%s", dumpMessages(store))
}
if !strings.Contains(aggregate, "失败") || !strings.Contains(aggregate, "最慢=") {
t.Fatalf("聚合行信息不足: %q", aggregate)
}
if perRequest != "" {
t.Fatalf("逐条网络请求日志不应在 info 级出现: %q", perRequest)
}
if summary == "" {
t.Fatalf("缺少任务汇总行;实际日志:\n%s", dumpMessages(store))
}
}
func dumpMessages(store *logger.MemoryLogStore) string {
var b strings.Builder
for _, entry := range store.Since(0) {
b.WriteString(entry.Message)
b.WriteString("\n")
}
return b.String()
}