zoukankan      html  css  js  c++  java
  • go内存泄露case

    用go写了一个守护进程程序:用于检測redis的存活状态并将结果写到zookeeper中,部署到redis机器上。对于每一个redis实例会有一个goroutine每隔固定时间去检測其状态,由主goroutine负责信号处理等。再接收到信号时kill其它的goroutine。程序执行了一段时间发现,有些redis实例的相应zookeeper的信息不更新。通过日志发现相应redis的goroutine挂掉了。

    阅读源代码发现貌似是zk的第三方库抛出一个非预期的异常导致。

    为了解决问题,对逻辑重构:由主goroutine每隔固定时间,对于每一个redis实例启动一个goroutine去进行检測,避免出现非预期异常导致goroutine挂掉,从而状态信息不更新的情况。

    因为goroutine的创建开销非常低,而且golang官方推荐使用大量的goroutine来抗并发,所以这样的方式实现也非常合理。重构完。上线測试发现存在内存泄露。

    (1)观察GC

    首先对代码review,因为半年前写的,而且近期都没用golang,所以没有发现bug。

    接着,就想看下gc相关的信息。或许可能透漏些东西。网上查了golang gc相关,在runtime的doc中描写叙述了。通过环境变量设置GODEBUG='gctrace=1'能够让go的执行时把gc打印信息到stderr。

    GODEBUG='gctrace=1' ./sentinel-agent >gc.log &
    gc.log的输出例如以下:

    gc781(1): 1+2385+17891+0 us, 60 -> 60 MB, 21971 (3503906-3481935) objects, 13818/14/7369 sweeps, 0(0) handoff, 0(0) steal, 0/0/0 yields
    gc782(1): 1+1794+18570+1 us, 60 -> 60 MB, 21929 (3503906-3481977) objects, 13854/1/7315 sweeps, 0(0) handoff, 0(0) steal, 0/0/0 yields
    gc783(1): 1+1295+20499+0 us, 59 -> 59 MB, 21772 (3503906-3482134) objects, 13854/1/7326 sweeps, 0(0) handoff, 0(0) steal, 0/0/0 yields
    
    gc781:从程序启动開始,第781次gc

    (1):參与gc的线程个数

    1+2385+17891+0:各自是1)stop-the-world的时间。即暂停全部goroutine。2)清扫标记对象的时间;3)标记垃圾对象的时间;4)等待线程结束的耗时。单位都是us。4者之和就是gc暂停的总体耗时

    60 -> 60 MB:gc后,堆上存活对象占用的内存。以及整个堆大小(包含垃圾对象)

    21971 (3503906-3481935) objects:gc后,堆上的对象数量,gc前分配的对象以及本次释放的对象

    13818/14/7369 sweeps:描写叙述对象清扫阶段。一共同拥有13818个memory span。当中14在后台被清扫。7369在stop-the-world期间被清扫

    0(0) handoff。0(0) steal:描写叙述并行标记阶段的负载均衡特性。

    当前在不同线程间传送操作数和总传送操作数。以及当前steal操作数和总steal操作数

    0/0/0 yields:描写叙述并行标记阶段的效率。在等待其它线程的过程中。一共同拥有0次yields操做

    经过观察gc的输出,发现当前堆上对象总数不断增多,没有降低的趋势。这说明存在对象的泄露,从而导致内存泄露。

    (2)memory profile

    依据golang官网profile指南,在代码中加入

    import _ "net/http/pprof"
    
    func main() {
        go func() {
            http.ListenAndServe("localhost:6060", nil)
        }()
    }
    能够在执行时对程序进行profile,通过http訪问:

    go tool pprof http://localhost:6060/debug/pprof/heap

    进行memory profile,默认是--inuse_space,显示当前活跃的对象(不包含垃圾对象)占用的空间。

    使用--alloc_space能够显示全部分配的对象(包含垃圾对象)。

    只是这两种方式都没有发现异常。

    (3)监控goroutine个数

    通过runtime.NumGoroutine()能够获取当前的goroutine的个数。通过给程序加入http server获取一些统计信息来了解程序的执行状态,这是Jeff Dean推崇的方法。通过加入下述代码来实时查看goroutine的个数

        // goroutine stats and pprof
        go func() {
            http.HandleFunc("/goroutines", func(w http.ResponseWriter, r *http.Request) {
                num := strconv.FormatInt(int64(runtime.NumGoroutine()), 10)
                w.Write([]byte(num))
            });
            http.ListenAndServe("localhost:6060", nil)
            glog.Info("goroutine stats and pprof listen on 6060")
        }()
    
    通过命令:

    curl localhost:6060/goroutines

    查询当前的goroutine的个数。通过不程序执行期间。不断查看。发现goroutine个数不断添加,没有销毁的迹象。

    (4)goroutine泄露

    通过上面的观察,发现存在goroutine泄露,即goroutine没有正常退出。因为每轮(每隔10秒执行一次)都会创建多个goroutine,假设不能正常退出,则会存在大量的goroutine。go的gc使用的是mark and sweep,会从全局变量、goroutine的栈为根集合扫描全部的存活对象。假设goroutine不退出,就会泄露大量内存。

    在确定是因为goroutine没有正常退出后,又一次review代码,发现了泄露的根本原因。在重构前。在信号处理程序中,为了正常结束程序,对于每一个goroutine都有一个channel,用于主goroutine等待全部goroutine正常结束后再退出。主goroutine中,信号处理程序用于等待全部goroutine的代码:

    waiters = make([]chan int, Num)
    for _, w := range waiters {
        <- w
    }

    执行检查逻辑的goroutine在结束后,会调用ag.w <- 1,用于向主goroutine发送消息。

    重构后,因为每轮都会创建goroutine,因为用于主goroutine和检查逻辑的goroutine之间的channel的大小是1,所以全部创建的检查goroutine都堵塞在ag.w <- 1上。不能正常退出。最后,把channel逻辑去掉。就不存在goroutine泄露了。

    (5)总结

    - goroutine的管理非常重要,假设goroutine泄露,就会存在内存泄露

    - 内嵌http server,用于查看程序执行状态

    - 眼下。go的gc还比較脆弱,尽量降低对象的创建。能缓存的就缓存。因为对象多了的话,扫描的时间也会加长

  • 相关阅读:
    Everybody's business is nobody's business
    Randy Pausch 卡内基梅隆大学毕业典礼上的演讲
    如何写好求职信
    NHibernate中DateTime,int,bool空值的处理方法
    数据库分页存储过程(2)
    数据库分页存储过程(7)
    数据库分页存储过程(3)
    数据库分页存储过程(4)
    给webform中的后置cs文件添加版权
    数据库分页存储过程(5)
  • 原文地址:https://www.cnblogs.com/lxjshuju/p/7142561.html
Copyright © 2011-2022 走看看