[Golang]记一次Goroutine泄露问题的排查

image

问题描述

之前组内一个线上服务的内存使用率稳定上扬, 查看监控,发现内存的使用趋势如下图,这种趋势是典型的内存泄露,不解决的话服务会OOM。

image

问题定位

于是尝试用pprof定位问题,俗话说:Go里面10次内存泄露9次是goroutine泄露。这次也不例外, 系统的内存泄露是由类似下面的代码引起的:

package main

import (
    "fmt"
    "net/http"
    "sync"
    _ "net/http/pprof"
)

func bug(_ http.ResponseWriter, _ *http.Request) {
    taskChan := make(chan int, 100)

    for i := 0; i < 100; i++ {
        taskChan <- i
    }
  
  consumer := func() {
        for task := range taskChan {
            fmt.Println(task)
        }
    }

    for i := 0; i < 100; i++ {
        go consumer()
    }
}

func main() {
    http.HandleFunc("/bug", bug)
    http.ListenAndServe(":8000", nil)
}


这里的 bug函数是一个典型的 生产者-消费者模型,逻辑是这样的:

  1. 声明一个容量为100的队列buffer
  1. 开一个循环,生产消息并发送至队列
  1. 声明消费者,消费者会对队列里的元素进行rpc操作 (这里用fmt.Print代替)
  1. 开100个协程进行消费

让我们尝试用 pprof工具定位一下问题,首先在浏览器里访问若干次这个url: http://127.0.0.1:8000/bug ,然后访问pprof的url查看系统运行情况:http://127.0.0.1:8000/debug/pprof/, 发现系统中有大量的goroutine阻塞着(平时只有200~300个)。

image

点击goroutine,进入 http://127.0.0.1:8000/debug/pprof/goroutine?debug=1这个链接,此时系统中一共有1704个goroutine,其中有1700个goroutine阻塞在 /go/src/go-test/bug/chan_OOM.go:18这一行:

image

把url参数改为 debug=2,可以看到每个goroutine的信息,用刚刚的调用栈以及行数作为查找参数,随意找一个goroutine查看详细信息:

image

这里显示ID为448的goroutine当前的状态为 chan receive ,阻塞了12分钟,阻塞在18行。

这个bug接口会被定时访问,每次访问都会新起100个goroutine。这些goroutine一直处于[chan receive] 的状态无法释放,导致goroutine占用的内存无法释放,系统长期运行下去,最终服务无可用内存,OOM~

问题的原因以及解决

goroutine泄露大概有两个场景:

  1. channel操作阻塞导致runtime期间goroutine一直在阻塞等待;

  2. goroutine有死循环;

这段代码发生泄露的原因就是channel没有关闭,goroutine一直引用channel,没有得到退出信号,导致其一直存活。知道了这个原因之后,还是比较好改的,把channel关闭即可。

package main

import (
    "fmt"
    "net/http"
    _ "net/http/pprof"
    "sync"
)

func bug(_ http.ResponseWriter, _ *http.Request) {
    taskChan := make(chan int, 100)

    for i := 0; i < 100; i++ {
        taskChan <- i
    }

    consumer := func() {
        for task := range taskChan {
            fmt.Println(task)
        }
    }

    for i := 0; i < 100; i++ {
        go consumer()
    }
}

func bugfix(_ http.ResponseWriter, _ *http.Request) {
    taskChan := make(chan int, 100)

    for i := 0; i < 100; i++ {
        taskChan <- i
    }

    consumer := func() {
        for task := range taskChan {
            fmt.Println(task)
        }
    }

    for i := 0; i < 100; i++ {
        go consumer()
    }
    close(taskChan) // bugfix
}

func main() {
    http.HandleFunc("/bug", bug)
    http.HandleFunc("/bugfix", bugfix)

    http.ListenAndServe(":8000", nil)
}

总结

俗话说: Go里面10次内存泄露9次是goroutine泄露引起的。而goroutine泄露大多是由于channel使用不当造成的。这个bug虽然不是我写的,但是要引以为戒~ 平时多看看channel不同模型的使用案例,不然容易踩坑~