【踩坑笔记】一次加锁和超时控制引起的交通事故

问题回顾

线上发现流量接入层好像扛不住,一直在被 OOM,并且客户出现大面积的超时。但是流量并没有打到后端的业务层。
在回滚代码,并且加机器之后,问题被解决了。

问题定位与解决

首先,怀疑是流量过大引起的。但是奇怪的点在于大部分流量没有打到业务层。通过分析流量接入层的日志,我们发现 有两个相邻日志输出的时间间隔比较长。而这两条日志输出之间正是有回滚的代码。所以,我们将问题定位的方向转移到了代码层面。

但是,线下压测过程中,并没有发现类似的严重耗时问题,(怀疑是测试 case 没有覆盖到)。于是,先人工 Review 一遍变动的代码。我们发现,有一个代码片段是加锁的,代码如下所示(golang 省略部分细节):

    // key1
    if val, exist := rateMap.Load(key1); exist {
        return true, val.(*RateLimit).Taken(count)
    }

    Lock.Lock()
    defer Lock.Unlock()
    if mapC, exist := RateLimitC[flag1]; exist {
        for _, val := range mapC {
            if key1_ok {
                rateLimit := NewRateLimit(val.Qps)
                rateLimit.Create()
                rateMap.Store(key1, &rateLimit)
                return true, rateLimit.Taken(count)
            }
        }
    }

    // key2
    if val, exist := rateMap.Load(key2); exist {
        return true, val.(*RateLimit).Taken(count)
    }

    for _, val := range RateLimitC[flag2] {
        if key2_ok {
            rateLimit := NewRateLimit(val.Qps)
            rateLimit.Create()
            rateMap.Store(key2, &rateLimit)
            return true, rateLimit.Taken(count)
        }
    }

这是一段 QPS 限流的逻辑,内部实现利用了令牌桶算法,(先忽略有待优化的逻辑,我们来看为什么会出现问题)
代码的大概意思是:

如果用 key1 获取到了 token,就直接返回;否则,加锁,看是 map 里是否有 flag1 代表的限流信息,如果有,则判断是否有符合 key1 条件的,如果有,则走正常获取 token 逻辑;如果没有,则尝试用 key2 获取 token,(下边逻辑类似 key1)

问题就出在线上大部分情况需要用 key2 来获取 token,所以大部分请求都会进入加锁区域。如果只是一个加锁,应该很快就能处理完,但是会有堆积性的耗时呢。
我们来看一下 val.(*RateLimit).Taken(count) 的实现:

func (this *RateLimit) Taken(count int) error {
    timer := time.NewTimer(time.Duration(count) * TimeDuration)
    defer timer.Stop()

    for i := count; i > 0; i-- {
        select {
        case <-this.BucketCh:
        case <-timer.C:
            return errors.New("not get bucket")
        }
    }

    return nil
}

里边有个超时机制,如果限定时间内没有获取到 token,则返回错误。

那么,现在的问题是,所有走通过 key2 获取 token 都会在加锁的区域串行通过,那么,当没有立即获取 token 的请求,阻塞在计时器的时候,其他等待锁的请求都会阻塞在加锁的阶段,直到上一个请求超时,或者获取到 token,他才能获得锁。
换句话说,这条路是一个单行道,一次只能有一人通过,这个人还经常卡在收费站口,那么后边来的人就可能会越积越多,等待的时间越来越长,最后把路都给压垮了。

总结

像这种错误,想到之后是很容易复现的,而且只要满足条件,这个 bug 必现。
反思:

  1. 开发最了解代码,功能完成之后,需要自己想一下测试的 case,尽量可以自己覆盖到;
  2. 如果只看锁的部分,不觉得有什么问题,但是跟上下文结合起来,问题显而易见(lock + timer);

另外,这种耗时问题,可以在线下用 go 官方的 pprof 包,查看一下程序的耗时情况,也是可以发现的。

    原文作者:fevin
    原文地址: https://segmentfault.com/a/1190000015805060
    本文转自网络文章,转载此文章仅为分享知识,如有侵权,请联系博主进行删除。
点赞