Javascript V8 中的特殊性能
Javascript odd performance special in V8
今天写了几行JS,惊呆了。。。可能是漏掉了什么,但想不通。
情况如下。我有一个被调用两次(或更多次)的函数。函数的第一次执行比后面的执行快。
代码已在 Node 和 Chrome(V8 引擎)中测试
Firefox 每次都以固定速度执行代码,这比 V8 引擎慢得多。跨引擎的不同执行速度并不重要。问题是关于为什么函数第一次执行比 V8 中的其他函数快。
代码如下:(可以在chrome控制台中输入copy/pasted,你会看到结果)
var loop = 10000000;
function callable() {
return Math.random();
}
function measureFunction(index) {
var result = 0;
var timer = new Date();
var start = timer.getTime();
for (var i = 0; i < loop; ++i)
result += callable();
res[index] = "RESULT FUNCTION: " + result + " FOR: " + (new Date().getTime() - start);
}
var res = new Array(2);
for (var i = 0 ;i < res.length; ++i)
measureFunction(i);
for (var i = 0; i < res.length; ++i)
console.log(res[i]);
这段代码可能有很多错误。但是可能有两件事:
- V8 实际上有两个编译器和垃圾收集器。在第二个 运行 中,它可能决定进行完整编译或完成 GC。所以在高性能代码中调用构造函数可能不是一个好主意
- V8 根据大量规则优化或取消优化您的代码。当你 运行
node --trace-deopt main.js
时,肯定会发生 deopts。在第二个 运行 V8 决定你的代码 运行 出于某种原因变慢了。
请注意,如果您将代码拆分为两个单独的函数,第二个函数甚至会 运行 更快。
您可以使用 node --v8-flags
选项进行更多调查。
TL;DR:这是因为 GC。但是很复杂。
我已经在这个稍微修改过的 js 上用 V8 version 4.8.0 (candidate)
(我手边那个)的调试版本重现了你的观察结果:
var loop = 10000000 * 10;
function callable() {
return Math.random();
}
function measureFunction(index) {
var result = 0;
var timer = new Date();
var start = timer.getTime();
for (var i = 0; i < loop; ++i)
result += callable();
res[index] = "RESULT FUNCTION: " + result + " FOR: " + (new Date().getTime() - start) + " ms";
}
var res = new Array(3);
for (var i = 0 ;i < res.length; ++i) {
measureFunction(i);
print (i + " COMPLETE"); // use console.log for node
}
for (var i = 0; i < res.length; ++i)
print(res[i]); // ditto
它在我的机器上给出了以下输出:
0 COMPLETE
1 COMPLETE
2 COMPLETE
RESULT FUNCTION: 49997528.61602645 FOR: 649 ms
RESULT FUNCTION: 49996578.63860239 FOR: 1402 ms
RESULT FUNCTION: 49995279.39097646 FOR: 1400 ms
之后,我 运行 v8 shell 具有以下选项:d8 main.js --trace-opt --trace-deopt --trace-gc
它给出了以下输出(删节):
...
[marking 0xaaf9fce2a79 <JS Function measureFunction (SharedFunctionInfo 0xaaf9fce2501)> for recompilation..
[didn't find optimized code in optimized code map for 0xaaf9fce2501 <SharedFunctionInfo measureFunction>]
[compiling method 0xaaf9fce2a79 <JS Function measureFunction (SharedFunctionInfo 0xaaf9fce2501)> using Crankshaft OSR]
[optimizing 0xaaf9fce2a79 <JS Function measureFunction (SharedFunctionInfo 0xaaf9fce2501)> - took 1.092, 3.601, 2.595 ms]
[didn't find optimized code in optimized code map for 0xaaf9fce2501 <SharedFunctionInfo measureFunction>]
[optimizing 0xaaf9fcd2181 <JS Function random (SharedFunctionInfo 0xaaf9fc5c111)> - took 0.445, 2.367, 0.122 ms]
[completed optimizing 0xaaf9fcd2181 <JS Function random (SharedFunctionInfo 0xaaf9fc5c111)>]
[deoptimizing (DEOPT eager): begin 0xaaf9fce2a79 <JS Function measureFunction (SharedFunctionInfo 0xaaf9fce2501)> (opt #3) @14, FP to SP delta: 120]
;;; deoptimize at 298: wrong instance type
...
[deoptimizing (eager): ... took 0.099 ms]
Materialization [0x7ffffae625a8] <- 0x25c6de07d439 ; 0x25c6de07d439 <Number: 5.00034e+07>
[removing optimized code for: measureFunction]
[evicting entry from optimizing code map (notify deoptimized) for 0xaaf9fce2501 <SharedFunctionInfo measureFunction> (osr ast id 71)]
0 COMPLETE
[marking 0xaaf9fce2a79 <JS Function measureFunction> for recompilation, reason: small function, ICs with typeinfo: 13/15 (86%)...]
[14386:0x49c5fb0] 657 ms: Scavenge 2.1 (37.1) -> 1.2 (37.1) MB, 1.2 / 0 ms [allocation failure].
[didn't find optimized code in optimized code map for 0xaaf9fce2501 <SharedFunctionInfo measureFunction>]
[compiling method 0xaaf9fce2a79 <JS Function measureFunction (SharedFunctionInfo 0xaaf9fce2501)> using Crankshaft OSR]
[optimizing 0xaaf9fce2a79 <JS Function measureFunction (SharedFunctionInfo 0xaaf9fce2501)> - took 1.232, 5.863, 0.621 ms]
[didn't find optimized code in optimized code map for 0xaaf9fce2501 <SharedFunctionInfo measureFunction>]
[14386:0x49c5fb0] 667 ms: Scavenge 2.1 (37.1) -> 1.2 (37.1) MB, 0.7 / 0 ms [allocation failure].
[14386:0x49c5fb0] 668 ms: Scavenge 2.2 (37.1) -> 1.2 (37.1) MB, 0.4 / 0 ms [allocation failure].
[14386:0x49c5fb0] 669 ms: Scavenge 2.2 (37.1) -> 1.2 (37.1) MB, 0.4 / 0 ms [allocation failure].
[14386:0x49c5fb0] 669 ms: Scavenge 2.2 (37.1) -> 1.2 (37.1) MB, 0.4 / 0 ms [allocation failure].
[14386:0x49c5fb0] 670 ms: Scavenge 2.2 (37.1) -> 1.2 (37.1) MB, 0.4 / 0 ms [allocation failure].
... and so on, 1550 times ...
1 COMPLETE
Same thing (only the scavenger messages) for 2.
如果我提供,例如 --gc-interval=1
到 v8,情况就会改变。在这种情况下,Scavenge 和 Mark-sweep GC 循环也在第一次调用期间发生,输出如下所示:
0 COMPLETE
1 COMPLETE
2 COMPLETE
RESULT FUNCTION: 50005046.56689139 FOR: 919 ms
RESULT FUNCTION: 50006871.86618896 FOR: 678 ms
RESULT FUNCTION: 49998279.72474023 FOR: 670 ms
UPD
事实证明 eljefedelrodeodeljefe 是部分正确的。
让我们看看会发生什么。
measureFunc 开始时未优化。它很快变热,因此 Crankshaft 对其进行优化并执行 OSR 条目(执行从它停止的地方继续——从循环的中间开始——但在新优化的机器代码版本上)。但由于某种原因,不久之后推测性假设被打破,导致紧急救援(OSR 退出未优化,'full' 代码)。
并且 V8 不会在第一次调用结束之前再次尝试重新编译 measureFunc。
可能是因为它已经将 OSRed 转化为优化函数并且推测性假设失败了,所以它认为急于重试没有意义(我想。我不知道究竟使用了什么启发式方法)。
所以大多数时候measureFucntion的第一次调用是在Full-compiler层执行的。这段完整的代码在 运行 循环时似乎不会触发 GC。不知道是故意的还是bug。有待进一步调查。
所以是的,第一个调用执行(大部分)未优化,后续执行已优化。但是 V8 并没有决定 运行 代码变慢。第一次执行恰好更快,因为未优化的代码不会停止触发 GC。它在这个例子中产生了真正的不同,因为代码实际上是 GC 密集型的(由于大量的堆编号分配具有较短的生命周期)。
我们不能让这个问题没有真正的答案就死掉!
问题在于 V8 不喜欢通过多态“+”运算符将 "result" 隐式转换为字符串。
如果您明确地将结果从数字转换为字符串,则会恢复预期的性能。
res[index] = "RESULT FUNCTION: " + result + " FOR:
// ===>
res[index] = "RESULT FUNCTION: " + Number.prototype.toString.apply(result) + " FOR:
您可以通过查看 --trace-deopt 输出来判断。执行显式转换会将 deopt 从 "eager" 不可恢复的 deopt 更改为 "soft" 随着时间的推移可恢复的 deopt。
同样,您可以在 --trace-gc 中看到巨大的差异。原始代码会产生许多清除。使用显式转换只会产生一次清除。
最终结果是,如果您显式转换,将获得最佳性能。
今天写了几行JS,惊呆了。。。可能是漏掉了什么,但想不通。
情况如下。我有一个被调用两次(或更多次)的函数。函数的第一次执行比后面的执行快。
代码已在 Node 和 Chrome(V8 引擎)中测试 Firefox 每次都以固定速度执行代码,这比 V8 引擎慢得多。跨引擎的不同执行速度并不重要。问题是关于为什么函数第一次执行比 V8 中的其他函数快。
代码如下:(可以在chrome控制台中输入copy/pasted,你会看到结果)
var loop = 10000000;
function callable() {
return Math.random();
}
function measureFunction(index) {
var result = 0;
var timer = new Date();
var start = timer.getTime();
for (var i = 0; i < loop; ++i)
result += callable();
res[index] = "RESULT FUNCTION: " + result + " FOR: " + (new Date().getTime() - start);
}
var res = new Array(2);
for (var i = 0 ;i < res.length; ++i)
measureFunction(i);
for (var i = 0; i < res.length; ++i)
console.log(res[i]);
这段代码可能有很多错误。但是可能有两件事:
- V8 实际上有两个编译器和垃圾收集器。在第二个 运行 中,它可能决定进行完整编译或完成 GC。所以在高性能代码中调用构造函数可能不是一个好主意
- V8 根据大量规则优化或取消优化您的代码。当你 运行
node --trace-deopt main.js
时,肯定会发生 deopts。在第二个 运行 V8 决定你的代码 运行 出于某种原因变慢了。
请注意,如果您将代码拆分为两个单独的函数,第二个函数甚至会 运行 更快。
您可以使用 node --v8-flags
选项进行更多调查。
TL;DR:这是因为 GC。但是很复杂。
我已经在这个稍微修改过的 js 上用 V8 version 4.8.0 (candidate)
(我手边那个)的调试版本重现了你的观察结果:
var loop = 10000000 * 10;
function callable() {
return Math.random();
}
function measureFunction(index) {
var result = 0;
var timer = new Date();
var start = timer.getTime();
for (var i = 0; i < loop; ++i)
result += callable();
res[index] = "RESULT FUNCTION: " + result + " FOR: " + (new Date().getTime() - start) + " ms";
}
var res = new Array(3);
for (var i = 0 ;i < res.length; ++i) {
measureFunction(i);
print (i + " COMPLETE"); // use console.log for node
}
for (var i = 0; i < res.length; ++i)
print(res[i]); // ditto
它在我的机器上给出了以下输出:
0 COMPLETE
1 COMPLETE
2 COMPLETE
RESULT FUNCTION: 49997528.61602645 FOR: 649 ms
RESULT FUNCTION: 49996578.63860239 FOR: 1402 ms
RESULT FUNCTION: 49995279.39097646 FOR: 1400 ms
之后,我 运行 v8 shell 具有以下选项:d8 main.js --trace-opt --trace-deopt --trace-gc
它给出了以下输出(删节):
...
[marking 0xaaf9fce2a79 <JS Function measureFunction (SharedFunctionInfo 0xaaf9fce2501)> for recompilation..
[didn't find optimized code in optimized code map for 0xaaf9fce2501 <SharedFunctionInfo measureFunction>]
[compiling method 0xaaf9fce2a79 <JS Function measureFunction (SharedFunctionInfo 0xaaf9fce2501)> using Crankshaft OSR]
[optimizing 0xaaf9fce2a79 <JS Function measureFunction (SharedFunctionInfo 0xaaf9fce2501)> - took 1.092, 3.601, 2.595 ms]
[didn't find optimized code in optimized code map for 0xaaf9fce2501 <SharedFunctionInfo measureFunction>]
[optimizing 0xaaf9fcd2181 <JS Function random (SharedFunctionInfo 0xaaf9fc5c111)> - took 0.445, 2.367, 0.122 ms]
[completed optimizing 0xaaf9fcd2181 <JS Function random (SharedFunctionInfo 0xaaf9fc5c111)>]
[deoptimizing (DEOPT eager): begin 0xaaf9fce2a79 <JS Function measureFunction (SharedFunctionInfo 0xaaf9fce2501)> (opt #3) @14, FP to SP delta: 120]
;;; deoptimize at 298: wrong instance type
...
[deoptimizing (eager): ... took 0.099 ms]
Materialization [0x7ffffae625a8] <- 0x25c6de07d439 ; 0x25c6de07d439 <Number: 5.00034e+07>
[removing optimized code for: measureFunction]
[evicting entry from optimizing code map (notify deoptimized) for 0xaaf9fce2501 <SharedFunctionInfo measureFunction> (osr ast id 71)]
0 COMPLETE
[marking 0xaaf9fce2a79 <JS Function measureFunction> for recompilation, reason: small function, ICs with typeinfo: 13/15 (86%)...]
[14386:0x49c5fb0] 657 ms: Scavenge 2.1 (37.1) -> 1.2 (37.1) MB, 1.2 / 0 ms [allocation failure].
[didn't find optimized code in optimized code map for 0xaaf9fce2501 <SharedFunctionInfo measureFunction>]
[compiling method 0xaaf9fce2a79 <JS Function measureFunction (SharedFunctionInfo 0xaaf9fce2501)> using Crankshaft OSR]
[optimizing 0xaaf9fce2a79 <JS Function measureFunction (SharedFunctionInfo 0xaaf9fce2501)> - took 1.232, 5.863, 0.621 ms]
[didn't find optimized code in optimized code map for 0xaaf9fce2501 <SharedFunctionInfo measureFunction>]
[14386:0x49c5fb0] 667 ms: Scavenge 2.1 (37.1) -> 1.2 (37.1) MB, 0.7 / 0 ms [allocation failure].
[14386:0x49c5fb0] 668 ms: Scavenge 2.2 (37.1) -> 1.2 (37.1) MB, 0.4 / 0 ms [allocation failure].
[14386:0x49c5fb0] 669 ms: Scavenge 2.2 (37.1) -> 1.2 (37.1) MB, 0.4 / 0 ms [allocation failure].
[14386:0x49c5fb0] 669 ms: Scavenge 2.2 (37.1) -> 1.2 (37.1) MB, 0.4 / 0 ms [allocation failure].
[14386:0x49c5fb0] 670 ms: Scavenge 2.2 (37.1) -> 1.2 (37.1) MB, 0.4 / 0 ms [allocation failure].
... and so on, 1550 times ...
1 COMPLETE
Same thing (only the scavenger messages) for 2.
如果我提供,例如 --gc-interval=1
到 v8,情况就会改变。在这种情况下,Scavenge 和 Mark-sweep GC 循环也在第一次调用期间发生,输出如下所示:
0 COMPLETE
1 COMPLETE
2 COMPLETE
RESULT FUNCTION: 50005046.56689139 FOR: 919 ms
RESULT FUNCTION: 50006871.86618896 FOR: 678 ms
RESULT FUNCTION: 49998279.72474023 FOR: 670 ms
UPD
事实证明 eljefedelrodeodeljefe 是部分正确的。
让我们看看会发生什么。
measureFunc 开始时未优化。它很快变热,因此 Crankshaft 对其进行优化并执行 OSR 条目(执行从它停止的地方继续——从循环的中间开始——但在新优化的机器代码版本上)。但由于某种原因,不久之后推测性假设被打破,导致紧急救援(OSR 退出未优化,'full' 代码)。
并且 V8 不会在第一次调用结束之前再次尝试重新编译 measureFunc。 可能是因为它已经将 OSRed 转化为优化函数并且推测性假设失败了,所以它认为急于重试没有意义(我想。我不知道究竟使用了什么启发式方法)。
所以大多数时候measureFucntion的第一次调用是在Full-compiler层执行的。这段完整的代码在 运行 循环时似乎不会触发 GC。不知道是故意的还是bug。有待进一步调查。
所以是的,第一个调用执行(大部分)未优化,后续执行已优化。但是 V8 并没有决定 运行 代码变慢。第一次执行恰好更快,因为未优化的代码不会停止触发 GC。它在这个例子中产生了真正的不同,因为代码实际上是 GC 密集型的(由于大量的堆编号分配具有较短的生命周期)。
我们不能让这个问题没有真正的答案就死掉!
问题在于 V8 不喜欢通过多态“+”运算符将 "result" 隐式转换为字符串。
如果您明确地将结果从数字转换为字符串,则会恢复预期的性能。
res[index] = "RESULT FUNCTION: " + result + " FOR:
// ===>
res[index] = "RESULT FUNCTION: " + Number.prototype.toString.apply(result) + " FOR:
您可以通过查看 --trace-deopt 输出来判断。执行显式转换会将 deopt 从 "eager" 不可恢复的 deopt 更改为 "soft" 随着时间的推移可恢复的 deopt。
同样,您可以在 --trace-gc 中看到巨大的差异。原始代码会产生许多清除。使用显式转换只会产生一次清除。
最终结果是,如果您显式转换,将获得最佳性能。