JavaScript test on V8

Question

function add(x, y) {  
   return x + y;  
}  

console.time("time1");

for (var i = 0; i < 90000000; ++i) {
    add(1, 2);   
    add('a','b');
}

console.timeEnd("time1");

function addText(x, y) {   
   return x + y;  
} 

function addNumber(x, y) {   
   return x + y;  
}

console.time("time2");

for (var i = 0; i < 90000000; ++i) {
    addNumber(1, 2);   
    addText('a','b');
}

console.timeEnd("time2");

the result is: time1: 1481ms, time2: 102ms,

i running this test on nodejs, but i don't know why the first test run slower than the second one.

Answer 1

This is because of deoptimisation happening under the hood due to parameter type change. To know this, we have to know what optimsiation V8 does:

Inlining

It is an important optimisation and is crucial for performance boost. It replaces function call with function body to speedup execution. If a function is small in size it will be inlined. This assumes that in function calls, the parameters are fixed.

Deoptimisation

The V8 does optimisation under certain assumptions. If it is wrong it has to undo those optimisations,so that it is able to run code correctly. Deoptimizations are bad because it takes time and the replaced code is less-performant.

To see this in action run the code with options --trace_opt --trace_opt_stats --trace_deopt --trace-inlining

[deoptimize context: cbf30f14679]
[marking addText 0xcbf30fc5ca0 for recompilation, reason: small function, ICs with typeinfo: 1/1 (100%)]
[optimizing: addText / cbf30fc5ca1 - took 0.058, 0.092, 0.000 ms]
Compiled: 1 functions with 42 byte source size in 0.150000ms.
[marking addNumber 0xcbf30fc5ce8 for recompilation, reason: small function, ICs with typeinfo: 1/1 (100%)]
[optimizing: addNumber / cbf30fc5ce9 - took 0.019, 0.033, 0.000 ms]
Compiled: 2 functions with 84 byte source size in 0.202000ms.
[marking  0x2c9408e1b3d0 for recompilation, reason: not much type info but very hot, ICs with typeinfo: 1/12 (8%)]
Inlined addNumber called from .
Inlined addText called from .
[optimizing:  / 2c9408e1b3d1 - took 0.131, 0.229, 0.000 ms]
Compiled: 3 functions with 898 byte source size in 0.562000ms.
time1: 126ms
**** DEOPT:  at bailout #11, address 0x0, frame size 192
[deoptimizing: begin 0x2c9408e1b3d1  @11]
  translating  => node=111, height=32
    0x7fff72081080: [top + 104] <- 0x2c9408e1b4e9 ; [sp + 32] 0x2c9408e1b4e9 <an Object>
    0x7fff72081078: [top + 96] <- 0x58df1704121 <undefined> ; literal
    0x7fff72081070: [top + 88] <- 0x58df1704121 <undefined> ; literal
    0x7fff72081068: [top + 80] <- 0x58df1704121 <undefined> ; literal
    0x7fff72081060: [top + 72] <- 0x58df1704121 <undefined> ; literal
    0x7fff72081058: [top + 64] <- 0x58df1704121 <undefined> ; literal
    0x7fff72081050: [top + 56] <- 0x23522b3122be ; caller's pc
    0x7fff72081048: [top + 48] <- 0x7fff720810b0 ; caller's fp
    0x7fff72081040: [top + 40] <- 0x2c9408e1b0d9; context
    0x7fff72081038: [top + 32] <- 0x2c9408e1b3d1; function
    0x7fff72081030: [top + 24] <- 0x2c9408e1b389 ; [sp + 40] 0x2c9408e1b389 <JS Function add>
    0x7fff72081028: [top + 16] <- 0x2c9408e1b2f9 ; [sp + 48] 0x2c9408e1b2f9 <JS Function addText>
    0x7fff72081020: [top + 8] <- 0x2c9408e1b341 ; [sp + 56] 0x2c9408e1b341 <JS Function addNumber>
    0x7fff72081018: [top + 0] <- 0 ; rbx (smi)
[deoptimizing: end 0x2c9408e1b3d1  => node=111, pc=0x23522b364aa0, state=NO_REGISTERS, alignment=no padding, took 0.076 ms]
[removing optimized code for: ]
[marking add 0x2c9408e1b388 for recompilation, reason: small function, ICs with typeinfo: 1/1 (100%)]
[optimizing: add / 2c9408e1b389 - took 0.013, 0.024, 0.000 ms]
Compiled: 4 functions with 939 byte source size in 0.599000ms.
[marking  0x2c9408e1b3d0 for recompilation, reason: hot and stable, ICs with typeinfo: 2/12 (16%)]
Inlined addNumber called from .
Inlined addText called from .
Inlined add called from .
Inlined add called from .
[optimizing:  / 2c9408e1b3d1 - took 0.100, 0.194, 0.000 ms]
Compiled: 5 functions with 1753 byte source size in 0.893000ms.
time2: 1759ms

The first loop gets deoptimised due to parameter change and runs longer. It cannot be explained by cache hit/miss because there are no read/writes.

Source: http://floitsch.blogspot.in/2012/03/optimizing-for-v8-inlining.html

Answer 2

i think it is about cache memory. in 1st, javascript dont know function 'add' do what. but in 2nd javascript understand that 'addNumber' return sum of x & y and 'addText' return x+''+y