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

简介

咱们使用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,1000
tick,0x7fff688bbe36,839,0,0x0,6
tick,0x7fff688bc2d2,2081,0,0x0,6
tick,0x100373430,3263,0,0x0,6
code-creation,Builtin,3,3746,0x1008aa020,1634,RecordWrite
code-creation,Builtin,3,3766,0x1008aa6a0,457,EphemeronKeyBarrier
code-creation,Builtin,3,3773,0x1008aa880,44,AdaptorWithBuiltinExitFrame
code-creation,Builtin,3,3781,0x1008aa8c0,294,ArgumentsAdaptorTrampoline
code-creation,Builtin,3,3788,0x1008aaa00,203,CallFunction_ReceiverIsNullOrUndefined
code-creation,Builtin,3,3796,0x1008aaae0,260,CallFunction_ReceiverIsNotNullOrUndefined
code-creation,Builtin,3,3804,0x1008aac00,285,CallFunction_ReceiverIsAny
code-creation,Builtin,3,3811,0x1008aad20,130,CallBoundFunction
...

能够看到日志文件中只记录了事件的发生，可是并无统计信息。

分析生成的文件

若是想要生成咱们看得懂的统计信息，则可使用：

//windows
tools\windows-tick-processor.bat v8.log

//linux
tools/linux-tick-processor v8.log

//macOS
tools/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... 下载。

若是要使用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-options
SSE3=1 SSSE3=1 SSE4_1=1 SAHF=1 AVX=1 FMA3=1 BMI1=1 BMI2=1 LZCNT=1 POPCNT=1 ATOM=0
Synopsis:
  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的博客

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