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

2022-08-07 20:15:44 +08:00
 des

最近在对服务做测试,然后就发现 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 万多

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

NodeJs 的版本是 v16.12.0 ,在 https://nodejs.org/dist/下载的
bigfei
2022-08-07 21:06:07 +08:00
des
2022-08-07 21:11:28 +08:00
@bigfei
我一开始也以为是 CLOSE_WAIT 的问题,现在看来 CLOSE_WAIT 只是结果
在我测试机断开连接之前,服务器上是没有 CLOSE_WAIT 状态的连接的,服务更像是“卡住了”,就连 setInterval 都没有执行
des
2022-08-07 22:06:49 +08:00
刚刚把主要的业务代码去掉了,测试依旧出问题
感觉不像是代码有问题,更像是系统配置不太对或者 NodeJs 的 BUG
后面我再简化下放一下代码
qrobot
2022-08-08 10:17:28 +08:00
@des
epoll 性能应该没这么差, 我看堆栈信息上显示好像是大量的占用了 Queue, 具体为什么大量占用 Queue 就要看代码了
des
2022-08-08 12:10:00 +08:00
@qrobot 应该不是,你说的这种情况现象应该会表现为 cpu 占满,我这边没有观察到这个现象,并且一旦我使用 pstack 或者 strace ,就能恢复正常,也不支持你这个观点
qrobot
2022-08-08 13:23:41 +08:00
@des Queue 不一定会 cpu 占满, 我看到这边堆栈信息好像有大量的 Queue , 我有很有理由怀疑是这块。epoll 的响应很快的.
qrobot
2022-08-08 13:25:56 +08:00
错误的代码导致大量占用 Queue 造成 Event loop 等待, 这是 NodeJS 中新手很容易犯的错误。
qrobot
2022-08-08 13:27:33 +08:00
Event loop 等待并不表示 CPU 会占满。 但是 CPU 占满 Event loop 一定会等待
qrobot
2022-08-08 13:30:20 +08:00
你可以放个测试用例和最小的可复现的仓库, 我可以帮你分析下
lsp7572
2022-08-08 14:39:20 +08:00
nodejs 可以 pstack 看调用栈吗。
des
2022-08-08 18:07:13 +08:00
@qrobot 目前重现的条件还不是特别清楚,所以还不好弄
des
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
2022-08-10 09:47:43 +08:00
@des 这个问题非常好查, 看一下代码就好了。nodejs Queue 导致的情况无非就几种情况
humbass
2022-08-10 19:05:06 +08:00
websocket 是好用,主要还是防止内部队列拥挤,以前经常碰到这个问题;
改用队列来处理后,这些毛病很容易被发现。
des
2022-08-14 21:23:24 +08:00
@bigfei @qrobot @lsp7572 @humbass
问题复现了,应该是 glibc 的 bug ,复现代码在这里:
https://pastebin.com/VDi2Vtc4
des
2022-08-14 21:23:50 +08:00
@des glibc 版本是 2.17
Holymomoo
2022-10-03 22:22:04 +08:00
lz 后来确定是这么底层的问题吗?怎么解决的
des
2022-10-03 22:31:33 +08:00
@Holymomoo 可以自行看一下更新记录,是 fork 造成的死锁问题
des
2022-10-03 22:36:59 +08:00
@Holymomoo 可以看到出问题时候的现象和堆栈一模一样。后来是用 preload 解决的,其实用 docker 也行


和很多人想的不一样,底层也会出现很多 bug 的,如果做过底层就知道,当然这话不是我说的

这是一个专为移动设备优化的页面(即为了让你能够在 Google 搜索结果里秒开这个页面),如果你希望参与 V2EX 社区的讨论,你可以继续到 V2EX 上打开本讨论主题的完整版本。

https://www.v2ex.com/t/871277

V2EX 是创意工作者们的社区,是一个分享自己正在做的有趣事物、交流想法,可以遇见新朋友甚至新机会的地方。

V2EX is a community of developers, designers and creative people.

© 2021 V2EX