Why does setImmediate() run faster than sequential code?

Question

I'm learning how setImmediate() works and came accross an oddity that I fail to find a technical explanation for.

The code is really simple:

setImmediate(function(){
    console.log("third", process.hrtime() );
});

console.log("first", process.hrtime() );
console.log("second", process.hrtime() );

No matter how many times I run this piece of code, the general result is always the same, which is:

The time of the sequential code (between the "first" and "second" prints) appears to take 3 times longer than the time between the "second" and "third" print.

Let me provide 3 example outputs to illustrate this:

Example 1

C:\>node tick.js
first [ 24684, 930636615 ]
second [ 24684, 933914009 ]
third [ 24684, 935172006 ]

first to second takes 0.0033 sec

second to third takes 0.0012 sec (= 3 times faster)

Example 2

C:\>node tick.js
first [ 24706, 107198319 ]
second [ 24706, 110517238 ]
third [ 24706, 111784622 ]

first to second takes 0.0034 sec

second to third takes 0.0012 sec

Example 3

C:\>node tick.js
first [ 24707, 952826072 ]
second [ 24707, 956081565 ]
third [ 24707, 957319084 ]

first to second takes 0.0032 sec

second to third takes 0.0013 sec

Thus?

Considering the fact that setImmediate happens in the next event loop, does anyone have an idea why 2 sequential lines of code ("first and second") take 3 times longer than the lines of code ("second and third") that are seperated on different event-loops through the setImmediate() ?

I am guessing that `setImmediate` is queueing the call to that function and that its execution is happening in the background, which skews the timing. — Lasse V. Karlsen, Aug 25 '18 at 21:05
I suspect there is some V8 optimization with the function call. If I remove the `setImmediate` and just run the three `console.log` statements,the time between the first and second is much larger than the time between the second and third. — Mark, Aug 25 '18 at 21:22

score 2 · Accepted Answer · answered Aug 25 '18 at 23:09

console call is much more costly than the rest, this contaminates the test.

The output of

let time1;
let time2;
let time3;

setImmediate(function(){
  time3 = process.hrtime();

  console.log(time1[1]);
  console.log(time2[1]);
  console.log(time3[1]);
});

time1 = process.hrtime();
time2 = process.hrtime();

is

908101090

908184221

909359846

And the output of

let time1;
let time2;
let time3;

setImmediate(function(){
  time3 = process.hrtime();

  console.log(time1[1]);
  console.log(time2[1]);
  console.log(time3[1]);
});

time1 = process.hrtime();
console.log();
time2 = process.hrtime();
console.log();

is

949882232

954583707

956190379

So this is very specific to Node.js console implementation.

Why does setImmediate() run faster than sequential code?

1 Answers1