接口超时排查
问题
Go 服务的某个接口偶发或持续超时,如何系统化排查定位根因?
答案
超时链路分析
一个 HTTP 请求的生命周期中,任何环节都可能导致超时:
排查步骤
1. 确认超时位置
# 看监控面板:P50/P95/P99 延迟趋势
# 重点看 P99,偶发超时通常在尾部延迟
# 看接口级别的延迟分布
# Prometheus 查询:
histogram_quantile(0.99,
sum(rate(http_request_duration_seconds_bucket{path="/api/users"}[5m])) by (le)
)
2. 链路追踪定位慢环节
// 在关键操作前后记录 Span
func GetUserProfile(ctx context.Context, userID string) (*Profile, error) {
ctx, span := tracer.Start(ctx, "GetUserProfile")
defer span.End()
// 每个子调用都创建子 Span
user, err := getUser(ctx, userID) // DB 查询
orders, err := getOrders(ctx, userID) // RPC 调用
posts, err := getPosts(ctx, userID) // Redis 查询
return &Profile{User: user, Orders: orders, Posts: posts}, nil
}
在 Jaeger/Zipkin 中搜索超时请求的 TraceID,看哪个 Span 耗时最长。
3. 按慢环节分类排查
原因 1:数据库慢查询
# 检查慢查询日志
mysqldumpslow -t 10 /var/log/mysql/slow.log
# 或看 Go 侧的 SQL 耗时
# GORM 开启慢查询日志
// GORM 慢查询日志
db, _ := gorm.Open(mysql.Open(dsn), &gorm.Config{
Logger: logger.Default.LogMode(logger.Warn), // 慢查询警告
})
常见原因:
- 缺失索引 →
EXPLAIN分析 + 加索引 - 大表全表扫描 → 优化查询条件
- 锁等待 → 减少事务范围
- 连接池满了 → 参考数据库连接池问题
原因 2:下游 RPC/HTTP 调用慢
// ❌ 没有超时控制,下游阻塞导致本服务也超时
resp, err := http.Get("http://downstream/api")
// ✅ 设置请求超时
ctx, cancel := context.WithTimeout(ctx, 3*time.Second)
defer cancel()
req, _ := http.NewRequestWithContext(ctx, "GET", "http://downstream/api", nil)
resp, err := http.DefaultClient.Do(req)
超时传递
下游超时应短于上游。如果接口总超时 5s,调 DB 超时 2s,调 RPC 超时 2s,预留 1s 给本身逻辑。
// 超时预算分配
func Handler(ctx context.Context) error {
// 总预算 5s(来自上游 context)
deadline, _ := ctx.Deadline()
remaining := time.Until(deadline)
// DB 查询预算:2s
dbCtx, cancel1 := context.WithTimeout(ctx, min(2*time.Second, remaining))
defer cancel1()
user, err := queryDB(dbCtx)
// RPC 调用预算:2s
rpcCtx, cancel2 := context.WithTimeout(ctx, min(2*time.Second, remaining))
defer cancel2()
data, err := callRPC(rpcCtx)
return nil
}
原因 3:Redis 慢操作
# Redis 慢查询日志
redis-cli SLOWLOG GET 10
常见原因:
KEYS *等 命令- 大 Key(value 几 MB)
- 网络延迟(跨机房)
- 连接池不够
原因 4:GC STW
GODEBUG=gctrace=1 ./myapp
# gc 12 @2.5s 8%: 0.15+25+0.10 ms clock
# ^^^ STW 时间 25ms
# 如果 STW > 10ms 且频繁,会导致尾部延迟
优化:
- 减少内存分配
- sync.Pool 复用对象
- 调整 GOGC / GOMEMLIMIT
原因 5:锁竞争
# 启用 mutex profile
go tool pprof http://localhost:6060/debug/pprof/mutex
// ❌ 持锁时间过长
mu.Lock()
data := expensiveComputation() // 耗时操作在锁内
cache[key] = data
mu.Unlock()
// ✅ 缩小临界区
data := expensiveComputation() // 先算好
mu.Lock()
cache[key] = data // 只保护赋值
mu.Unlock()
原因 6:DNS 解析
// 默认每次 HTTP 请求都可能触发 DNS 解析
// 如果 DNS 服务器慢,会增加延迟
// 解决:使用连接池复用 TCP 连接
transport := &http.Transport{
MaxIdleConns: 100,
MaxIdleConnsPerHost: 10,
IdleConnTimeout: 90 * time.Second,
}
client := &http.Client{
Transport: transport,
Timeout: 10 * time.Second,
}
超时设置最佳实践
// 服务端:请求总超时
srv := &http.Server{
ReadTimeout: 5 * time.Second,
WriteTimeout: 10 * time.Second,
IdleTimeout: 120 * time.Second,
}
// 客户端:下游调用超时
client := &http.Client{
Timeout: 5 * time.Second,
Transport: &http.Transport{
DialContext: (&net.Dialer{
Timeout: 2 * time.Second, // 连接超时
}).DialContext,
TLSHandshakeTimeout: 2 * time.Second,
ResponseHeaderTimeout: 3 * time.Second,
},
}
// 数据库超时
dsn := "user:pass@tcp(host:3306)/db?timeout=3s&readTimeout=3s&writeTimeout=3s"
// Redis 超时
rdb := redis.NewClient(&redis.Options{
DialTimeout: 2 * time.Second,
ReadTimeout: 1 * time.Second,
WriteTimeout: 1 * time.Second,
PoolTimeout: 3 * time.Second,
})
排查清单
| 检查项 | 方法 |
|---|---|
| 哪个接口超时? | 监控面板 P99 延迟 |
| 哪个环节慢? | 链路追踪(Jaeger) |
| 是 DB 慢? | 慢查询日志 + EXPLAIN |
| 是下游慢? | 下游延迟指标 |
| 是 GC? | gctrace + pprof heap |
| 是锁? | pprof mutex/block |
| 是连接问题? | 连接池监控 |
常见面试问题
Q1: 接口偶发超时但大部分正常(P99 高,P50 正常),原因有哪些?
答案:
- GC STW(影响少量请求)
- 锁竞争(部分请求等锁)
- 数据库连接池瞬时耗尽
- 下游服务偶发慢响应
- DNS 解析超时
- Linux TCP 重传
- 定位方法:收集多个超时案例的 trace,找共性
Q2: Context 超时传递怎么设计?
答案:
- 入口层设置总超时(如网关 10s)
- 每个下游调用用
context.WithTimeout设更短的超时 - 超时预算层层递减,确保不超过上游 deadline
ctx.Deadline()可以读取剩余预算
Q3: 如何预防接口超时?
答案:
- 所有外部调用(DB、Redis、RPC)必须设置超时
- 慢操作异步化(消息队列)
- 非核心依赖加熔断器
- 设置合理的超时预算
- 链路追踪 + 延迟告警
Q4: HTTP Client 的各种超时参数什么区别?
答案:
Client.Timeout:整个请求的总超时Transport.DialContext.Timeout:TCP 连接建立超时TLSHandshakeTimeout:TLS 握手超时ResponseHeaderTimeout:等待响应 Header 超时- 建议都设置,每层独立控制