写点什么

使用 V8 和 node 轻松 profile 分析 nodejs 应用程序

发布于: 2021 年 02 月 05 日

简介

我们使用 nodejs 写好了程序之后,要是想对该程序进行性能分析的话,就需要用到 profile 工具了。


虽然有很多很方便和强大的第三方 profile 工具,但是我们这里主要讲解 V8 和 node 自带的 profile,因为他们已经足够简单和强大了。使用他们基本上可以满足我们的日常分析需要。


下面就一起来看看吧。


使用 V8 的内置 profiler 工具

nodejs 是运行在 V8 引擎上的,而 V8 引擎本身就提供了内置的 profile 工具,要想直接使用 V8 引擎,我需要下载 V8 源代码,然后进行 build。一般来说我们有两种 build V8 的方法。


使用 gm 来 build V8

gm 是一个非常方便的 all-in-one 的脚本,可以用来生成 build 文件,触发 build 过程和运行测试用例。


一般来说,gm 脚本的位置在:/path/to/v8/tools/dev/gm.py


我们可以为其创建一个 alias,方便后面的使用:


alias gm=/path/to/v8/tools/dev/gm.py
复制代码

build V8:


gm x64.release
复制代码

build 之后进行用例验证:


gm x64.release.check
复制代码

是不是很简单?


手动 build V8

手动 build V8 就比较麻烦了,我们也可以分为三步,1.生成 build 文件,2.触发 build,3.运行测试用例


我们可以使用 gn 来为 out/foo 生成 build 文件:


gn args out/foo
复制代码

上面的命令将会开启一个编辑窗口,用来输入 gn 的参数。


我们可以添加 list 来查看所有的参数描述:


gn args out/foo --list
复制代码

当然我们也可以直接指定参数,来创建 build 文件:


gn gen out/foo --args='is_debug=false target_cpu="x64" v8_target_cpu="arm64" use_goma=true'
复制代码

除了 gn 之外,我们还可以使用 v8 自带的 v8gen 来创建 build 文件:


alias v8gen=/path/to/v8/tools/dev/v8gen.py
v8gen -b 'V8 Linux64 - debug builder' -m client.v8 foo
复制代码

创建好 build 文件之后,我们就可以进行编译了。


build 所有的 V8:


ninja -C out/x64.release
复制代码

只 build d8:


ninja -C out/x64.release d8
复制代码

最后我们运行测试,来验证是否构建成功:


tools/run-tests.py --outdir out/foo//或者tools/run-tests.py --gn
复制代码

生成 profile 文件

build 好 V8 之后,我们就可以使用其中的命令来生成 profile 文件了。


找到 d8 文件:


d8 --prof app.js
复制代码

通过添加 –prof 参数,我们可以生成一个 v8.log 文件,这个文件中包含了 profiling 数据。


注意这时候的 v8.log 文件虽然不是二进制格式的,但是阅读起来还是有难度的,因为它只是简单的做了 log 操作,并没有进行有效的统计分析。


我们看下生成的文件:


...profiler,begin,1000tick,0x7fff688bbe36,839,0,0x0,6tick,0x7fff688bc2d2,2081,0,0x0,6tick,0x100373430,3263,0,0x0,6code-creation,Builtin,3,3746,0x1008aa020,1634,RecordWritecode-creation,Builtin,3,3766,0x1008aa6a0,457,EphemeronKeyBarriercode-creation,Builtin,3,3773,0x1008aa880,44,AdaptorWithBuiltinExitFramecode-creation,Builtin,3,3781,0x1008aa8c0,294,ArgumentsAdaptorTrampolinecode-creation,Builtin,3,3788,0x1008aaa00,203,CallFunction_ReceiverIsNullOrUndefinedcode-creation,Builtin,3,3796,0x1008aaae0,260,CallFunction_ReceiverIsNotNullOrUndefinedcode-creation,Builtin,3,3804,0x1008aac00,285,CallFunction_ReceiverIsAnycode-creation,Builtin,3,3811,0x1008aad20,130,CallBoundFunction...
复制代码

可以看到日志文件中只记录了事件的发生,但是并没有统计信息。


分析生成的文件

如果想要生成我们看得懂的统计信息,则可以使用:


//windowstools\windows-tick-processor.bat v8.log
//linuxtools/linux-tick-processor v8.log
//macOStools/mac-tick-processor v8.log
复制代码

来生成可以理解的日志文件。


生成的文件大概是下面样子的:


Statistical profiling result from benchmarks\v8.log, (4192 ticks, 0 unaccounted, 0 excluded).
[Shared libraries]: ticks total nonlib name 9 0.2% 0.0% C:\WINDOWS\system32\ntdll.dll 2 0.0% 0.0% C:\WINDOWS\system32\kernel32.dll
[JavaScript]: ticks total nonlib name 741 17.7% 17.7% LazyCompile: am3 crypto.js:108 113 2.7% 2.7% LazyCompile: Scheduler.schedule richards.js:188 103 2.5% 2.5% LazyCompile: rewrite_nboyer earley-boyer.js:3604 103 2.5% 2.5% LazyCompile: TaskControlBlock.run richards.js:324 96 2.3% 2.3% Builtin: JSConstructCall ...
复制代码

用惯的 IDE 的同学可能在想,能不能有个 web 页面来统一展示这个结果呢?


有的,V8 提供了 profview 工具,让我们可以从 web UI 来分析生成的结果。


profview 是一个 html 工具,我们可以从 https://chromium.googlesource.com/v8/v8.git/+/master/tools/profview/ 下载。


如果要使用 profview,我们还需要对第一步生成的 v8.log 文件进行预处理:


linux-tick-processor --preprocess > v8.json
复制代码

然后在 profview 页面上传 v8.json 进行分析即可。


生成时间线图

–prof 还可以接其他参数,比如 –log-timer-events, 通过使用这个参数可以用来统计 V8 引擎中花费的时间。


d8 --prof --log-timer-events app.js
tools/plot-timer-events v8.log
复制代码

第一个命令生成 v8.log 文件,第二个命令会生成一个 timer-events.png 图形文件,更加直观的展示数据。


因为生成日志实际上对程序的性能是有一定的影响的,我们还可以为 plot-timer-events 添加失真因子,来纠正这个问题。如果我们没有指定纠正因子,脚本会自动进行查找。当然,我们也可以向下面这样手动指定:


tools/plot-timer-events --distortion=4500 v8.log
复制代码

使用 nodejs 的 profile 工具

在 nodejs 4.4.0 之前,只能下载 V8 的源代码进行编译,才能进行 profile。 而在 nodejs 4.4.0 之后,node 命令已经集成了 V8 的功能。


我们可以使用 node –v8-options 来查看 node 中可用的 V8 参数:


node  --v8-optionsSSE3=1 SSSE3=1 SSE4_1=1 SAHF=1 AVX=1 FMA3=1 BMI1=1 BMI2=1 LZCNT=1 POPCNT=1 ATOM=0Synopsis:  shell [options] [--shell] [<file>...]  d8 [options] [-e <string>] [--shell] [[--module] <file>...]
-e execute a string in V8 --shell run an interactive JavaScript shell --module execute a file as a JavaScript module
Note: the --module option is implicitly enabled for *.mjs files.
The following syntax for options is accepted (both '-' and '--' are ok): --flag (bool flags only) --no-flag (bool flags only) --flag=value (non-bool flags only, no spaces around '=') --flag value (non-bool flags only) -- (captures all remaining args in JavaScript)
Options: --use-strict (enforce strict mode) type: bool default: false --es-staging (enable test-worthy harmony features (for internal use only)) type: bool default: false...
复制代码

参数很多,同样的我们可以使用 –prof 参数:


node --prof app.js
复制代码

会在本地目录生成一个类似 isolate-0x102884000-14025-v8.log 的文件。


文件的内容和 V8 生成的一致,这里就不列出来了。


要想分析这个文件,可以使用:


node --prof-process isolate-0x102884000-14025-v8.log > processed.txt
复制代码

看下生成的分析结果:


Statistical profiling result from isolate-0x102884000-14025-v8.log, (296 ticks, 4 unaccounted, 0 excluded).
[Shared libraries]: ticks total nonlib name 6 2.0% /usr/lib/system/libsystem_pthread.dylib 6 2.0% /usr/lib/system/libsystem_kernel.dylib 2 0.7% /usr/lib/system/libsystem_malloc.dylib 1 0.3% /usr/lib/system/libmacho.dylib 1 0.3% /usr/lib/system/libcorecrypto.dylib
[JavaScript]: ticks total nonlib name
...
[Summary]: ticks total nonlib name 0 0.0% 0.0% JavaScript 276 93.2% 98.6% C++ 24 8.1% 8.6% GC 16 5.4% Shared libraries 4 1.4% Unaccounted
[C++ entry points]: ticks cpp total name 142 63.1% 48.0% T __ZN2v88internal21Builtin_HandleApiCallEiPmPNS0_7IsolateE 82 36.4% 27.7% T __ZN2v88internal40Builtin_CallSitePrototypeGetPromiseIndexEiPmPNS0_7IsolateE 1 0.4% 0.3% T __ZN2v88internal36Builtin_CallSitePrototypeGetFileNameEiPmPNS0_7IsolateE...


复制代码

和 V8 的也很类似。


从 Summary 和各个 entry points 中,我们可以进一步分析程序中到底哪一块占用了较多的 CPU 时间。


上面的百分百的意思是,在采样的这些数据中,有 93.2%的都在运行 C++代码。那么我们接下来就应该去看一下,到底是哪些 C++代码占用了最多的时间,并找出相应的解决办法。


本文作者:flydean 程序那些事

本文链接:http://www.flydean.com/nodejs-profile/

本文来源:flydean 的博客

欢迎关注我的公众号:「程序那些事」最通俗的解读,最深刻的干货,最简洁的教程,众多你不知道的小技巧等你来发现!


发布于: 2021 年 02 月 05 日阅读数: 777
用户头像

关注公众号:程序那些事,更多精彩等着你! 2020.06.07 加入

最通俗的解读,最深刻的干货,最简洁的教程,众多你不知道的小技巧,尽在公众号:程序那些事!

评论

发布
暂无评论
使用V8和node轻松profile分析nodejs应用程序