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底层的定时器还在工作)

最后编辑于
©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 158,736评论 4 362
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 67,167评论 1 291
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 108,442评论 0 243
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 43,902评论 0 204
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 52,302评论 3 287
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 40,573评论 1 216
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 31,847评论 2 312
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 30,562评论 0 197
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 34,260评论 1 241
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 30,531评论 2 245
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 32,021评论 1 258
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 28,367评论 2 253
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 33,016评论 3 235
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 26,068评论 0 8
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 26,827评论 0 194
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 35,610评论 2 274
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 35,514评论 2 269