慢调用先吃掉容量,再制造超时
5.2 用舱壁把下游隔开,但舱壁只限制“同时进去多少”,不解决“进去之后多久出来”。一个下游从 20ms 变成 300ms,占用时间放大 15 倍;在固定 worker 或连接上限下,可用容量同步缩到 1/15。请求先堆在队列,队列满了开始阻塞提交,最后上游自己的 deadline 到期——用户看到的是“下单超时”,根因却在下游的一个慢查询。
本站 熔断与限流 讨论过何时切断下游,本节只处理切断之前的链路:deadline 怎样传、取消怎样生效、慢调用怎样统计,以及用什么证据证明扩散链被截断。
扩散链的四个阶段
| 阶段 | 现象 | 关键指标 | 常见误判 |
|---|---|---|---|
| 下游变慢 | P99 从 20ms 到 300ms | 下游 P99、错误率 | “只是偶发慢查询” |
| 容量被占 | worker/连接全部在途 | 在途数、连接池使用率 | “线程池太小,扩容” |
| 队列打满 | 提交开始阻塞 | 队列深度、提交阻塞次数 | “加大队列就能扛” |
| 上游超时 | 网关 5xx/504 上升 | 网关超时数、端到端 P99 | “网关有问题” |
这四个阶段里,只有第一阶段发生在下游;后三个阶段都是本进程的排队与等待。扩容 worker 会把更多请求同时压给已经变慢的下游,通常让第二阶段更糟;加大队列只是把超时推迟到上游 deadline。正确的顺序是先用 deadline 限制单次占用,再用取消释放已放弃的请求,最后才考虑舱壁和扩容。
用 Guard 把 deadline、取消、统计绑在一起
Guard.Do 从调用方 context 派生一个带 Budget 的子 context。context.WithTimeout 会保留更早的截止时间,所以上游只剩 40ms 时,这里配 500ms 也不会把下游延长到 500ms。调用返回后按三种情况分类:父 context 被取消记 Canceled,子 context 到期记 Timeout,其余错误原样返回;耗时超过 SlowThreshold 的调用另外记 Slow。
P99 来自一个固定容量的环形窗口。窗口是实例级、时间窗级的,不能把多个实例的 P99 平均成集群 P99;要集群口径,应在网关或指标系统里对直方图合并,而不是对分位数求平均。
// file: internal/platform/slowcall/guard.go
// tier: L1
// verify: go test ./internal/platform/slowcall/
package slowcall
import (
"context"
"errors"
"sort"
"sync"
"sync/atomic"
"time"
)
var (
ErrTimeout = errors.New("slowcall: deadline exceeded")
ErrCanceled = errors.New("slowcall: canceled by caller")
)
type Config struct {
Budget time.Duration
SlowThreshold time.Duration
MaxSamples int
}
type Stats struct {
Calls, Completed, Timeouts, Canceled, Slow int64
InFlight, MaxInFlight int64
}
// Guard bounds one downstream call by the caller's deadline and classifies
// timeout, cancellation, and slow-but-successful calls separately.
type Guard struct {
cfg Config
mu sync.Mutex
samples []time.Duration
next int
calls atomic.Int64
completed atomic.Int64
timeouts atomic.Int64
canceled atomic.Int64
slow atomic.Int64
inFlight atomic.Int64
maxInFlight atomic.Int64
}
func New(cfg Config) *Guard {
if cfg.Budget <= 0 {
cfg.Budget = time.Second
}
if cfg.SlowThreshold <= 0 {
cfg.SlowThreshold = cfg.Budget / 2
}
if cfg.MaxSamples < 1 {
cfg.MaxSamples = 1024
}
return &Guard{cfg: cfg}
}
// Do can only tighten the parent: WithTimeout keeps the earlier deadline.
func (g *Guard) Do(parent context.Context, fn func(context.Context) error) error {
ctx, cancel := context.WithTimeout(parent, g.cfg.Budget)
defer cancel()
g.calls.Add(1)
bump(&g.maxInFlight, g.inFlight.Add(1))
start := time.Now()
err := fn(ctx)
g.inFlight.Add(-1)
g.record(time.Since(start))
switch {
case parent.Err() == context.Canceled:
g.canceled.Add(1)
return ErrCanceled
case ctx.Err() == context.DeadlineExceeded:
g.timeouts.Add(1)
return ErrTimeout
case err != nil:
return err
}
g.completed.Add(1)
return nil
}
// A bounded ring keeps memory flat; P99 is a window, not all history.
func (g *Guard) record(d time.Duration) {
if d >= g.cfg.SlowThreshold {
g.slow.Add(1)
}
g.mu.Lock()
if len(g.samples) < g.cfg.MaxSamples {
g.samples = append(g.samples, d)
} else {
g.samples[g.next] = d
g.next = (g.next + 1) % len(g.samples)
}
g.mu.Unlock()
}
func (g *Guard) Stats() Stats {
return Stats{
Calls: g.calls.Load(), Completed: g.completed.Load(),
Timeouts: g.timeouts.Load(), Canceled: g.canceled.Load(),
Slow: g.slow.Load(), InFlight: g.inFlight.Load(),
MaxInFlight: g.maxInFlight.Load(),
}
}
// P99 is per-instance and per-window; never average it across instances.
func (g *Guard) P99() time.Duration {
g.mu.Lock()
values := append([]time.Duration(nil), g.samples...)
g.mu.Unlock()
if len(values) == 0 {
return 0
}
sort.Slice(values, func(i, j int) bool { return values[i] < values[j] })
return values[len(values)*99/100]
}
func bump(dst *atomic.Int64, v int64) {
for cur := dst.Load(); v > cur; cur = dst.Load() {
if dst.CompareAndSwap(cur, v) {
return
}
}
}
复现扩散链:修复前 vs 修复后
测试用一个 300ms 的慢下游,16 个 worker、32 个队列位、网关 deadline 100ms,以 7ms 间隔发 240 个请求(约 142/s)。修复前 worker 用 context.Background() 调下游,客户端放弃后调用仍在跑;修复后 worker 走 Guard,预算 70ms。
// file: internal/platform/slowcall/spread_test.go
// tier: L1
// verify: go test ./internal/platform/slowcall/ -count=1 -v
package slowcall
import (
"context"
"errors"
"sync"
"sync/atomic"
"testing"
"time"
)
func TestGuardClassifies(t *testing.T) {
g := New(Config{Budget: 80 * time.Millisecond, SlowThreshold: 50 * time.Millisecond})
_ = g.Do(context.Background(), func(context.Context) error { return nil })
timeout := func(ctx context.Context) error { <-ctx.Done(); return ctx.Err() }
if err := g.Do(context.Background(), timeout); !errors.Is(err, ErrTimeout) {
t.Fatal(err)
}
parent, cancel := context.WithCancel(context.Background())
cancel()
if err := g.Do(parent, timeout); !errors.Is(err, ErrCanceled) {
t.Fatal(err)
}
if s := g.Stats(); s.Calls != 3 || s.Completed != 1 || s.Timeouts != 1 || s.Canceled != 1 || s.Slow != 1 {
t.Fatalf("stats = %+v", s)
}
t.Logf("calls=3 completed=1 timeouts=1 canceled=1 slow=1 p99=%s", g.P99().Round(time.Millisecond))
}
type downstream struct {
latency time.Duration
active atomic.Int64
peak atomic.Int64
calls atomic.Int64
canceled atomic.Int64
}
func (d *downstream) Call(ctx context.Context) error {
d.calls.Add(1)
bump(&d.peak, d.active.Add(1))
defer d.active.Add(-1)
select {
case <-time.After(d.latency):
return nil
case <-ctx.Done():
d.canceled.Add(1)
return ctx.Err()
}
}
type request struct {
ctx context.Context
done chan error
}
type service struct {
queue chan *request
down *downstream
guard *Guard
inFlight atomic.Int64
peakFlight atomic.Int64
peakQueue atomic.Int64
blocked atomic.Int64
}
func newService(workers, queue int, d *downstream, g *Guard) *service {
s := &service{queue: make(chan *request, queue), down: d, guard: g}
for i := 0; i < workers; i++ {
go func() {
for req := range s.queue {
bump(&s.peakFlight, s.inFlight.Add(1))
var err error
if s.guard != nil {
err = s.guard.Do(req.ctx, s.down.Call)
} else {
err = s.down.Call(context.Background())
}
s.inFlight.Add(-1)
req.done <- err
}
}()
}
return s
}
func (s *service) handle(ctx context.Context) error {
req := &request{ctx: ctx, done: make(chan error, 1)}
select {
case s.queue <- req:
bump(&s.peakQueue, int64(len(s.queue)))
case <-ctx.Done():
s.blocked.Add(1)
return ctx.Err()
}
select {
case err := <-req.done:
return err
case <-ctx.Done():
return ctx.Err()
}
}
type report struct {
svcTimeout, gateway, peakFlight, peakQueue, blocked int64
downPeak, downCanceled int64
}
func runVariant(t *testing.T, fixed bool, budget time.Duration) report {
t.Helper()
d := &downstream{latency: 300 * time.Millisecond}
var g *Guard
if fixed {
g = New(Config{Budget: budget, SlowThreshold: budget})
}
s := newService(16, 32, d, g)
var svcTimeout, gateway atomic.Int64
var wg sync.WaitGroup
for i := 0; i < 240; i++ {
wg.Add(1)
go func() {
defer wg.Done()
ctx, cancel := context.WithTimeout(context.Background(), 100*time.Millisecond)
defer cancel()
switch err := s.handle(ctx); {
case errors.Is(err, ErrTimeout):
svcTimeout.Add(1)
case errors.Is(err, context.DeadlineExceeded):
gateway.Add(1)
}
}()
time.Sleep(7 * time.Millisecond)
}
wg.Wait()
time.Sleep(50 * time.Millisecond)
return report{
svcTimeout: svcTimeout.Load(), gateway: gateway.Load(),
peakFlight: s.peakFlight.Load(), peakQueue: s.peakQueue.Load(), blocked: s.blocked.Load(),
downPeak: d.peak.Load(), downCanceled: d.canceled.Load(),
}
}
func TestFailureSpreadBeforeAfter(t *testing.T) {
before := runVariant(t, false, 0)
after := runVariant(t, true, 70*time.Millisecond)
t.Logf("before svc_timeout=%d gateway_timeout=%d peak_flight=%d peak_queue=%d submit_blocked=%d down_peak=%d down_canceled=%d",
before.svcTimeout, before.gateway, before.peakFlight, before.peakQueue,
before.blocked, before.downPeak, before.downCanceled)
t.Logf("after svc_timeout=%d gateway_timeout=%d peak_flight=%d peak_queue=%d submit_blocked=%d down_peak=%d down_canceled=%d",
after.svcTimeout, after.gateway, after.peakFlight, after.peakQueue,
after.blocked, after.downPeak, after.downCanceled)
if before.gateway < 50 || before.blocked < 50 || before.downCanceled != 0 {
t.Fatalf("before did not reproduce the spread: %+v", before)
}
if after.gateway != 0 || after.blocked != 0 || after.downCanceled < 230 {
t.Fatalf("after did not stop the spread: %+v", after)
}
if after.peakFlight > 16 || after.downPeak > 16 {
t.Fatalf("after exceeded worker bound: flight=%d down=%d", after.peakFlight, after.downPeak)
}
}
本机 macOS darwin/arm64、Go 1.26.0,单次运行;原始输出在 .local/reports/be-arch/be-arch-perf-05-3-spread-tests.txt:
$ go test ./internal/platform/slowcall/ -count=1 -v
before svc_timeout=0 gateway_timeout=240 peak_flight=16 peak_queue=32 submit_blocked=96 down_peak=16 down_canceled=0
after svc_timeout=240 gateway_timeout=0 peak_flight=10 peak_queue=1 submit_blocked=0 down_peak=10 down_canceled=240
| 指标 | 修复前 | 修复后 | 说明 |
|---|---|---|---|
| 网关超时 | 240 | 0 | 请求在 100ms 客户端 deadline 前拿到明确结果 |
| 服务超时 | 0 | 240 | 70ms 预算到期,返回 TIMEOUT 而不是拖着 |
| 提交阻塞 | 96 | 0 | 修复前队列满,handler 卡在入队 |
| 峰值排队 | 32 | 1 | 队列从未打满 |
| 下游在途峰值 | 16 | 10 | 修复后由到达率 × 70ms 决定 |
| 下游取消数 | 0 | 240 | 每个放弃的请求都通知了下游 |
修复前 240 个请求全部由网关超时收尾:worker 被 300ms 调用占满,队列 32 个位置填满后又有 96 次提交阻塞,客户端在 100ms 时先放弃。修复后没有一次网关超时,全部在 70ms 由服务返回 TIMEOUT;下游在途从 16 降到 10,240 次调用都收到取消。注意修复后仍然“全部失败”——在 300ms 下游和 70ms 预算下这是正确结果,区别是失败变得有界、可归因,且不再占用容量。
三层指标必须同时看
| 层 | 必看指标 | 能回答的问题 |
|---|---|---|
| 网关 | 5xx/504 比例、端到端 P99、在途请求数 | 用户是否在超时,超时发生在哪一段 |
| 服务 | 队列深度、提交阻塞数、worker 在途、取消数 | 容量是被下游占用还是被队列占用 |
| 下游 | 连接数、请求 P99、错误率、被取消比例 | 是下游真的慢,还是调用方提前放弃 |
只看网关,会把容量问题误判成网关故障;只看下游,会漏掉本进程队列里的等待;只看服务,无法区分“下游慢”和“下游已经拒绝”。三者要用同一个 trace id 串起来,且时间窗口对齐,否则“下游 P99 正常、网关超时高”可能只是两个五分钟窗口错位。
取消只有在 downstream 配合时才生效
Guard 的取消依赖下游监听 ctx.Done()。数据库驱动、HTTP 客户端、gRPC 通常支持 context;但有些 SDK 只支持连接级超时,或者根本不接受 context。这种情况下取消不会立刻释放连接,只会让调用方先返回;连接仍被占用到下游自己结束。处理办法是把取消能力纳入下游选型:不接受 context 的客户端,必须配置 socket/连接超时,并在池层面限制最大在途;无法限制的,只能靠舱壁和熔断把它隔离。不要把“调用了 cancel”当成“下游已经停止工作”,后者要用下游的取消计数或连接释放指标验证。
修复顺序与退出条件
顺序应该是:先给每个下游加 deadline(小于上游剩余预算),再确认下游响应取消,然后加舱壁限制并发,最后才考虑扩容。反过来先扩容,会把慢下游压得更狠。deadline 的退出条件是下游 P99 连续一周低于预算的 50%,此时可以适当放宽以容纳长尾;如果放宽后网关超时回升,说明长尾仍在,应恢复。取消的退出条件是下游取消比例持续低于 1%,说明请求很少被放弃,可以简化取消路径;但不要删除,因为故障时它仍是唯一能释放容量的机制。
常见错误与边界
第一,只在网关设超时。网关 100ms 到期时,服务内部的调用还在跑,worker 和连接继续被占用,超时只是把等待转移到用户侧。
第二,每层重新设一个完整的超时。库存 100ms、支付 100ms、通知 100ms 串起来最坏 300ms,超过上游预算;应传绝对截止时间。
第三,取消不传递。服务返回了 TIMEOUT,但下游调用仍用 Background,取消只停留在本进程。
第四,把慢调用统计做成只记成功请求。超时和被取消的调用恰恰是最需要看的样本,只统计成功会让 P99 永远好看。
第五,用单实例 P99 代表集群。每台机器的窗口不同,直接平均分位数会掩盖长尾;应合并直方图或看网关端到端指标。
小结
慢调用的破坏力来自容量占用:300ms 下游在 16 个 worker 下把服务容量压到约 53/s,队列填满后提交阻塞,最终由网关 deadline 收尾。Guard 用派生 deadline、取消传递和分类统计把这条链截断;真实单次运行中,240 个请求的网关超时从 240 降到 0,提交阻塞从 96 降到 0,下游取消从 0 升到 240,代价是全部请求在 70ms 明确返回 TIMEOUT。下一章从单次调用转向入口流量,讨论限流算法与分布式限流。
阅读导航:上一节:5.2 舱壁隔离与资源配额 · 下一节:6.1 限流算法与分布式限流 。
继续阅读
探索更多技术文章
浏览归档,发现更多关于系统设计、工具链和工程实践的内容。