V2EX = way to explore
V2EX 是一个关于分享和探索的地方
现在注册
已注册用户请  登录
des
V2EX  ›  Node.js

求助, nodeJs 进程无响应了,应该怎么查

  •  
  •   des · 2022-08-07 20:15:44 +08:00 · 4419 次点击
    这是一个创建于 874 天前的主题,其中的信息可能已经有所发展或是发生改变。

    最近在对服务做测试,然后就发现 websocket 连接保持不动的话,过一阵 node 进程就无响应了
    表现就是请求端口无响应,LISTEN 的 Recv-Q 不掉
    然后在代码里面加入的 setInterval 然后打印也突然不输出了,看样子像是事件循环卡住了

    [root /]# ss -ltn
    State      Recv-Q Send-Q        Local Address:Port          Peer Address:Port 
    LISTEN     261    511                      :::4000                    :::* 
    

    保持的连接数也不多,才 8 千。也不怎么发送数据,也就半分钟发一条一个字符的 webscoket 数据
    连接断开之后,程序也是不继续走,然后就是一堆的 CLOSE_WAIT

    内存和 CPU 看上去也没啥异样
    最最奇葩的一点是,一旦我使用 pstack 或者 strace ,或者用 kill ,进程就恢复正常了
    这是堆栈信息: https://pastebin.com/VJ4ekuQR

    Maximum number of open file descriptors 、nr_open 之类的也看过了,都是 6 万多

    23 条回复    2022-10-29 19:34:51 +08:00
    des
        1
    des  
    OP
       2022-08-07 20:36:45 +08:00
    补充一下,测试机和服务器中间是有 ALB 的,走的公网连接,ALB 有定时使用 HEAD 根目录检测存活机制,不知道有没有影响
    客户端定时发送的数据也是一直有日志的,服务端能收到,直到服务出问题就没了
    从开始连接到服务出问题,出问题的时长基本都在 15 分钟到 30 分钟
    unhandledRejection 和 uncaughtException 全程也没有任何东西

    NodeJs 的版本是 v16.12.0 ,在 https://nodejs.org/dist/下载的
    bigfei
        2
    bigfei  
       2022-08-07 21:06:07 +08:00
    des
        3
    des  
    OP
       2022-08-07 21:11:28 +08:00
    @bigfei
    我一开始也以为是 CLOSE_WAIT 的问题,现在看来 CLOSE_WAIT 只是结果
    在我测试机断开连接之前,服务器上是没有 CLOSE_WAIT 状态的连接的,服务更像是“卡住了”,就连 setInterval 都没有执行
    des
        4
    des  
    OP
       2022-08-07 22:06:49 +08:00
    刚刚把主要的业务代码去掉了,测试依旧出问题
    感觉不像是代码有问题,更像是系统配置不太对或者 NodeJs 的 BUG
    后面我再简化下放一下代码
    qrobot
        5
    qrobot  
       2022-08-08 10:17:28 +08:00
    @des
    epoll 性能应该没这么差, 我看堆栈信息上显示好像是大量的占用了 Queue, 具体为什么大量占用 Queue 就要看代码了
    des
        6
    des  
    OP
       2022-08-08 12:10:00 +08:00 via iPhone
    @qrobot 应该不是,你说的这种情况现象应该会表现为 cpu 占满,我这边没有观察到这个现象,并且一旦我使用 pstack 或者 strace ,就能恢复正常,也不支持你这个观点
    qrobot
        7
    qrobot  
       2022-08-08 13:23:41 +08:00
    @des Queue 不一定会 cpu 占满, 我看到这边堆栈信息好像有大量的 Queue , 我有很有理由怀疑是这块。epoll 的响应很快的.
    qrobot
        8
    qrobot  
       2022-08-08 13:25:56 +08:00
    错误的代码导致大量占用 Queue 造成 Event loop 等待, 这是 NodeJS 中新手很容易犯的错误。
    qrobot
        9
    qrobot  
       2022-08-08 13:27:33 +08:00
    Event loop 等待并不表示 CPU 会占满。 但是 CPU 占满 Event loop 一定会等待
    qrobot
        10
    qrobot  
       2022-08-08 13:30:20 +08:00
    你可以放个测试用例和最小的可复现的仓库, 我可以帮你分析下
    lsp7572
        11
    lsp7572  
       2022-08-08 14:39:20 +08:00
    nodejs 可以 pstack 看调用栈吗。
    des
        12
    des  
    OP
       2022-08-08 18:07:13 +08:00 via iPhone
    @qrobot 目前重现的条件还不是特别清楚,所以还不好弄
    des
        13
    des  
    OP
       2022-08-09 13:32:13 +08:00
    @qrobot
    感谢回复,根据你的提醒我去查了一下 gc 日志,看起来好像真的有问题
    “525695.2 / 0.0 ms”这条是卡住了之后,我执行 pstack 才有的
    https://pastebin.com/0anu1851



    另外换了几个版本 12 、14 、16 ,都有问题应该可以初步排除 NodeJs 的 bug
    qrobot
        14
    qrobot  
       2022-08-10 09:47:43 +08:00
    @des 这个问题非常好查, 看一下代码就好了。nodejs Queue 导致的情况无非就几种情况
    humbass
        15
    humbass  
       2022-08-10 19:05:06 +08:00
    websocket 是好用,主要还是防止内部队列拥挤,以前经常碰到这个问题;
    改用队列来处理后,这些毛病很容易被发现。
    des
        16
    des  
    OP
       2022-08-14 21:23:24 +08:00
    @bigfei @qrobot @lsp7572 @humbass
    问题复现了,应该是 glibc 的 bug ,复现代码在这里:
    https://pastebin.com/VDi2Vtc4
    des
        17
    des  
    OP
       2022-08-14 21:23:50 +08:00
    @des glibc 版本是 2.17
    Holymomoo
        18
    Holymomoo  
       2022-10-03 22:22:04 +08:00
    lz 后来确定是这么底层的问题吗?怎么解决的
    des
        19
    des  
    OP
       2022-10-03 22:31:33 +08:00 via iPhone
    @Holymomoo 可以自行看一下更新记录,是 fork 造成的死锁问题
    des
        20
    des  
    OP
       2022-10-03 22:36:59 +08:00 via iPhone
    @Holymomoo 可以看到出问题时候的现象和堆栈一模一样。后来是用 preload 解决的,其实用 docker 也行


    和很多人想的不一样,底层也会出现很多 bug 的,如果做过底层就知道,当然这话不是我说的
    yijiecaoming
        21
    yijiecaoming  
       2022-10-29 19:25:16 +08:00
    @qrobot 大佬,我碰到这样一种情况
    yijiecaoming
        22
    yijiecaoming  
       2022-10-29 19:26:56 +08:00
    @qrobot 大佬,我碰到这样一种情况

    cpu 100%,机器大量 CLOSE_WAIT

    应该从哪块排查
    des
        23
    des  
    OP
       2022-10-29 19:34:51 +08:00 via iPhone
    @yijiecaoming CPU100%,那就从 CPU 查起呗,看看 CPU 在干嘛
    关于   ·   帮助文档   ·   博客   ·   API   ·   FAQ   ·   实用小工具   ·   2486 人在线   最高记录 6679   ·     Select Language
    创意工作者们的社区
    World is powered by solitude
    VERSION: 3.9.8.5 · 21ms · UTC 04:10 · PVG 12:10 · LAX 20:10 · JFK 23:10
    Developed with CodeLauncher
    ♥ Do have faith in what you're doing.