如何读取nodejs内部探查器tick-processor输出

我对分析我的Node.js应用程序很感兴趣.我用--prof旗帜启动它,并获得了一个v8.log文件.我采用了windows-tick-processor并获得了一个人类可读的分析日志.在问题的底部是日志文件中的一些小摘录,我完全无法理解.

我得到了滴答统计方法.我不明白totalvs nonlib意味着什么.此外,我不明白为什么有些事情的前缀LazyCompile,Function,Stub或其他条款.

我希望得到的最佳答案是刻度处理器输出格式的完整文档/指南,完整地解释每个术语,结构等...

除此之外,我只是不明白lazy-compile是什么.是汇编吗？是不是每个函数都只编译一次？那么编译怎么可能是我的应用程序执行的重要部分？该应用程序运行了几个小时来生成此日志,我假设内部JavaScript编译需要几毫秒.这表明懒惰编译是每个函数不会发生一次,但在某种代码评估期间会发生？这是否意味着每当我有一个函数定义(例如嵌套函数)时,内部函数每次都会"懒惰编译"？

我在任何地方都找不到任何关于此的信息,我一直在谷歌搜索DAYS ......

我也意识到有很多探查器标志.其他参考资料也欢迎.

[JavaScript]:
   ticks  total  nonlib   name
  88414    7.9%   20.1%  LazyCompile: *getUniqueId C:\n\dev\SCNA\infra\lib\node-js\utils\general-utils.js:16
  22797    2.0%    5.2%  LazyCompile: *keys native v8natives.js:333
  14524    1.3%    3.3%  LazyCompile: Socket._flush C:\n\dev\SCNA\runtime-environment\load-generator\node_modules\zmq\lib\index.js:365
  12896    1.2%    2.9%  LazyCompile: BasicSerializeObject native json.js:244
  12346    1.1%    2.8%  LazyCompile: BasicJSONSerialize native json.js:274
   9327    0.8%    2.1%  LazyCompile: * C:\n\dev\SCNA\runtime-environment\load-generator\node_modules\zmq\lib\index.js:194
   7606    0.7%    1.7%  LazyCompile: *parse native json.js:55
   5937    0.5%    1.4%  LazyCompile: *split native string.js:554
   5138    0.5%    1.2%  LazyCompile: *Socket.send C:\n\dev\SCNA\runtime-environment\load-generator\node_modules\zmq\lib\index.js:346
   4862    0.4%    1.1%  LazyCompile: *sort native array.js:741
   4806    0.4%    1.1%  LazyCompile: _.each._.forEach C:\n\dev\SCNA\infra\node_modules\underscore\underscore.js:76
   4481    0.4%    1.0%  LazyCompile: ~_.each._.forEach C:\n\dev\SCNA\infra\node_modules\underscore\underscore.js:76
   4296    0.4%    1.0%  LazyCompile: stringify native json.js:308
   3796    0.3%    0.9%  LazyCompile: ~b native v8natives.js:1582
   3694    0.3%    0.8%  Function: ~recursivePropertiesCollector C:\n\dev\SCNA\infra\lib\node-js\utils\object-utils.js:90
   3599    0.3%    0.8%  LazyCompile: *BasicSerializeArray native json.js:181
   3578    0.3%    0.8%  LazyCompile: *Buffer.write buffer.js:315
   3157    0.3%    0.7%  Stub: CEntryStub
   2958    0.3%    0.7%  LazyCompile: promise.promiseDispatch C:\n\dev\SCNA\runtime-environment\load-generator\node_modules\q\q.js:516

88414    7.9%  LazyCompile: *getUniqueId C:\n\dev\SCNA\infra\lib\node-js\utils\general-utils.js:16
  88404  100.0%    LazyCompile: *generateId C:\n\dev\SCNA\infra\lib\node-js\utils\general-utils.js:51
  88404  100.0%      LazyCompile: *register C:\n\dev\SCNA\infra\lib\node-js\events\pattern-dispatcher.js:72
  52703   59.6%        LazyCompile: * C:\n\dev\SCNA\runtime-environment\load-generator\lib\vuser-driver\mdrv-driver.js:216
  52625   99.9%          LazyCompile: *_.each._.forEach C:\n\dev\SCNA\runtime-environment\load-generator\node_modules\underscore\underscore.js:76
  52625  100.0%            LazyCompile: ~usingEventHandlerMapping C:\n\dev\SCNA\runtime-environment\load-generator\lib\vuser-driver\mdrv-driver.js:214
  35555   40.2%        LazyCompile: *once C:\n\dev\SCNA\infra\lib\node-js\events\pattern-dispatcher.js:88
  29335   82.5%          LazyCompile: ~startAction C:\n\dev\SCNA\runtime-environment\load-generator\lib\vuser-driver\mdrv-driver.js:201
  25687   87.6%            LazyCompile: ~onActionComplete C:\n\dev\SCNA\runtime-environment\load-generator\lib\vuser-driver\mdrv-logic.js:130
   1908    6.5%            LazyCompile: ~b native v8natives.js:1582
   1667    5.7%            LazyCompile: _fulfilled C:\n\dev\SCNA\runtime-environment\load-generator\node_modules\q\q.js:795
   4645   13.1%          LazyCompile: ~terminate C:\n\dev\SCNA\runtime-environment\load-generator\lib\vuser-driver\mdrv-driver.js:160
   4645  100.0%            LazyCompile: ~terminate C:\n\dev\SCNA\runtime-environment\load-generator\lib\vuser-driver\mdrv-logic.js:171
   1047    2.9%          LazyCompile: *startAction C:\n\dev\SCNA\runtime-environment\load-generator\lib\vuser-driver\mdrv-driver.js:201
   1042   99.5%            LazyCompile: ~onActionComplete C:\n\dev\SCNA\runtime-environment\load-generator\lib\vuser-driver\mdrv-logic.js:130

Vladislav Iv.. 33

实际上,你在假设实际花费在编译代码上的时间是正确的:它需要几毫秒(可以用--trace-opt旗帜看到).

现在谈论这个LazyCompile.以下是Vyacheslav Egorov(前v8 dev)博客的引文:

如果使用的是V8的Tick处理器记住,LazyCompile:前缀并不能意味着,这一次是在编译器中度过,它只是意味着该函数本身懒洋洋地编译.

函数名前面的星号表示在优化函数中花费时间,tilda - 未优化.

关于你关于函数被编译多少次的问题.实际上,JIT(所谓的全代码生成器)在第一次执行时会为每个函数创建一个非优化版本.但后来可能会发生任意(好的,某种程度上)数字或重新编译(由于优化和纾困).但是在这种分析日志中你不会看到任何一个.

Stub 我理解的前缀意味着执行是在C-Stub中,它是运行时的一部分,并与引擎的其他部分一起编译(即它不是JIT编译的JS代码).

total对比nonlib:

这些列仅仅意味着在那里花费了总x /非lib时间的x%.(我可以在这里引用你的讨论).

此外,您可以找到https://github.com/v8/v8/wiki/Using%20V8%E2%80%99s%20internal%20profiler有用.