#100DaysOfMERN - Day 7

#100DaysOfMERN - Day 7

marayana's photo
marayana
·

10 min read

✏ What happens When (in Node.js)?

Understanding how my code is processed and executed is key to understanding asynchronous JavaScript. There's a few factors involved:

  • JavaScript's single thread
  • the environment's multi thread
  • call stack and callback queue
  • event loop

I'll include this image again for easier reference:

js-event-loop-felix-gerschau.png (image credit)

In order to make sense of the what-happens-when, I'll write some functions to log stuff to the console, using different methods and conditions for each log (also doing this in Node.js now instead of the browser).

1. A simple log function

function log(){
    console.log('log')
}

2. A function that logs after going through a ~1.5 seconds while loop

function log_loopDelay(){
    let i=0;
    while(i < 1E9) {i++};
    console.log('loopDelay')
}

3. A function that logs after calling setTimeout

function log_setTimeout(t){
    setTimeout(() => console.log(`setTimeout(${t}s)`), t*1000)
}

I'll call setTimeout, but with the time set to 0. Let's check what these print to the console, when I'm calling them in this order:

log_setTimeout(0);
log_loopDelay();
log();

I've already learned yesterday that the difference between the call to setTimeout and the other log functions is that setTimeout is an asynchronous method provided by the environment via an API.

  • it pulls the code inside of it out of JavaScript's single thread and places it in one of its own threads (and in the case of setTimeout, starts a timer)
  • once the timer has run out, the callback (my console.log) will be placed into the callback queue
  • as soon as the call stack is empty, the event loop will pick it up, and push it back onto the call stack.

Checking the console:

loopDelay
log
setTimeout(0s)

The synchronous functions log() and log_loopDelay() will always be executed first, and always in order, there's no way around that. log_setTimeout(0) however, even though the time is set to 0, will be taken out of the flow and go on a trip through the API's thread, the callback queue and the event loop, before it gets executed.

So far, this makes perfect sense. I'll now add another call to setTimeout with the time set to 1s, and change the order a little:

log_setTimeout(1);
log_loopDelay();
log_setTimeout(0);
log();

It's already clear that both setTimeout functions will run after all synchronous code has completed. But in which order?

Result:

loopDelay
log
setTimeout(1s)
setTimeout(0s)

This makes sense, because the loop takes about 1.5 seconds to complete. When setTimeout(0) gets placed into the API thread, the timer of setTimeout(1) is already finished, so the callback of setTimeout(1) is already waiting in the callback queue.

Now I'm changing the time parameter to 5s. Will that make a difference?

log_setTimeout(5);
log_loopDelay();
log_setTimeout(0);
log();

Output:

loopDelay
log
setTimeout(0s)
setTimeout(5s)

It obviously does. When setTimeout(0) gets placed in the API thread after roughly 1.5 seconds, setTimeout(5) is still sitting there, waiting for its timer to complete. setTimeout(0) however goes directly into the callback queue.

✏ Unpredictable behaviour

Changing the time parameter offers a possibility to (roughly) measure how long that while loop actually runs. I can safely say that:

  • it's longer than 1 second (because setTimeout(1) comes before setTimeout(0))
  • it's shorter than 5 seconds (because setTimeout(5) comes after setTimeout(0))

I played with the time parameter for a while to narrow it further down. It turned out that at some point, results get inconsistent. Using setTimeout(1.345) and running the script multiple times, the output randomly changed. Sometimes, setTimeout(0) was logged before setTimeout(1.345), sometimes it was logged after.

I don't really know at this point how to avoid a situation like this, in fact I don't think it's possible, but it's probably good to be aware of it.

✏ Introducing setImmediate()

Node.js has another timer function besides setTimeout. You can use setImmediate if you want to make sure that your code runs (according to the docs) "asynchronous, but as soon as possible ". Adding that to my list of test functions:

4. A function that logs after calling setImmediate

function log_setImmediate(){
    setImmediate(() => console.log('setImmediate'))
}

Now I'm calling the functions in this order (setting the first timeout back to 1s to avoid "race conditions"):

log_setImmediate();
log_setTimeout(1);
log_setTimeout(0);
log_loopDelay();
log();

Prepare for confusion. The output is absolutely not what I would've expected:

loopDelay
log
setTimeout(0s)
setTimeout(1s)
setImmediate

Let's go through the code step by step, here's my theory of what is (or should be) happening:

  • log_setImmediate gets pushed into an API thread and gets immediately placed into the callback queue
  • log_setTimeout(1) gets pushed into an API thread and sits there while its timer is running
  • log_setTimeout(0) gets pushed into an API thread and gets placed into the callback queue after 0 seconds
  • log_loopDelay() gets executed synchronously and blocks the stack for about 1.5s. While the single thread is busy with this operation, the timer of log_setTimeout(1) ends and log_setTimeout(1) gets placed into the callback queue
  • log() gets executed as soon as log_loopDelay()is done

If the above considerations are correct, the order of the logs for the asynchronous calls should be: 

setImmediate
setTimeout(0s)
setTimeout(1s)

I can accept that the order of setImmediate() and setTimeout(0) isn't exactly clear, even the Node.js docs are a bit fuzzy about it:

A setTimeout() callback with a 0ms delay is very similar to setImmediate(). The execution order will depend on various factors, but they will be both run in the next iteration of the event loop.

But how on earth can it happen that setTimeout(1s) comes before setImmediate()?

There's obviously something that I haven't understood. Before I confuse myself and everyone else even more, I'll do some detective work.

Sidenote: After reading this post again, I've realised that I often wrote something like " setTimeout(0) gets pushed back into the callback queue". That is of course not correct, it's the callback that gets pushed back, but I'll leave it like that, hoping it won't lead anyone astray.

✏ Recap

I've learned

  • every piece of synchronous code always gets executed before asynchronous operations, and always in order
  • the order of execution of asynchronous code is often unpredictable, and at this point and with my current knowledge, also totally confusing

✏ Next:

  • figuring out what's wrong with my current theory about async code, particularly setImmediate()

✏ Thanks for reading!

I do my best to thoroughly research the things I learn, but if you find any errors or have additions, please leave a comment below, or @ me on Twitter. If you liked this post, I invite you to subsribe to my newsletter. Until next time 👋

✏ Previous Posts

  • Day 1: Introduction, Node.js, Node.js in the terminal
  • Day 2: npm, node_modules, package.json and package-lock.json, local vs global installation of packages
  • Day 3: Create a React app without create-react-app, Webpack, Babel
  • Day 4: npx and cowsay
  • Day 5: npm vs. npx, npm audit, semantic versioning and update rules
  • Day 6: Call stack, event loop, JavaScript engine, JavaScript runtime
100DaysOfCodeMERN StackBeginner DevelopersJavaScript