记一次goroutine泄漏的问题

Golang因为有着比线程更加轻量级的协程的出现,使得并发编程的上手难度一下子变得亲民起来。而channel的引入,使得goroutine之间的通信变得异常的便捷。
但好用并不意味着毫无风险,go channel使用不当,也极易引起goroutine泄漏。
何谓goroutine泄漏?就是开启了goroutine,却并没有及时回收,导致goroutine越积越多,如果程序及时关闭还不会出现问题,如果是在服务器中,程序长期运行,就会导致资源占用十分恐怖。
虽然goroutine比线程更轻量级,但每个goroutine至少也会有8~10K的空间,如果goroutine达到了一个恐怖的量级,内存的占用也是十分可怕的。
笔者近期就遇到了一个生产环境的goroutine泄漏问题。

问题复盘

我们有一套go语言开发的程序部署在客户的机器,该程序主要用来接收http请求,并将相应的请求解释成客户端配置文件,下发给客户端。服务器与客户端之间采用的是TCP长连接,二者之间靠心跳机制保活。
除此之外,该服务器还会接收客户端发过来的自监控性能指标信息,通过写ES或其他数据库的方式落到硬盘,以供监控分析。
以上这是背景。
起因是发现其中某一台机器上,该程序运行一段时间后,内存占用达到了数个G,而客户端的连接数量其实并不多。

image.png

通过pprof查看,发现goroutine的数量多得很不正常,甚至达到了13万多个。
image.png

pprof工具定位,最终发现了问题所在,就是因为goroutine泄漏了。
那么,goroutine怎么会泄漏呢?经过分析代码终于发现了端倪,原来问题出在自监控信息上。
为了接受客户端自监控性能指标的信息,我们在服务器的配置文件中配置了数据库信息,如ESMySQLInfluxDb等,客户可以根据自己的需要选择合适的数据库进行存储。自监控信息通过心跳包携带上来。
在设计上是这么做的:心跳接受自监控信息和写数据库分别位于两个协程中,彼此之间通过channel通信。
channel的定义如下,它有1000个缓存:

Runner{
    input: make(chan ProcessMetric, 1000),
    config:            config,
    exporters: make(map[string]Exporter, 0),
}

在心跳接收的地方:

 pm := exporters.ProcessMetric{
    AgentId:      agentID,
    Timestamp:    time.Unix(agentHeartbeatInfo.Monitor.Timestamp/1000, 0),
    HostName:     agentHeartbeatInfo.System.HostName,
    Ip:           agentHeartbeatInfo.System.Connection.Ip,
    Pid:          subProcess.Pid,
    ProcessName:  subProcess.Procname,
    Cmd:          subProcess.Cmd,
    CpuUsageRate: subProcess.CpuUsageRate,
    MemUsage:     subProcess.MemUsage,
    SendLines:    subProcess.SendLines,
}
svr.exporterService.Input() <- pm

写入数据库的地方:

for {
   select {
   case metric := <-exporter.input:
      exporter.process(metric)
   case <-exporter.t:
      return
 }
}

乍看起来这样设计似乎没有什么问题,但是为了代码的健壮性,当用户在配置文件里一个数据库都没配置时,就不会去写到数据库。

if len(runner.config.Exporters) == 0 {
   return nil
}

问题就出在这里。本来这段代码只是为了提高健壮性的,因为监控信息一般都会打开,偏偏真有客户因为机器上没有部署相应的数据库,所以没有打开,所以导致心跳一直在往channel里发信息,但是channel的接收端由于直接return了,导致无法读取,当1000个缓存满了之后,消息就全部阻塞在那里,导致goroutine越来越多,最终达到了数十万个。

问题重现

为了重现这个问题,我将代码抽象出来了,大致如下程序所示:

package main

import (
    "fmt"
    "net/http"
    _ "net/http/pprof"
    "runtime"
    "time"
)

func main() {
    go http.ListenAndServe("0.0.0.0:6060", nil) //注册pprof监控
    ch := make(chan int, 5)                     //go channel,负责go routine之间通信,5个缓存
    flag := false                               //bool类型标记,模拟配置信息,false表示没有配置
    //第一个 go routine, 模拟写数据库信息,这里简化,直接读取channel的内容
    go func() {
        //当flag为false时,直接return,这行代码是导致go routine泄漏的关键
        if !flag {
            return
        }
        for {
            select {
            case recv := <-ch:
                //读取 channel
                fmt.Println("recive channel message:", recv)
            }
        }
    }()

    //for 循环模拟TCP长连接,每隔500ms向channel写一条数据,模拟心跳上报客户端自监控信息
    for {
        i := 0
        time.Sleep(500 * time.Millisecond)
        go func() {
            fmt.Println("goroutine count:", runtime.NumGoroutine())
            i++
            ch <- i
        }()
    }
}

运行上面的程序,发现当channel中5个缓存满了之后,每向channel中写一次数据,goroutine就会多一个,如果不停止程序,goroutine还将无限增加下去。

Feb-04-2021 11-38-07.gif

问题修复

修复这个问题的方法也很简单,在发送端也做一个判断,当flagfalse的时候不向channel发送数据就可以了。

for {
        i := 0
        time.Sleep(500 * time.Millisecond)
        go func() {
            fmt.Println("goroutine count:", runtime.NumGoroutine())
            i++
            if flag {
                ch <- i
            }
        }()
    }

修复后运行情况如下所示:


Feb-04-2021 14-03-21.gif

可见无论运行多久,goroutine数量始终保持在3个,不会随着时间的推移无休止增加。

原理剖析

很多人可能不明白,为什么channel阻塞,会造成goroutine增加。看现象似乎每向channel写入一次数据,就会产生一个goroutine,而每从channel中取出一个数据,就会销毁这个goroutine
其实这么理解也是说得通的。channel本来就是为了goroutine通信用的,数据的传输自然要借助于goroutine
我们打开channel的源码(src/runtime/chan.go),可以看到向channel写入信息的函数其实是chansend1,内部调用的是chansend函数。

// entry point for c <- x from compiled code
//go:nosplit
func chansend1(c *hchan, elem unsafe.Pointer) {
   chansend(c, elem, true, getcallerpc())
}

channel对应的数据结构封装在一个hchan的结构体里,这个结构体的结构如下所示:

type hchan struct {
    qcount   uint // total data in the queue
    dataqsiz uint // size of the circular queue
    buf      unsafe.Pointer // points to an array of dataqsiz elements
    elemsize uint16
    closed   uint32
    elemtype *_type // element type
    sendx    uint // send index
    recvx    uint // receive index
    recvq    waitq // list of recv waiters
    sendq    waitq // list of send waiters  
    // lock protects all fields in hchan, as well as several 
    // fields in sudogs blocked on this channel. 
    // 
    // Do not change another G's status while holding this lock 
    // (in particular, do not ready a G), as this can deadlock 
    // with stack shrinking. 
    lock mutex
}

在这个结构体里,维护了两类队列,一个基于数组的循环队列buf,主要用来缓存数据,还有两个用户缓存阻塞的goroutine的双向队列sendqrecvq
这个buf的大小dataqsiz其实就是我们创建channel时指定的缓存大小。当qcount的数量小于dataqsiz的时候,其实数据是可以放入缓存的。

image.png

buf满了之后,数据就无法再放入缓存队列中了,它就会阻塞在那地方,这些阻塞的数据会新创建一个goroutine,并把这个goroutine存放到sendq队列中。

// Block on the channel. Some receiver will complete our operation for us.
gp := getg()
//这里调用acquireSudog()创建一个goroutine
mysg := acquireSudog()
mysg.releasetime = 0
if t0 != 0 {
   mysg.releasetime = -1
}
// No stack splits between assigning elem and enqueuing mysg
// on gp.waiting where copystack can find it.
mysg.elem = ep
mysg.waitlink = nil
mysg.g = gp
mysg.isSelect = false
mysg.c = c
gp.waiting = mysg
gp.param = nil
//放入sendq队列
c.sendq.enqueue(mysg)
//goroutine进入休眠
gopark(chanparkcommit, unsafe.Pointer(&c.lock), waitReasonChanSend, traceEvGoBlockSend, 2)

如果数据一直发不不去,那么这个goroutine将一直在这里休眠,直到有数据发送出去了,就会唤醒它。

// someone woke us up.
if mysg != gp.waiting {
   throw("G waiting list is corrupted")
}

最后调用releaseSudog函数回收这个sudog(goroutine)。
通过上面的分析,我想大家已经理解了,为什么channel有数据阻塞,就会导致goroutine得不到释放,从而导致更严重的goroutine泄漏问题。

总结

编程千万条,协程第一条;协程有泄露,亲人两行泪!

[参考资料]
golang channel源码阅读

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

推荐阅读更多精彩内容