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

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

第二个场景

程序输出如下：

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

结论：

在所有的定时器都没有被触发的场景。如果在定时器设置的时间内（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底层的定时器还在工作）