思考一下node在服务上的代码调试和性能调优

前言

在服务器上调试node,是一件救火行为,因为,如果是本地开发,通过IDE提供的调试平台我们可以进行一步一步的调试,在远程服务器上调试,会中断服务进程,造成其他错误,推荐利用单元测试工具和做好合理的日志进程调试,万不得已,后院着火了,再使用服务器上的调试方法。

Debugger

V8提供了标准的调试API,这个工具在node中是通过在语句中添加debugger的形式进行的,同时,启动的时候也需要带上debug参数才可以实现。详见下方

node debug xxx.js
x = 5;
setTimeout(function () {
debugger;
console.log("world");
}, 1000);
console.log("hello");

$ node debug examples/B/myscript.js
< debugger listening on port 5858
connecting... ok
break in examples/B/myscript.js:2
1 // myscript.js
2 x = 5;
3 setTimeout(function () {
4 debugger;
debug>

代码中遇到debugger;后会中断,可以通过以下的命令进行debug。

命令 说明
cont 或者c,继续执行
next 或者n,执行到下一个断点
step 或者s,步进到函数内部
out 或者o,从函数内部跳出
pause 暂停执行
setBreakpoint() 或者sb(),在当前行设置断点
setBreakpoint(lineNo) 或者sb(lineNo),在指定行设置断点
setBreakpoint('fn()') 或者sb('fn()'),在函数体的第一个声明处设置断点
setBreakpoint('xxx.js') 或者sb('xxx.js'),在脚本文件的第一行设置断点
clearBreakpoint 或者cb(),清除断点
backtrace 或者bt,打印当前执行情况下的堆栈信息
list(5) 列出当前上下文前后5行的源代码
watch(expr) 添加表达式到观察者列表,进行观察
unwatch(expr) 从观察列表中移除对表达式的观察
watchers 列出所有观察的表达式和值
repl 打开调试的交互,用于执行调试脚本的上下文

对于已经启动的程序如何debug

通过向程序发送SIGUSR1信号开启调试,kill -s USR1 10093,可以在浏览器上开启调试,使用工具Node Inspector。

安装:npm install -g node-inspector

启动的时候,直接node-inspector即可.....

当然,使用node Inspector必须先启用node进程的调试模式,也就是使用debug或者发送SIGUSR1给node进程来启用调试模式,启动进程后,调用Inspector工具,工具就与node进程建立了调试代理:

$ node-inspector
Node Inspector v0.5.0
info - socket.io started
Visit http://127.0.0.1:8080/debug?port=5858 to start debugging

剩下的就跟在IDE中调试代码一样了。

node调试的原理

在打开调试的时候,我们会看到这样的输出:

Debugger listening on port 5858

可以访问下 http://localhost:5858

看到如下信息:

Type:connect
V8-Version:4.2.15.19
Protocol-Version:1
Embedding-Host:node v4.2.15
Content-Length:0

这个其实就是node调用呢内建调试功能,并监听端口5858来使用调试命令。我们还可以使用

node debug <URI>
node debug -p <pid>

来调用

如果我们使用 --debug 参数打开文件:
.

node --debug xxxx.js

此时,nodejs 不会进入到命令行模式,而是直接执行代码,但是依然会开启内建调试功能,这就意味着我们具备了远程调试 NodeJS 代码的能力,使用 --debug 参数打开服务器的 nodejs 文件,然后通过:

node debug <服务器IP>:<调试端口,默认5858>

可以在本地远程调试 nodejs 代码。不过这里需要区分下 --debug 和 --debug-brk,前者会执行完所有的代码,一般是在监听事件的时候使用,而后者,不会执行代码,需要等到外部调试接入后,进入代码区。语言表述不会那么生动,读者可以自行测试下。

默认端口号是 5858,如果这个端口被占用,程序会递增端口号,我们也可以指定端口:

node  node --debug-brk=8787 xxxx.js
Debugger listening on port 8787

不过在最新的node中,调试的原理以及有所改变:

调试

可以看到直接推荐使用Inspector了,因此,大家也就不必太过于在乎调试了,还是那句话:服务器上的debug比较麻烦,还是通过良好的单元测试服务器日志进行错误排查。

性能调试

我们可以使用pm2这样的检测工具来检测node,现在我们想先分享一下产生问题的原因。或者说是什么问题造成了cpu或内存达到瓶颈,从而导致系统奔溃的呢?在菜谱负载过高,内存突然飙升的时候又如何发现这些问题呢?

分析原因

cpu负载过重的原因

1.垃圾回收频率过高、量过大,也给也是因为内存飙升造成的后遗症
2.计算密集型的长循环,比如遍历大量的文件、文件夹、大量的计算等

内存飙升的原因

1.缓存,很多人把内存当缓存用,比如session存在内存中
2.闭包,作用域没有被及时释放,造成常驻内存占用过多
3.生成者的生产能力和消费者的消费能力不匹配,例如数据库已经忙不过来了,但是Query队列中还有大量请求堆积。

解决手段

一般情况下,我们可以通过分析GC日志来查找问题:

问题 解释
内存飙升 特别是old space内存的飙升,会直接导致GC的次数和时间增长
缓存增加 导致GC的时间增加,无用遍历过多(如果缓存增加(比如使用对象缓存了很多用户信息),GC 是不知道这些缓存死了还是活着的,他们会不停地查看这个对象,以及这个对象中的子对象是否还存活,如果这个对象数特别大,那么 GC 遍历的时间也会特别长。当我们进行密集型计算的时候,会产生很多中间变量,这些变量往往在 New Space 中就死掉了,那么 GC 也会在这里多次地进行 New Space 区域的垃圾回收。
密集型计算 导致GC new space次数增加。(也就是前边说过的scavenage操作的cheney算法)

分析GC日志

在启动程序的时候添加 --trace_gc 参数,V8 在进行垃圾回收的时候,会将垃圾回收的信息打印出来:

node --trace_gc aa.js
...
[94036]       68 ms: Scavenge 8.4 (42.5) -> 8.2 (43.5) MB, 2.4 ms [allocation failure].
[94036]       74 ms: Scavenge 8.9 (43.5) -> 8.9 (46.5) MB, 5.1 ms [allocation failure].
[94036] Increasing marking speed to 3 due to high promotion rate
[94036]       85 ms: Scavenge 16.1 (46.5) -> 15.7 (47.5) MB, 3.8 ms (+ 5.0 ms in 106 steps since last GC) [allocation failure].
[94036]       95 ms: Scavenge 16.7 (47.5) -> 16.6 (54.5) MB, 7.2 ms (+ 1.3 ms in 14 steps since last GC) [allocation failure].
[94036]      111 ms: Mark-sweep 23.6 (54.5) -> 23.2 (54.5) MB, 6.2 ms (+ 15.3 ms in 222 steps since start of marking, biggest step 0.3 ms) [GC interrupt] [GC in old space requested].
...

V8还提供了很多启动选项:

启动项 含义
–max-stack-size 设置栈大小
–v8-options 打印 V8 相关命令
–trace-bailout 查找不能被优化的函数,重写
–trace-deopt 查找不能优化的函数

这些启动项都可以让我们查看 V8 在执行时的各种 log 日志,对于排查隐晦问题比较有用

另外,通过 Profile 可以找到具体函数在整个程序中的执行时间和执行时间占比,从而分析到具体的代码问题,V8 也提供了 Profile 日志导出:

$ node --prof test.js
//执行命令之后,会在该目录下产生一个 *-v8.log 的日志文件,我们可以安装一个日志分析工具 tick:
npm install tick -g
node-tick-processor *-v8.log
[Top down (heavy) profile]:
  Note: callees occupying less than 0.1% are not shown.

  inclusive      self           name
  ticks   total  ticks   total
    426   36.7%      0    0.0%  Function: ~<anonymous> node.js:27:10
    426   36.7%      0    0.0%    LazyCompile: ~startup node.js:30:19
    410   35.3%      0    0.0%      LazyCompile: ~Module.runMain module.js:499:26
    409   35.2%      0    0.0%        LazyCompile: Module._load module.js:273:24
    407   35.1%      0    0.0%          LazyCompile: ~Module.load module.js:345:33
    406   35.0%      0    0.0%            LazyCompile: ~Module._extensions..js module.js:476:37
    405   34.9%      0    0.0%              LazyCompile: ~Module._compile module.js:378:37
...

解决问题

对于内存当做缓存的,我们可以引入外部缓存如redis等,对于闭包,我们可以人为控制闭包的释放,对于大文件,我们可以将其分解为小文件迭代的去读取,总之,方法多多,大家可以继续探讨

©著作权归作者所有,转载或内容合作请联系作者
  • 序言:七十年代末,一起剥皮案震惊了整个滨河市,随后出现的几起案子,更是在滨河造成了极大的恐慌,老刑警刘岩,带你破解...
    沈念sama阅读 159,716评论 4 364
  • 序言:滨河连续发生了三起死亡事件,死亡现场离奇诡异,居然都是意外死亡,警方通过查阅死者的电脑和手机,发现死者居然都...
    沈念sama阅读 67,558评论 1 294
  • 文/潘晓璐 我一进店门,熙熙楼的掌柜王于贵愁眉苦脸地迎上来,“玉大人,你说我怎么就摊上这事。” “怎么了?”我有些...
    开封第一讲书人阅读 109,431评论 0 244
  • 文/不坏的土叔 我叫张陵,是天一观的道长。 经常有香客问我,道长,这世上最难降的妖魔是什么? 我笑而不...
    开封第一讲书人阅读 44,127评论 0 209
  • 正文 为了忘掉前任,我火速办了婚礼,结果婚礼上,老公的妹妹穿的比我还像新娘。我一直安慰自己,他们只是感情好,可当我...
    茶点故事阅读 52,511评论 3 287
  • 文/花漫 我一把揭开白布。 她就那样静静地躺着,像睡着了一般。 火红的嫁衣衬着肌肤如雪。 梳的纹丝不乱的头发上,一...
    开封第一讲书人阅读 40,692评论 1 222
  • 那天,我揣着相机与录音,去河边找鬼。 笑死,一个胖子当着我的面吹牛,可吹牛的内容都是我干的。 我是一名探鬼主播,决...
    沈念sama阅读 31,915评论 2 313
  • 文/苍兰香墨 我猛地睁开眼,长吁一口气:“原来是场噩梦啊……” “哼!你这毒妇竟也来了?” 一声冷哼从身侧响起,我...
    开封第一讲书人阅读 30,664评论 0 202
  • 序言:老挝万荣一对情侣失踪,失踪者是张志新(化名)和其女友刘颖,没想到半个月后,有当地人在树林里发现了一具尸体,经...
    沈念sama阅读 34,412评论 1 246
  • 正文 独居荒郊野岭守林人离奇死亡,尸身上长有42处带血的脓包…… 初始之章·张勋 以下内容为张勋视角 年9月15日...
    茶点故事阅读 30,616评论 2 245
  • 正文 我和宋清朗相恋三年,在试婚纱的时候发现自己被绿了。 大学时的朋友给我发了我未婚夫和他白月光在一起吃饭的照片。...
    茶点故事阅读 32,105评论 1 260
  • 序言:一个原本活蹦乱跳的男人离奇死亡,死状恐怖,灵堂内的尸体忽然破棺而出,到底是诈尸还是另有隐情,我是刑警宁泽,带...
    沈念sama阅读 28,424评论 2 254
  • 正文 年R本政府宣布,位于F岛的核电站,受9级特大地震影响,放射性物质发生泄漏。R本人自食恶果不足惜,却给世界环境...
    茶点故事阅读 33,098评论 3 238
  • 文/蒙蒙 一、第九天 我趴在偏房一处隐蔽的房顶上张望。 院中可真热闹,春花似锦、人声如沸。这庄子的主人今日做“春日...
    开封第一讲书人阅读 26,096评论 0 8
  • 文/苍兰香墨 我抬头看了看天上的太阳。三九已至,却和暖如春,着一层夹袄步出监牢的瞬间,已是汗流浃背。 一阵脚步声响...
    开封第一讲书人阅读 26,869评论 0 197
  • 我被黑心中介骗来泰国打工, 没想到刚下飞机就差点儿被人妖公主榨干…… 1. 我叫王不留,地道东北人。 一个月前我还...
    沈念sama阅读 35,748评论 2 276
  • 正文 我出身青楼,却偏偏与公主长得像,于是被迫代替她去往敌国和亲。 传闻我的和亲对象是个残疾皇子,可洞房花烛夜当晚...
    茶点故事阅读 35,641评论 2 271

推荐阅读更多精彩内容

  • Android 自定义View的各种姿势1 Activity的显示之ViewRootImpl详解 Activity...
    passiontim阅读 170,569评论 25 707
  • 这两天鼓捣了一下node项目,记录一下node的调试方法。 前端开发的调试可以用打日志(console.log)或...
    采姑娘的大白菜阅读 16,128评论 2 9
  • 有点雾,有点雨,有点蒙蒙细雨
    謂言阅读 186评论 0 0
  • 作者 刘超奇 日内 普通有着窗户的客厅 一男穿着短裤背心躲在客厅的阴凉角 男: 热,简直烈日灼身。这个世界怎么变得...
    猫云七阅读 344评论 1 1
  • 在美丽的法国——巴黎,是每个人爱恋的地方。 ...
    ceb41f56410c阅读 145评论 1 1