• Go程序(Grpc服务)协程数暴涨的原因排查分析


    目录

    背景

    完整排查过程

    解决及验证


    因实际生产过程中涉及流程较多,排查起来需层层排除,步步为营,最终实现找到罪魁祸首。但当你真真正正解决了问题时,你的心情是放松的、愉悦的!

    背景

    有两个程序A和B,A会和B建立grpc连接,A端通过封装来管控建立的所有连接, 正常情况下A和B均一直启动着。

    其中与B程序一样的还有几个在其它机器上,也就是A和C、D等都可能会建立连接。

    当意识到发生协程泄漏时,百感交集,这又是一个考验干部的机会,机不可失!

    完整排查过程

    程序运行过程中,发现协程数一直在上涨,一开始只有五十个左右,随着时间变化经过了几个小时后,一度涨到1900左右,同时A的常驻内存也在持续上涨。

    此时分析出现的日志,发现后台在不断的建立连接和断联操作,每次两个操作之间间隔了大概几十秒的样子。

    分析图如下(此时协程数为1878):

    c40ab22dafd34049a192432c02327917.png

    可以看出不存在其它代码的协程泄漏,发现goroutine占的较多的是grpc相关的第三方包,大协程数均出现在了grpc这块(这句话你看到后是不是有了些想法?) grpc本身也是构建在HTTP/2之上的。

    查询当前top20,结合此图,我们能看到这几样子关键调用(取重要部分,copy时顺序已乱):

    internal/poll.runtime_pollWait
    internal/poll.(*pollDesc).waitRead (inline)
    internal/poll.(*pollDesc).wait
    internal/poll.(*FD).Read

    google.golang.org/grpc.(*addrConn).resetTransport
    google.golang.org/grpc.(*ccBalancerWrapper).watcher
    google.golang.org/grpc/internal/transport.(*controlBuffer).get
    google.golang.org/grpc/internal/transport.(*loopyWriter).run
    google.golang.org/grpc/internal/transport.newHTTP2Client.func3
    google.golang.org/grpc/internal/transport.(*http2Client).reader

    看看源码中涉及transport及resetTransport的地方:

    399dbe9c08964917890571dd2e623cff.png

    而resetTransport里最后进行了阻塞,直到resetTransport为down才会解除阻塞,也就是说对应的goroutine一直得不到释放,此处已发生泄漏

    92ad5ab79fe74cdc94e39c9345687395.png

    由pprof图得知resetTransport那里堆积了376个goroutine,不就是这里么。

    简单说下为什么一直在建联和断连

    这和逻辑有关。排查已在维护的客户端时会进行遍历,一旦发现某些客户端不合法、连接为空等情况时会主动做断连操作,而一直在反反复复进行这两个操作就不对劲了,后来排查发现是代码问题,在初始化每个连接时一切都是成功的,但在注册到维护的map时没有赋值(疏漏),因此实际上每次检测连接时就会将其断掉(调用自己封装客户端的close方法)。

    而断掉的逻辑是怎样的呢?

    判断每个客户端对应的grpc连接,如果连接不为空则进行close()并删掉维护的相关记录,为空当然直接清除记录即可就不需要conn.close,基于上面的情况,赋值就没有赋上,因此close的时候当然每次conn都是空的了,可怕的是这时候它的连接实际上还正常着,也就是说经过close后没有成功的close掉、连接还在…

    这样一直往复,就导致和目标服务建立了很多个grpc连接却想关闭而没有实际关闭,一直建联、一直上涨。

    再来验证一下分析的结果:

    在目标机器上netstat当前建立的tcp连接,发现从A连到B的连接大量堆积,都是ESTABLISHED状态的连接。

    正常情况下,A到B理论上只会有一个正常的连接,这一看就不对,这样下去fd、内存就耗完了!

    这下不就清楚了?那我们再来通过外围连接层面试试,将B直接停掉,看看A的协程数是不是大幅降低?(此时在B上检查, 和A建立的tcp连接达300多个,A协程数此时为1947)

    经过试验,直接降低57%左右,从1947 降到 835

    (为什么不是直接降低到接近正常的数量,一是因为同时还有其它到A的连接,二是外部断联后,部分受grpc管控的,猜测像

    controlbuffer, balancewapper,   loopyWriter 以及socket相关的pollwait等相关routine或流程并没有停止或立即停止所致,最后修复后多次重复相关操作,并未出现上述几个关键模块的泄露现象,后者需深究源码及相关流程)

    观察几个小时后,协程数一直维持在830左右,不再上涨,这也就印证了排除此部分的问题外,其它部分不存在goroutine泄漏, 此时只需要解决此问题即可。

    解决及验证

    根据分析的情况重新修改代码,正确赋值、确保每次正常关闭,再次重启并试验整个过程,结果正常,无异常上涨!

    多次重复相关过程,得到的分析图如下:

    9e769a84673a443a9f20f5c9cbcb26d4.png

    可以看到很清爽,持续观察没有冗余不断暴涨的现象。

    因时间紧迫,这次也以解决问题为主要目的,花了一些时间层层排查到了这里,找到原因可以松一口气了!

  • 相关阅读:
    使用北鲲云在AWS上运行基因分析HPC任务
    2023最新版JavaSE教程——第2天:变量与运算符
    基于SpringBoot的健身房管理系统
    导入导出并将excel表格数据展示
    【postgresql】CentOS7 安装Pgweb
    css自学框架之图片懒加载
    Momentum Safe 启动大使计划,大家积极参与进来,让我们的社区越来越壮大
    Elastic Agent 的安装及使用
    Vcenter6.5扩容存储后无法创建虚机处理方法
    Redis布隆过滤器
  • 原文地址:https://blog.csdn.net/HYZX_9987/article/details/126650314