我好像发现了一个Go的Bug?

捉虫大师
• 阅读 1059

从一次重构说起

这事儿还得从一次重构优化说起。

最近在重构一个路由功能,由于路由比较复杂,需求变化也多,于是想通过责任链模式来重构,刚好这段时间也在 Sentinel-Go 中看到相关源码。

用责任链模式,最大的好处是可以针对每次请求灵活地插拔路由能力,如:

我好像发现了一个Go的Bug?

这样实现会在每次请求到来时去new 出整个责任链,可以预见对象会频繁的创建、销毁。

对 Java 来说,对象池并不推荐,除非对象的创建特别费力,像一个连接对象,否则线程之间的锁竞争绝对比直接分配内存的消耗要多的多~

但 Go 不一样,它内置的 sync.Pool 配合调度模型(GMP)能够刚好规避这种锁竞争。

大家知道 Go 的对象池很牛逼就行了,具体原理不是本文重点,也不是一两句话能解释的清楚,有机会再写一篇文章详细说道~

但理论归理论,是骡子是马,得拉出来遛遛才知道是不是真的牛逼~

我好像发现了一个Go的Bug?

Benchmark 超时!

测试这种性能,Benchmark 肯定是首选,于是我写了个两个例子来对比,直接 New 对象和使用 sync.Pool 池化对象。

func BenchmarkPooledObject(b *testing.B) {
    b.RunParallel(func(pb *testing.PB) {
        for pb.Next() {
            object := pool.Get().(*MyObject)
            Consume(object)
            // 用完了放回对象池
            object.Reset()
            pool.Put(object)
        }
    })
}

func BenchmarkNewObject(b *testing.B) {
    b.RunParallel(func(pb *testing.PB) {
        for pb.Next() {
            object := &MyObject{
                Name: "hello",
                Age:  2,
            }
            Consume(object)
        }
    })
}

当时是这些测试参数

go test -bench=. -cpu=4 -count=2 -benchtime=10s

跑出了如下结果,似乎还是直接 New 对象更快,这和理论不符合啊!

BenchmarkPooledObject-4         1000000000               6.25 ns/op
BenchmarkNewObject-4            1000000000               0.374 ns/op

于是就想,是不是我测试的方法哪里不太对?

池化技术能减少对象的创建、销毁的消耗,有很大一部分得益于减少 GC 次数,是不是我这只跑了10s,还没开始 GC ?

于是我查了下,什么时候 Go 会触发 GC,得到了如下的答案:

  1. 主动调用 runtime.GC 来触发
  2. 被动触发,分为两种:
    • 超过2分钟没有触发,则强制触发 GC
    • 内存增长达到一定比例,触发 GC,比如初始化堆大小为4MB,当增长 25%时,即5MB 时触发一次GC

显然主动触发不合适,被动触发没法确认增长比例,那只能依靠2分钟强制触发 GC 来达到目的了,于是我把基础测试的时间加长,改成了 -benchtime=150s

执行后,就去泡了杯茶,上了个厕所...过了很久,终于执行完了,结果却是这样的结局:

*** Test killed with quit: ran too long (11m0s).

执行失败了,而且还执行了11分钟~

我搜索了下这个报错,网上说的是,Go 的单元测试和 Benchmark 都有超时时间,默认是10分钟,可以通过 -timeout 来修改。

但这不是重点,重点是为啥我设置了150s,却执行了11分钟?

我好像发现了一个Go的Bug?

源码之下没有秘密

直觉告诉我这事不简单,要么是我错了,要么是 Go 错了~ 幸好 Go 是开源的,源码之下没有秘密。

通过 Debug 和代码查阅后,先是找到了这段代码

func (b *B) runN(n int) {
    benchmarkLock.Lock()
    defer benchmarkLock.Unlock()
    defer b.runCleanup(normalPanic)
    // 注意看这里,帮我们GC了
    runtime.GC()
    b.raceErrors = -race.Errors()
    b.N = n
    b.parallelism = 1
    // 重置计时器
    b.ResetTimer()
    // 开始计时
    b.StartTimer()
    // 执行 benchmark 方法 
    b.benchFunc(b)
    // 停止计时
    b.StopTimer()
    b.previousN = n
    b.previousDuration = b.duration
    b.raceErrors += race.Errors()
    if b.raceErrors > 0 {
        b.Errorf("race detected during execution of benchmark")
    }
}

这段代码是在执行一次我们定义的 Benchmark 方法,n 就是传入到我们定义方法参数的 *testing.B 结构中的一个属性。 而且它计算的时间也非常合理,只计算了执行我们定义方法的时间,也就是 -benchtime 的时间只是函数执行的时间,Benchmark 框架的耗时不计算在内。

更合理的是,框架在执行方法前,还帮我们触发了一次 GC,也就是说,只有我们的函数在执行的时候产生的内存垃圾才算到我们的 Benchmark 时间中,非常严谨。

但这跟我们的执行失败毫无关系~

但从一个侧面来说,Benchmark 执行的总时间一定是大于 -benchtime 设置的时间的。

真的是这样吗?我做了两组实验,就打破了这个规律:

go test -bench=. -cpu=4 -count=1 -benchtime=5s

BenchmarkPooledObject-4         793896368                7.65 ns/op
BenchmarkNewObject-4            1000000000               0.378 ns/op
PASS
ok      all-in-one/go-in-one/samples/object_pool        7.890s
go test -bench=. -cpu=4 -count=1 -benchtime=10s

BenchmarkPooledObject-4         1000000000               7.16 ns/op
BenchmarkNewObject-4            1000000000               0.376 ns/op
PASS
ok      all-in-one/go-in-one/samples/object_pool        8.508s

第二组设置了执行 10s,但总的测试时间只有8.508s,很奇怪,更奇怪的是测试结果的第二列执行次数,他们居然都是 1000000000,这么巧吗?

带着疑问,找到了 Benchmark 的这段核心代码:

func (b *B) launch() {
   ...
    // 标注①
    if b.benchTime.n > 0 {
        // We already ran a single iteration in run1.
        // If -benchtime=1x was requested, use that result.
        if b.benchTime.n > 1 {
            b.runN(b.benchTime.n)
        }
    } else {
        d := b.benchTime.d
            // 标注②
        for n := int64(1); !b.failed && b.duration < d && n < 1e9; {
            last := n
            goalns := d.Nanoseconds()
            prevIters := int64(b.N)
            prevns := b.duration.Nanoseconds()
            if prevns <= 0 {
                prevns = 1
            }
                // 标注③
            n = goalns * prevIters / prevns
            // Run more iterations than we think we'll need (1.2x).
            // 标注④
            n += n / 5
            // Don't grow too fast in case we had timing errors previously.
            // 标注⑤
            n = min(n, 100*last)
            // Be sure to run at least one more than last time.
            // 标注⑥
            n = max(n, last+1)
            // Don't run more than 1e9 times. (This also keeps n in int range on 32 bit platforms.)
            // 标注⑦
            n = min(n, 1e9)
            // 标注⑧
            b.runN(int(n))
        }
    }
    b.result = BenchmarkResult{b.N, b.duration, b.bytes, b.netAllocs, b.netBytes, b.extra}
}

核心都标了序号,这里来解释下:

标注①:Go 的 Benchmark 执行两种传参,执行次数和执行时间限制,我用的是执行时间,也可以用 -benchtime=1000x来表示需要测试1000次。

标注②:这里是当设置了执行时间限制时,判断时间是否足够的条件,可以看到除了时间的判断外,还有 n < 1e9 的限制,也就是最多执行次数是 1e9,也就是 1000000000,这解释了上面的一个困惑,为啥执行时间还比设置的 benchtime 小。因为 Go 限制了最大执行次数为 1e9,并不是设置多少就是多少,还有个上限。

标注③到⑧: Go 是如何知道 n 取多少时,时间刚好符合我们设置的 benchtime?答案是试探!

n 从1 开始试探,执行1次后,根据执行时间来估算 n。n = goalns * prevIters / prevns,这就是估算公式,goalns 是设置的执行时间(单位纳秒),prevIters 是上次执行次数,prevns 是上一次执行时间(纳秒)

根据上次执行的时间和目标设定的执行总时间,计算出需要执行的次数,大概是这样吧:

目标执行次数 = 执行目标时间 / (上次执行时间 / 上次执行次数)

化简下得到:

目标执行次数 = 执行目标时间 * 上次执行次数 / 上次执行时间,这不就是上面那个公式~

目标执行次数 n 的计算,源码中还做了一些其他处理:

  • 标注④:让实际执行次数大概是目标执行次数的1.2倍,万一达不到目标时间不是有点尴尬?索性多跑一会
  • 标注⑤:也不能让 n 增长的太快了,设置个最大增长幅度为100倍,当 n 增长太快时,被测试方法一定是执行时间很短,误差可能较大,缓慢增长好测出真实的水平
  • 标注⑥:n 不能原地踏步,怎么也得+1
  • 标注⑦:n 得设置个 1e9 的上限,这是为了在32位系统上不要溢出

Go Benchmark 的执行原理大致摸清了,但我们要的答案还未浮出水面。

接着我对 Benchmark 进行了断点调试。

首先是 -benchtime=10s

发现 n 的试探增长是 1,100,10000,1000000,100000000,1000000000,最终 n 是 1000000000

这说明我们的执行方法耗时很短,执行次数达到了上限。

再看-benchtime=150s,开始还挺正常:

n 增长是 1,100,10000,1000000,100000000,但后一个出现了问题:

我好像发现了一个Go的Bug?

n 居然变成了负数!显然这是溢出了。

n = goalns * prevIters / prevns 这个公式,在目标执行时间(goalns)很大,测试方法执行时间(prevns)很短时,会导致 n 溢出!

溢出有什么后果呢?

后面的 n = min(n, 100*last) 就是负数了,但还有 n = max(n, last+1) 保证,所以 n 还是在增加,不过很慢,每次都只 +1,所以后续试探的 n 序列为 100000001,100000002,100000003....

这就导致了 n 很难达到 1e9 的上限,而且总的执行耗时也很难达到设定的预期时间,所以测试程序会一直跑~直到超时!

这大概是一个Bug吧?

写这段 Benchamrk 逻辑的作者加入了这个 1e9 的执行次数上限,考虑了溢出,但没有考虑 n 在计算过程中的溢出情况。

我觉得这应该是一个 Bug,但不能完全确定。

网上没有找到相关的 Bug 报告,于是去给 Go 官方提了 issue 和相应的修复代码,由于 Go 的开发流程比较复杂和漫长,所以在本文发表时,官方并没有明确表明这是 Bug 还是其他。

如果后续官方有回复或其他变故,我再来告诉大家~


搜索关注微信公众号"捉虫大师",后端技术分享,架构设计、性能优化、源码阅读、问题排查、踩坑实践。

我好像发现了一个Go的Bug?

点赞
收藏
评论区
推荐文章
责任链和策略设计模式-基于Java编程语言
责任链和策略设计模式这两种设计模式非常实用,下面简单介绍一下我对这两种设计模式的理解和它们在Spring框架源码中的应用。
Dubbo架构设计与源码解析(三)责任链模式
责任链模式是设计模式中简单且常见的设计模式,可能我们日常中也会经常应用责任链模式,dubbo中的责任链模式将灵活性发挥的很充分。
Wesley13 Wesley13
2年前
java实现23种设计模式之责任链模式
顾名思义,责任链模式(ChainofResponsibilityPattern)为请求创建了一个接收者对象的链。这种模式给予请求的类型,对请求的发送者和接收者进行解耦。这种类型的设计模式属于行为型模式。在这种模式中,通常每个接收者都包含对另一个接收者的引用。如果一个对象不能处理该请求,那么它会把相同的请求传给下一个接收者,依此类推。pa
京东云开发者 京东云开发者
11个月前
一分钟学会、三分钟上手、五分钟应用,快速上手责任链框架详解 | 京东云技术团队
责任链模式是开发过程中常用的一种设计模式,在SpringMVC、Netty等许多框架中均有实现。我们日常的开发中如果要使用责任链模式,通常需要自己来实现,但自己临时实现的责任链既不通用,也很容易产生框架与业务代码耦合不清的问题,增加CodeReview的成本。
Stella981 Stella981
2年前
Apache commons chain 初探
Apachecommonschain是什么Apachecommonchain是对责任链设计模式的改造封装,让使用者更加方便的使用。简单回顾一下责任链设计模式在阎宏博士的《JAVA与模式》一书中开头是这样描述责任链(ChainofResponsibility)模式的:责任链模式是一种对象的行为模式。在
Stella981 Stella981
2年前
Nepxion Discovery Agent
前言基于SpringCloud的全链路灰度蓝绿发布功能,其中一个场景是,基于Header传递的全链路灰度路由,采用配置中心配置路由策略映射在网关或者服务上,支持根据用户自定义Header跟路由策略整合,最终转化为路由Header信息而实现,路由策略传递到全链路服务中。这是一个非常普遍的需求,但如果业务方用了服务之间异步调用的方式,会导致存储在Th
Wesley13 Wesley13
2年前
Java描述设计模式(15):责任链模式
本文源码:GitHub·点这里(https://www.oschina.net/action/GoToLink?urlhttps%3A%2F%2Fgithub.com%2Fcicadasmile%2Fmodelarithmeticparent)||GitEE·点这里(https://gitee.com/cicadasmile/modela
Wesley13 Wesley13
2年前
Java设计模式之责任链模式
引入责任链模式责任链模式顾名思义,责任链模式(ChainofResponsibilityPattern)为请求创建了一个接收者对象的链。这种模式给予请求的类型,对请求的发送者和接收者进行解耦。这种类型的设计模式属于行为型模式。在这种模式中,通常每个接收者都包含对另一个接收者的引用。如果一个对象不能处理该请求,那么它会
Stella981 Stella981
2年前
FP角度下的责任链模式(中间件模式,middleware)
责任链模式,十分常见,比如说,j2ee里的filter,express里的middleware,redux里的middleware问题是:怎么才可以用最简单的方式实现一个责任链模式?用数组,链表来记录中间件?这些都想过,后来终于找到一种很简单的方式,灵感来自于fp使用者要的是什么对于使用者来说,Middleware
京东云开发者 京东云开发者
8个月前
一文带你读懂设计模式之责任链模式 | 京东云技术团队
翻了一下之前刚入职时候的学习笔记,发现之前在熟悉业务代码的时候曾经专门学习并整理过过设计模式中的责任链模式,之前只是对其简单了解过常用的设计模式有哪些,并未结合实例和源码深入对其探究,利用熟悉代码契机进行系统学习并整理文档如下。