golang中的定时器由于没有正确释放导致内存和cpu使用率异常

本文首发于我的个人网站: https://pengrl.com/p/1785/

前言

本篇文章介绍如何正确释放golang中的定时器,如果定时器没有正确释放,在一些高性能场景可能导致内存和cpu占用异常。
这是一个很容易踩中的坑。

涉及到 package time
中的以下内容:

func After(d Duration) <-chan Time
func NewTimer(d Duration) *Timer
func NewTicker(d Duration) *Ticker

先把结论放前面:

在高性能场景下,不应该使用time.After,而应该使用New.Timer并在不再使用该Timer后(无论该Timer是否被触发)调用Timer的Stop方法来及时释放资源。不然内存资源可能被延时释放。

使用time.NewTicker时,在Ticker对象不再使用后(无论该Ticker是否被触发过),一定要调用Stop方法,否则会造成内存和cpu泄漏。
注意,本篇文章前后有关联,需要顺序阅读。

time.After

官方文档说明

func After(d Duration) <-chan Time
After waits for the duration to elapse and then sends the current time on the returned channel. It is equivalent to NewTimer(d).C.

由此我们可以知道, After函数等待参数duration所指定的时间到达后才返回,返回的chan中Time的值为当前时间。

After函数等价于time.NewTimer(d).C。
我们再看After函数的源码实现:

func After(d Duration) <-chan Time {
    return NewTimer(d).C
}

确实如上面文档所描述,在内部生成了一个time.Timer的匿名对象,并返回它的chan Time数据成员C。
官方文档中还贴了个小例子:

select {
case m := <-c:
    handle(m)
case <-time.After(5 * time.Minute):
    fmt.Println("timed out")
}

这个例子演示了一小段消费者代码,当消费协程在5分钟内从channel c上接收到数据,则执行消费业务逻辑 handle(m)
,当超过5分钟未接收到数据,则打印超时。
那么问题来了,如果消费协程在5分钟内从channel c上接收到了数据,time.After内部的time.Timer以及Timer内部的channel何时释放?
我们来看以下这段源码中的注释

// The underlying Timer is not recovered by the garbage collector
// until the timer fires. If efficiency is a concern, use NewTimer
// instead and call Timer.Stop if the timer is no longer needed.

意思是,After函数底层所使用的Timer直到timer被触发才会被golang的垃圾回收器处理。如果是高性能场景,应该使用time.NewTimer替代After函数,并且在timer不再使用时调用Timer.Stop。

从程序语意来说,官方文档所举例子中的time.After的case对应的 fmt.Println("timed out")
肯定是不会被执行了,那么注释中的 the timer fires
是什么时候呢?

写demo程序验证

demo程序逻辑

申请10万个协程作为生产者,10万个协程作为消费者,10万个channel,每1个消费者和唯一1个生成者通过1个channel相互关联。

测试场景一,最普通的生产消费模型。消费协程不设置超时,所有的消费协程都被生产协程通过channel唤醒。
测试场景二,消费协程设置超时,但是超时设置的足够长,长到所有的消费协程依然都被channel唤醒。

demo程序源码

package main

import (
    "fmt"
    "log"
    "runtime"
    "sync"
    "sync/atomic"
    "time"
)

var allDone sync.WaitGroup
var consumeCount uint32
var timeoutCount uint32

func nowStats() string {
    var ms runtime.MemStats
    runtime.ReadMemStats(&ms)
    return fmt.Sprintf("Alloc:%d(bytes) HeapIdle:%d(bytes) HeapReleased:%d(bytes) NumGoroutine:%d", ms.Alloc, ms.HeapIdle, ms.HeapReleased, runtime.NumGoroutine())
}

func produce(ch chan int) {
    ch <- 1
}

func consume(ch chan int) {
    //t := time.NewTimer(5 * time.Second)
    select {
    case <-ch:
        atomic.AddUint32(&consumeCount, 1)
    case <-time.After(5 * time.Second):
        //case <- t.C:
        atomic.AddUint32(&timeoutCount, 1)
    }
    //t.Stop()
    allDone.Done()
}

func main() {
    log.Printf("program begin. %s\n", nowStats())

    for i := 0; i < 1000*1000; i++ {
        allDone.Add(1)
        ch := make(chan int, 1)
        go consume(ch)
        go produce(ch)
    }
    allDone.Wait()

    runtime.GC()
    log.Printf("all consumer done. consume count:%d timeoutcount:%d stats:%s\n",
        atomic.LoadUint32(&consumeCount), atomic.LoadUint32(&timeoutCount), nowStats())
    log.Printf("sleep...")
    time.Sleep(10 * time.Second)

    runtime.GC()
    log.Printf("program end. %s\n", nowStats())
}

如何观察

在两个场景下,我们都使用golang中的runtime.MemStats(使用方法可参考我之前写的一篇文章 https://pengrl.com/p/24169/
)来观察demo程序的内存变化。

以下测试数据基于的环境为 centos go1.12.1

第一个场景

程序输出如下:

2019/04/08 11:13:26 program begin. Alloc:44040(bytes) HeapIdle:66666496(bytes) HeapReleased:0(bytes) NumGoroutine:1
2019/04/08 11:13:27 all consumer done. consume count:1000000 timeoutcount:0 stats:Alloc:6110368(bytes) HeapIdle:59203584(bytes) HeapReleased:0(bytes) NumGoroutine:1
2019/04/08 11:13:27 sleep...
2019/04/08 11:13:37 program end. Alloc:6111968(bytes) HeapIdle:59179008(bytes) HeapReleased:0(bytes) NumGoroutine:1
分析:
在所有的消费协程消费结束后(all consumer done.):
Alloc:6110368 表示demo程序申请还未被垃圾回收器回收的内存为 5967KB

HeapIdle:59203584 表示demo程序的垃圾回收器持有且没有归还给操作系统的内存为 56M

结论:该场景的内存使用正常。

第二个场景

程序输出如下:

2019/04/08 11:29:49 program begin. Alloc:44040(bytes) HeapIdle:66666496(bytes) HeapReleased:0(bytes) NumGoroutine:1
2019/04/08 11:29:52 all consumer done. consume count:1000000 timeoutcount:0 stats:Alloc:227885584(bytes) HeapIdle:103030784(bytes) HeapReleased:0(bytes) NumGoroutine:1
2019/04/08 11:29:52 sleep...
2019/04/08 11:30:02 program end. Alloc:19885920(bytes) HeapIdle:311320576(bytes) HeapReleased:0(bytes) NumGoroutine:1
分析:
在所有的消费协程消费结束后(all consumer done.):
Alloc:227885584(bytes) HeapIdle:103030784(bytes)
即demo程序申请还未被垃圾回收器回收的内存为 217M
,demo程序的垃圾回收器持有且没有归还给操作系统的内存为 98M

在等待10秒后(program end.):
Alloc:19885920(bytes) HeapIdle:311320576(bytes)

即demo程序申请还未被垃圾回收器回收的内存下降为 18M
,demo程序的垃圾回收器持有且没有归还给操作系统的内存上升为 296M

结论:
在所有的定时器都没有被触发的场景。如果在定时器设置的时间内(5秒),程序依然持有这部分内存,如果在超过定时器设置的时间后(10秒),程序内存被释放。
但何时进一步释放给操作系统由垃圾回收器决定。

time.NewTimer

我们将上面的demo程序中的time.After更换成time.NewTimer,并调用timer的Stop方法。相关的代码修改如下:

func consume(ch chan int) {
    t := time.NewTimer(5 * time.Second)
    select {
    case <-ch:
        atomic.AddUint32(&consumeCount, 1)
    case <-t.C:
        atomic.AddUint32(&timeoutCount, 1)
    }
    t.Stop()
    allDone.Done()
}

程序输出如下:

2019/04/08 13:44:44 program begin. Alloc:44040(bytes) HeapIdle:66560000(bytes) HeapReleased:0(bytes) NumGoroutine:1
2019/04/08 13:44:47 all consumer done. consume count:1000000 timeoutcount:0 stats:Alloc:11036656(bytes) HeapIdle:119873536(bytes) HeapReleased:49831936(bytes) NumGoroutine:1
2019/04/08 13:44:47 sleep...
2019/04/08 13:44:57 program end. Alloc:11036864(bytes) HeapIdle:119750656(bytes) HeapReleased:49831936(bytes) NumGoroutine:1

分析:
在所有的消费协程消费结束后:
Alloc:11036656(bytes) HeapIdle:119873536(bytes)

即程序申请还未被垃圾回收器回收的内存为 10M
,程序的垃圾回收器持有且没有归还给操作系统的内存为 114M

结论:
说明使用time.NewTimer并调用Stop方法后,内存会立即被垃圾回收器回收。

何时需要调用Stop方法

func (t *Timer) Stop() bool

Stop prevents the Timer from firing. It returns true if the call stops the timer, false if the timer has already expired or been stopped.
调用Stop方法可阻止Timer被触发。如果Stop调用停止了timer,那么返回true,如果timer已经被触发过或者已经被停止了,那么返回false。

结论:
Stop方法在timer未被触发或已被触发或已被关闭的情况下都可以被调用。在高性能场景下,我们应该统一在select结束后,即timer不再使用后调用Stop方法。

time.NewTicker

time.NewTicker和time.NewTimer的区别是Timer只被触发一次,而Ticker会周期性持续触发。
我们将demo程序的NewTimer修改成NewTicker,如果不调用Stop方法,那么不光内存得不到释放,cpu也会周期性的被大量占用,即使我们已经不再使用那个Ticker对象了。(即对应的golang底层的定时器还在工作)