NodeJs内存占用过高的排查实战记录

2024-04-06 15:55:07

前言

一次线上容器扩容引发的排查，虽然最后查出并不是真正的 OOM 引起的，但还是总结记录一下其中的排查过程，整个过程像是破案，一步步寻找蛛丝马迹，一步步验证出结果。

做这件事的意义和必要性个人觉得有这么几个方面吧：

从程序员角度讲：追求代码极致，不放过问题，务必保证业务的稳定性这几个方面
从资源角度讲：就是为了降低无意义的资源开销
从公司角度讲：降低服务器成本，给公司省钱

环境：腾讯 Taf 平台上运行的 NodeJs 服务。

问题起因

最开始是因为一个定时功能上线后，线上的容器自动进行了扩容，由于 NodeJs 服务本身只有一些接口查询和 socket.io 的功能，一没大流量，二没高并发的一个服务居然需要扩容 8 个容器（一个容器分配的是 2G 的内存），想到这里怀疑是内存泄漏了。同时日志中偶发的看到内存不足。

扩容原因

问了运维同学查到是由于内存占用到临界值导致的扩容。

负载情况

首先排除一下是不是因为服务压力过大导致的内存占用升高，可能这是一种正常的业务现象。

通过监测，发现流量和 CPU 占用都不是很高，甚至可以说是很低，那么这么高的内存占用是属于不正常的现象的。

因为是内存原因导致的，而且有逐步持续上升的现象，所以就联想到了内存泄漏这个方向，常用的做法是打印「堆快照」即 heapsnapshot 文件。

进入容器：

go 节点名称

进入 NodeJs 项目的文件夹

/usr/local/app/taf/service_name/bin/src

生成快照：

const heapdump = require('heapdump');
heapdump.writeSnapshot('./' + new Date().getTime() + '.heapsnapshot', function(err, filename) {
    console.log('dump written to', filename);
});

受限于容器内使用 lrzsz 命令直接传输文件很慢，因此需要使用 scp 命令传输到一台静态资源服务器上，可以通过浏览器进行下载的。

scp 1620374489828.heapsnapshot username@ip:/data/static/snapshot

对比 heapsnapshot

在服务启动后，和运行一段时间后的生成两次快照内容，对比后的排序也只能大致看到 Websocket Socket 这些关键字。

进一步展开也无法定位到是否由某个函数引起的。

从快照里面似乎找不到什么线索，由于整个工程的业务量代码并不是很大，因此逐行 review 排查，但是似乎也没有什么异常的写法会引起 oom，其实业务代码小还好，如果是个大工程的话，这种做法没有性价比，还是需要通过一些诊断手段来排查，而不是直接去 codereview。

反复打印了几次快照，看了几遍后，还是看到 websocket 这些字眼，因而考虑到是否是因为 socket 链接未释放导致的问题呢？

Google 关键字搜了一下 WebSocket memory leak，还真有，解决方案是加上 perMessageDeflate ，禁用压缩。目前低版本的 socket-io 默认是开启的，于是我加了之后观察了一段时间的内存占用，并未有明显的下跌，发布后，内存占用依旧很高。

配置语法：

require('socket.io').listen(server, {perMessageDeflate: false});

客户端发送的请求中含有这个字段：

首先这个参数是用来压缩数据的，client 端默认是开启，server 端是关闭的，出于某些原因，开启后会导致内存和性能的消耗，官方建议是考虑后再决定是否开启。但是低版本的 socket-io 是开启的，比如 ^2.3.0 的版本（貌似是 bug，后续版本已经改为默认关闭）。

The extension is disabled by default on the server and enabled by default on the client. It adds a significant overhead in terms of performance and memory consumption so we suggest to enable it only if it is really needed.

https://github.com/socketio/socket.io/issues/3477#issuecomment-610265035

开启后，内存仍旧居高不下。

console.log

另外一个现象就是现有的 Node 服务会打印一些日志，翻了一些网上的 NodeJs 内存泄漏的文章，有看到 console 日志输出导致的泄漏的情况，因此注释掉 console 之后继续观察内存占用，结果仍旧是内存高占用。

线索到这里似乎就断掉了，没有头绪了。

日志

过了一天后，无意中看了一下日志文件，由于服务启动的时候会打印一些启动日志，发现有重复输出的情况：

说明有重复运行的情况，为了验证这一猜想，使用 top 命令查看。

TOP 命令

同时还想看一下具体的内存占用。发现居然有这么多的 worker process ，根据当前业务的实际使用情况不应该只有 2 ~ 4 个就够了么，为什么要开这么多的子进程。

PID USER      PR  NI  VIRT  RES  SHR S %CPU %MEM    TIME+  COMMAND
 90359 username       20   0  736m  38m  14m S  0.0  0.0   0:07.30 /usr/local/app/service_name/bin/src/index.js: worker process
 90346 username       20   0  864m  38m  14m S  0.3  0.0   0:07.08 /usr/local/app/service_name/bin/src/index.js: worker process
 90381 username       20   0  730m  38m  14m S  0.3  0.0   0:08.75 /usr/local/app/service_name/bin/src/index.js: worker process
 90366 username       20   0  804m  37m  14m S  0.0  0.0   0:06.94 /usr/local/app/service_name/bin/src/index.js: worker process
 90618 username       20   0  730m  37m  14m S  0.0  0.0   0:08.42 /usr/local/app/service_name/bin/src/index.js: worker process
 90326 username       20   0  736m  37m  14m S  0.0  0.0   0:08.46 /usr/local/app/service_name/bin/src/index.js: worker process
 90542 username       20   0  736m  37m  14m S  0.0  0.0   0:08.85 /usr/local/app/service_name/bin/src/index.js: worker process
 90332 username       20   0  799m  37m  14m S  0.0  0.0   0:07.32 /usr/local/app/service_name/bin/src/index.js: worker process
 90580 username       20   0  732m  37m  14m S  0.3  0.0   0:08.94 /usr/local/app/service_name/bin/src/index.js: worker process
 90602 username       20   0  731m  37m  14m S  0.3  0.0   0:08.33 /usr/local/app/service_name/bin/src/index.js: worker process
 90587 username       20   0  735m  37m  14m S  0.0  0.0   0:08.83 /usr/local/app/service_name/bin/src/index.js: worker process
 90568 username       20   0  731m  37m  14m S  0.0  0.0   0:08.83 /usr/local/app/service_name/bin/src/index.js: worker process
 90544 username       20   0  729m  37m  14m S  0.0  0.0   0:09.07 /usr/local/app/service_name/bin/src/index.js: worker process
 90556 username       20   0  729m  37m  14m S  0.0  0.0   0:08.82 /usr/local/app/service_name/bin/src/index.js: worker process
 90431 username       20   0  735m  37m  14m S  0.0  0.0   0:08.29 /usr/local/app/service_name/bin/src/index.js: worker process
 90486 username       20   0  729m  37m  14m S  0.0  0.0   0:09.06 /usr/local/app/service_name/bin/src/index.js: worker process
 90516 username       20   0  735m  37m  14m S  0.0  0.0   0:08.95 /usr/local/app/service_name/bin/src/index.js: worker process
 90465 username       20   0  729m  37m  14m S  0.0  0.0   0:09.06 /usr/local/app/service_name/bin/src/index.js: worker process
 90527 username       20   0  735m  37m  14m S  0.0  0.0   0:08.46 /usr/local/app/service_name/bin/src/index.js: worker process
 90487 username       20   0  732m  37m  14m S  0.3  0.0   0:08.48 /usr/local/app/service_name/bin/src/index.js: worker process
 90371 username       20   0  731m  37m  14m S  0.3  0.0   0:08.75 /usr/local/app/service_name/bin/src/index.js: worker process
 90423 username       20   0  729m  36m  14m S  0.3  0.0   0:08.09 /usr/local/app/service_name/bin/src/index.js: worker process
 90402 username       20   0  729m  36m  14m S  0.3  0.0   0:08.96 /usr/local/app/service_name/bin/src/index.js: worker process
 90500 username       20   0  729m  36m  14m S  0.0  0.0   0:08.70 /usr/local/app/service_name/bin/src/index.js: worker process
 90353 username       20   0  729m  36m  14m S  0.3  0.0   0:08.95 /usr/local/app/service_name/bin/src/index.js: worker process
 90636 username       20   0  729m  36m  14m S  0.0  0.0   0:08.84 /usr/local/app/service_name/bin/src/index.js: worker process
 90425 username       20   0  732m  36m  14m S  0.0  0.0   0:08.78 /usr/local/app/service_name/bin/src/index.js: worker process
 90506 username       20   0  729m  36m  14m S  0.0  0.0   0:08.84 /usr/local/app/service_name/bin/src/index.js: worker process
 90589 username       20   0  729m  36m  14m S  0.3  0.0   0:09.05 /usr/local/app/service_name/bin/src/index.js: worker process
 90595 username       20   0  729m  36m  14m S  0.0  0.0   0:09.03 /usr/local/app/service_name/bin/src/index.js: worker process
 90450 username       20   0  729m  36m  14m S  0.3  0.0   0:08.97 /usr/local/app/service_name/bin/src/index.js: worker process
 90531 username       20   0  729m  36m  14m S  0.0  0.0   0:08.99 /usr/local/app/service_name/bin/src/index.js: worker process
 90509 username       20   0  735m  36m  14m S  0.0  0.0   0:08.67 /usr/local/app/service_name/bin/src/index.js: worker process
 90612 username       20   0  730m  36m  14m S  0.3  0.0   0:08.84 /usr/local/app/service_name/bin/src/index.js: worker process
 90479 username       20   0  729m  36m  14m S  0.0  0.0   0:08.58 /usr/local/app/service_name/bin/src/index.js: worker process
 90609 username       20   0  731m  36m  14m S  0.3  0.0   0:09.23 /usr/local/app/service_name/bin/src/index.js: worker process
 90404 username       20   0  734m  36m  14m S  0.3  0.0   0:08.78 /usr/local/app/service_name/bin/src/index.js: worker process
 90395 username       20   0  736m  36m  14m S  0.0  0.0   0:08.57 /usr/local/app/service_name/bin/src/index.js: worker process
 90444 username       20   0  729m  36m  14m S  0.0  0.0   0:09.04 /usr/local/app/service_name/bin/src/index.js: worker process
 90438 username       20   0  729m  36m  14m S  0.3  0.0   0:07.78 /usr/local/app/service_name/bin/src/index.js: worker process
 90340 username       20   0  736m  36m  14m S  0.3  0.0   0:07.37 /usr/local/app/service_name/bin/src/index.js: worker process
 90333 username       20   0  729m  36m  14m S  0.0  0.0   0:07.60 /usr/local/app/service_name/bin/src/index.js: worker process
 90563 username       20   0  735m  36m  14m S  0.3  0.0   0:08.93 /usr/local/app/service_name/bin/src/index.js: worker process
 90565 username       20   0  734m  36m  14m S  0.3  0.0   0:08.77 /usr/local/app/service_name/bin/src/index.js: worker process
 90457 username       20   0  735m  36m  14m S  0.0  0.0   0:08.31 /usr/local/app/service_name/bin/src/index.js: worker process
 90387 username       20   0  740m  36m  14m S  0.0  0.0   0:07.59 /usr/local/app/service_name/bin/src/index.js: worker process
 90573 username       20   0  728m  35m  14m S  0.0  0.0   0:09.06 /usr/local/app/service_name/bin/src/index.js: worker process
 90472 username       20   0  728m  35m  14m S  0.0  0.0   0:08.94 /usr/local/app/service_name/bin/src/index.js: worker process
 90313 username       20   0  588m  27m  13m S  0.0  0.0   0:00.46 /usr/local/app/service_name/bin/src/index.js: master process

由于 %MEM 这一列的数值在容器内部看不出具体的内存占用，都是显示的 0.0，所以需要查看 VIRT, RES 和 SHR 这三个值，它们的含义可以在这里查看： https://www.orchome.com/298

我们更关心 RES，RES 的含义是指进程虚拟内存空间中已经映射到物理内存空间的那部分的大小，因此可以发现，一个 worker process 占用了 35 ~ 38M 之间的内存大小，一共有 48 个 worker process，一个 master process。

48 个 worker process 是怎么来的呢？通过查询 CPU 的逻辑个数，可以看到确实是 48 个。

# 总核数 = 物理CPU个数 X 每颗物理CPU的核数
# 总逻辑CPU数 = 物理CPU个数 X 每颗物理CPU的核数 X 超线程数

# 查看物理CPU个数
cat /proc/cpuinfo| grep "physical id"| sort| uniq| wc -l

# 查看每个物理CPU中core的个数(即核数)
cat /proc/cpuinfo| grep "cpu cores"| uniq

# 查看逻辑CPU的个数
cat /proc/cpuinfo| grep "processor"| wc -l

控制进程数

由于对 Taf 平台不是很熟悉，了解到在 taf 上面运行 NodeJS 需要对应的 package： @tars/node-agent ，查了一下官网的使用文档： https://tarscloud.github.io/TarsDocs/dev/tars.js/tars-node-agent.html

有一个 -i 的配置，代表 instances

-i, –instances

node-agent 采用 Node.js 原生的 Cluster模块来实现负载均衡。

可在此配置 node-agent 启动的子进程（业务进程）数量：

未配置（或配置为 auto 、 0 ），启动的子进程数量等于 CPU 物理核心个数。

配置为 max ，启动的子进程数量等于 CPU 个数（所有核心数）。

如果 node-agent 是由 tarsnode 启动的，会自动读取TARS配置文件中的 tars.application.client.asyncthread 配置节。

也可通过 TARS平台 -> 编辑服务 -> 异步线程数进行调整。

https://tarscloud.github.io/TarsDocs/dev/tars.js/tars-node-agent.html
通过这个 package 启动 Taf 上的 NodeJs 服务，同时开启负载均衡的能力，由于没有配置具体的子进程（业务进程）数量，所以默认就是用了 CPU 物理核心个数，因为是 2 个 cpu 所以再 *2，一共生成了 48 个 ‍♂️，每个 worker process 都要占用内存，所以内存占用一直居高不下。

可以在「私有模板」里修改配置：

然后重启服务，查看内存占用：

可见 worker process 数量影响了内存占用，原先内存使用率的趋势图上会持续增长（刚开始也是因此怀疑内存泄漏），这个问题在降低了 worker process 后并没有体现出来，目前暂且忽略，后续会持续观察。

为了验证重复 console 和 worker process 的关系，在开启 2 个 worker process 的情况下，查看日志，确实是打印了 2 次。

总结

复盘一下这次的问题：

为什么没有及时发现？

可能和前端开发者的角色有一定关系，对于后端服务的一些特性不太敏感。也没有花精力去关注，或者说不知道，不了解。

是否可以提前避免？

可以有类似的告警机制提示 Node 服务的内存在上升趋势，获取我还没有熟悉透 Taf 平台的功能，后期摸索一下。

到此这篇关于NodeJs内存占用过高的排查的文章就介绍到这了,更多相关NodeJs内存占用过高内容请搜索我们以前的文章或继续浏览下面的相关文章希望大家以后多多支持我们！

详解Nodejs内存治理

s运行的宿主环境不同,相应的对内存治理的要求也不一样,当宿主环境是浏览器时,由于网页的运行时间短,且只运行在用户的机器上(相当于分布式),即使内存使用过多或者存在一定的内存泄漏,也并不会对终端用户产生太大的影响.当宿主环境编程服务器(Node)时,情况就大不相同了,本身代码运行在固定的几台机器(集中式)上,而且运行的时间是长时间运行,一旦内存治理不好出现了内存膨胀甚至是内存泄漏的情况的话,就会出现服务器端响应时间变长甚至是服务crash的情况. Nodejs是基于V8构建的,所以在Node中使用
nodeJs内存泄漏问题详解

之前一次偶然机会发现,react 在server渲染时,当NODE_ENV != production时,会导致内存泄漏.具体issues: https://github.com/facebook/react/issues/7406 .随着node,react同构等技术地广泛运用,node端内存泄漏等问题应该引起我们的重视.为什么node容易出现内存泄漏以及出现之后应该如何排查,下面通过一个简单的介绍以及例子来说明. 首先,node是基于v8引擎基础上,其内存管理方式与v8一致.下面简单介绍v8
如何用Node.js编写内存效率高的应用程序

前言软件应用程序在计算机的主存储器中运行,我们称之为随机存取存储器(RAM).JavaScript,尤其是 Nodejs(服务端js)允许我们为终端用户编写从小型到大型的软件项目.处理程序的内存总是一个棘手的问题,因为糟糕的实现可能会阻塞在给定服务器或系统上运行的所有其他应用程序.C 和 C++程序员确实关心内存管理,因为隐藏在代码的每个角落都有可能出现可怕的内存泄漏.但是对于 JS 开发者来说,你真的有关心过这个问题吗? 由于 JS 开发人员通常在专用的高容量服务器上进行 web 服务器编程
浅析Node.js中的内存泄漏问题

这篇文章是由Mozilla的Identity团队带来的 A Node.JS Holiday Season系列文章的首篇,该团队上个月发布了 Persona的第一个测试版本.在开发Persona时我们构建了一系列的工具,包括了从调试,到本地化,到依赖管理以及更多的方面.在这一系列的文章中我们将与社区分享我们的经验和这些工具,这对任何想用node.js建立一个高可用性服务的人都很有用.我们希望您能喜欢这些文章,并期待看到您的想法和贡献. 我们将从一篇关于Node.js的实质性问题:内存泄漏的主题文章
NodeJs内存占用过高的排查实战记录

前言一次线上容器扩容引发的排查,虽然最后查出并不是真正的 OOM 引起的,但还是总结记录一下其中的排查过程,整个过程像是破案,一步步寻找蛛丝马迹,一步步验证出结果. 做这件事的意义和必要性个人觉得有这么几个方面吧: 从程序员角度讲:追求代码极致,不放过问题,务必保证业务的稳定性这几个方面从资源角度讲:就是为了降低无意义的资源开销从公司角度讲:降低服务器成本,给公司省钱环境:腾讯 Taf 平台上运行的 NodeJs 服务. 问题起因最开始是因为一个定时功能上线后,线上的容器自动进行了扩容
Mysql5.6启动内存占用过高解决方案

vps的内存为512M,安装好nginx,php等启动起来,mysql死活启动不起来看了日志只看到对应pid被结束了,后跟踪看发现是内存不足被killed; 调整my.cnf 参数,重新配置(系统默认配置太高直接占用400M内存,小玩家玩不起呢)即可 performance_schema_max_table_instances=200 table_definition_cache=200 table_open_cache=128 下面附一个相关的my.cnf配置文件的说明 [client] po
w3wp.exe内存占用过高(网站打不开,应用程序池回收就正常)

服务器cpu,内存正常, 部分网站打不开,应用程序池回收就正常,如何解决? 提问: 服务器\IIS和ASP问题请问下各位``网站最近每天要出现几次打不开很慢`只显示tile标题其它无,站点是ASP的,前台生成的html,今天看到的W3WP.exe占用最高达280M,一般都只有170M左右IIS管理里地址池回收一下就正常`是什么原因? 补充:服务器CPU占用极少`只有百分几点物理内存6G 内存占用量也极少.PS:主要问题就是这个程序池.网站出现慢或打不开,一回收就正常. WEB服务器高手--们在哪
Pytorch GPU内存占用很高,但是利用率很低如何解决

1.GPU 占用率,利用率输入nvidia-smi来观察显卡的GPU内存占用率(Memory-Usage),显卡的GPU利用率(GPU-util) GPU内存占用率(Memory-Usage) 往往是由于模型的大小以及batch size的大小,来影响这个指标显卡的GPU利用率(GPU-util) 往往跟代码有关,有更多的io运算,cpu运算就会导致利用率变低. 比如打印loss, 输出图像,等等这个时候发现,有一块卡的利用率经常跳到1%,而其他三块卡经常维持在70%以上 2.原因分析当
一次Docker中Redis连接暴增的问题排查实战记录

周六生产服务器出现redis服务器不可用状态,错误信息为: 状态不可用,等待后台检查程序恢复方可使用.Unexpected end of stream; expected type 'Status' 如下图所示,下图6300就是我们redis服务器运行的端口. 头一次碰到此类问题,心想难道是redis挂掉了,随即通过telnet ip+端口.发现运行正常,然后就想着进入redis看下目前连接情况.一看发现竟然高达1903条这么多. 然后想着应该是代码创建redis连接过多导致的,查看代码. 发现
java实战CPU占用过高问题的排查及解决

最近一段时间某台服务器上的一个应用总是隔一段时间就自己挂掉用top看了看从重新部署应用开始没有多长时间CPU占用上升得很快排查步骤 1.使用top 定位到占用CPU高的进程PID top 2.通过ps aux | grep PID命令获取线程信息,并找到占用CPU高的线程 ps -mp pid -o THREAD,tid,time | sort -rn 3.将需要的线程ID转换为16进制格式 printf "%x\n" tid 4.打印线程的堆栈信息到了这一步具体看堆栈的日
一次NodeJS内存泄漏排查的实战记录

目录前言案例一故障现象排查过程案例二故障现象排查过程问题原因 node-v9.x 以下的版本 node-v10.x 以上的版本修复泄露总结前言性能问题(内存.CPU 飙升导致服务重启.异常)排查一直是 Node.js 服务端开发的难点,去年在经过调研后,在我们项目的 Node.js 服务上都接入了 Easy-Monitor 来帮助排查生产环境遇到的性能问题.前段时间遇到了两例内存泄漏的案例,在这里做一个排查经过的整理. 案例一故障现象线上的某个服务发生了重启,经过观察
记一次tomcat进程cpu占用过高的问题排查记录

本文主要记录一次tomcat进程,因TCP连接过多导致CPU占用过高的问题排查记录. 问题描述 linux系统下,一个tomcat web服务的cpu占用率非常高,top显示结果超过200%.请求无法响应.反复重启依然同一个现象. 问题排查 1.获取进程信息通过jdk提供的jps命令可以快速查出jvm进程, jps pid 2.查看jstack信息 jstack pid 发现存在大量log4j线程block,处于waiting lock状态 org.apache.log4j.Category.
arthas排查jvm中CPU占用过高问题解决

目录安装小试找出CPU的元凶查看线程栈的参数安装小试记一次使用arthas排查jvm中CPU占用过高问题.这工具屌爆了碾压我目前使用的全部JVM工具. curl -O https://arthas.aliyun.com/arthas-boot.jar java -jar arthas-boot.jar --repo-mirror aliyun --use-http jar后面的参数也可以不加加上只是为了下载速度更快接下来arthas 控制台中显示了当前机器上jvm进程列表输
w3wp.exe占用CPU和内存问题过高的解决方法

今天研究了一下,可以做以下配置: 1.在IIS中对每个网站进行单独的应用程序池配置.即互相之间不影响. 2.设置应用程序池的回收时间,默认为1720小时,可以根据情况修改.同时,设置同时运行的w3wp进程数目为1.再设置当内存或者cpu占用超过多少,就自动回收内存一般来说,这样就可以解决了.但仍然会出现个别网站因为程序问题,不能正确释放. 那么,怎么样才能找到是哪一个网站的? 1.在任务管理器中增加显示pid字段.就可以看到占用内存或者cpu最高的进程pid 2.在命令提示符下运行iisapp

NodeJs内存占用过高的排查实战记录

前言

问题起因

对比 heapsnapshot

总结

相关推荐

随机推荐