[toc] # 簡介 我們使用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，方便後面的使用： ~~~js alias gm=/path/to/v8/tools/dev/gm.py ~~~ build V8: ~~~js gm x64.release ~~~ build之後進行用例驗證： ~~~js gm x64.release.check ~~~ 是不是很簡單？ ## 手動build V8 手動build V8就比較麻煩了，我們也可以分為三步，1.生成build檔案，2.觸發build，3.執行測試用例 我們可以使用gn來為out/foo生成build檔案： ~~~js gn args out/foo ~~~ 上面的命令將會開啟一個編輯視窗，用來輸入gn的引數。 我們可以新增list來檢視所有的引數描述： ~~~js gn args out/foo --list ~~~ 當然我們也可以直接指定引數，來建立build檔案： ~~~js gn gen out/foo --args='is_debug=false target_cpu="x64" v8_target_cpu="arm64" use_goma=true' ~~~ 除了gn之外，我們還可以使用v8自帶的v8gen來建立build檔案： ~~~js alias v8gen=/path/to/v8/tools/dev/v8gen.py v8gen -b 'V8 Linux64 - debug builder' -m client.v8 foo ~~~ 建立好build檔案之後，我們就可以進行編譯了。 build所有的V8： ~~~js ninja -C out/x64.release ~~~ 只build d8: ~~~js ninja -C out/x64.release d8 ~~~ 最後我們執行測試，來驗證是否構建成功： ~~~js tools/run-tests.py --outdir out/foo //或者 tools/run-tests.py --gn ~~~ ## 生成profile檔案 build好V8之後，我們就可以使用其中的命令來生成profile檔案了。 找到d8檔案： ~~~js d8 --prof app.js ~~~ 通過新增 --prof 引數，我們可以生成一個v8.log檔案，這個檔案中包含了profiling資料。 注意這時候的v8.log檔案雖然不是二進位制格式的，但是閱讀起來還是有難度的，因為它只是簡單的做了log操作，並沒有進行有效的統計分析。 我們看下生成的檔案： ~~~js ... 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 ... ~~~ 可以看到日誌檔案中只記錄了事件的發生，但是並沒有統計資訊。 ## 分析生成的檔案 如果想要生成我們看得懂的統計資訊，則可以使用： ~~~js //windows tools\windows-tick-processor.bat v8.log //linux tools/linux-tick-processor v8.log //macOS tools/mac-tick-processor v8.log ~~~ 來生成可以理解的日誌檔案。 生成的檔案大概是下面樣子的： ~~~js 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檔案進行預處理： ~~~js linux-tick-processor --preprocess > v8.json ~~~ 然後在profview頁面上傳v8.json進行分析即可。 ## 生成時間線圖 --prof 還可以接其他引數，比如 --log-timer-events， 通過使用這個引數可以用來統計V8引擎中花費的時間。 ~~~js d8 --prof --log-timer-events app.js tools/plot-timer-events v8.log ~~~ 第一個命令生成v8.log檔案，第二個命令會生成一個timer-events.png圖形檔案，更加直觀的展示資料。 因為生成日誌實際上對程式的效能是有一定的影響的，我們還可以為plot-timer-events新增失真因子，來糾正這個問題。如果我們沒有指定糾正因子，指令碼會自動進行查詢。當然，我們也可以向下面這樣手動指定： ~~~js 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引數： ~~~js 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] [...] d8 [options] [-e ] [--shell] [[--module] ...] -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 引數： ~~~js node --prof app.js ~~~ 會在本地目錄生成一個類似 isolate-0x102884000-14025-v8.log 的檔案。 檔案的內容和V8生成的一致，這裡就不列出來了。 要想分析這個檔案，可以使用： ~~~js node --prof-process isolate-0x102884000-14025-v8.log > processed.txt ~~~ 看下生成的分析結果： ~~~js 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/](http://www.flydean.com/nodejs-profile/) > > 本文來源：flydean的部落格 > > 歡迎關注我的公眾號:「程式那些事」最通俗的解讀，最深刻的乾貨，最簡潔的教程，眾多你不知道的小技巧等你來