Нестандартная особенность Javascript для V8

Question

Сегодня я написал несколько строк JS, и я был ошеломлен. Может быть, я что-то пропустил, но не могу понять.

Ситуация следующая. У меня есть функция, которая называется дважды (или даже больше). Первое выполнение функции выполняется быстрее, чем после выполнения.

Код был протестирован в узле & Chrome (двигатель V8) Firefox выполняет код каждый раз с фиксированной скоростью, что довольно медленно, чем двигатели V8. Независимо от того, какая другая скорость выполнения в двигателях не важна. Вопрос в том, почему первое исполнение функции быстрее, чем другие в V8.

Вот код: (Он может копировать/вставить в хромированной консоли, и вы увидите результат)

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]); 

Answer 1

TL; DR: это из-за GC. Но это сложно.

Я воспроизведены ваши наблюдения с отладочной сборкой 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 оболочку со следующими параметрами: 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. В этом случае циклы Мусоробота и Марк-развертка 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 частично прав.

Посмотрим, что произойдет.

ИзмерениеFunc начинается с неоптимизированного.Он становится очень быстрым, поэтому Crankshaft оптимизирует его и записывает запись OSR (выполнение продолжается там, где оно было остановлено - от середины цикла, но только от новой оптимизированной версии машинного кода). Но почему-то вскоре после этого умозрительное предположение нарушается, вызывая спасение (выход OSR для неоптимизированного «полного» кода).

И V8 не пытается перекомпилировать measureFunc еще до того, как закончится первый звонок. Возможно, потому, что он уже OSRed в оптимизированную функцию и умозрительное предположение не удалось, поэтому он не видит смысла в попытке повторной попытки (я полагаю, я не знаю, какие эвристики используются точно).

Так что большую часть времени первый вызов measureFucntion выполняется на уровне полного компилятора. И этот полный код, похоже, не запускает GC, пока он работает в цикле. Я не знаю, было ли это намеренно или ошибка. Это подлежит дальнейшему расследованию.

Так что да, первое исполнение вызова (в основном) неоптимизировано, а последующие исполнения оптимизированы. Но V8 не решает запустить код медленнее. Первое выполнение происходит быстрее, потому что неоптимизированный код не останавливает запуск GC. И это действительно имеет значение в этом примере, потому что код на самом деле GC-интенсивный (из-за большого количества присвоений числа кучи с коротким сроком службы).

Answer 2

Там может быть много вещей неправильно с этим кодом. Однако возможны две вещи:

1. У V8 фактически есть два компилятора и сборщик мусора. Во втором прогоне, вероятно, он решает сделать полную компиляцию или сделать GC. Так что вызов конструкторов в исполнительном коде - это, может быть, не очень хорошая идея.
2. V8 оптимизирует или де оптимизирует ваш код на основе множества правил. Когда вы запускаете node --trace-deopt main.js, есть определенно деопты. Во втором запуске V8 решает, что по какой-то причине ваш код замедляется.

Обратите внимание, что если вы разделите код на две отдельные функции, вторая функция будет работать даже быстрее.

Подробные сведения см. В параметрах node --v8-flags.

Answer 3

Мы не можем позволить этому вопросу умереть без реального ответа!

Проблема в том, что V8 не любит преобразовывать «результат» в строку неявно через полиморфный оператор «+».

Если вы явно конвертируете результат из числа в строку, ожидаемая производительность восстанавливается.

res[index] = "RESULT FUNCTION: " + result + " FOR: 
 
// ===> 
 
res[index] = "RESULT FUNCTION: " + Number.prototype.toString.apply(result) + " FOR:

Вы можете сказать, глядя на --trace-deopt выход. Выполнение явного преобразования изменяет deopt от «нетерпеливого» неустранимого deopt до «мягкого» deopt, который можно восстановить с течением времени.

Аналогично, вы можете увидеть МАССИВНУЮ разницу в -trace-gc. Исходный код генерирует много удалений. Использование явного преобразования приводит к только одному очистке.

Конечным результатом является то, что оптимальная производительность достигается, если вы явно конвертируете.