Introduction

The event loop enables Node’s non-blocking I/O model, which is the key to Node’s ability to scale under load (as you saw in Unit 4). In this tutorial, you learn more about the event loop, which is comprised of well-defined phases that run – in a particular order – within the event loop.

Specifically, I cover:

  • The event loop’s phases: what they do, the order in which they run, and how your callbacks run within those phases.
  • How to map out the event loop and various ways you can write code that runs in the event loop, including:
    • Task callbacks used with timers. I go into detail about which phases these callbacks run in.
    • Microtask callbacks that run immediately following the phase in which they are created.
  • The Events API, including how to use Node’s event-driven APIs and how to create your own custom events
  • How to use Streams to work with files. I cover when the File Streams events run within the event loop’s phases.

Most of the code you write as a Node developer is callbacks of one type or another. Until you understand which types of callbacks run in which phases, your callbacks will not run predictably or in the order you would like them to.

After completing this tutorial, you should have a good grasp on how the event loop works, and how to write code that works with it. You will also know how to map out the event loop for yourself.

Get the code

As always, the code for every example you see in this unit is in the GitHub repo for the course in the Node.js/Course/Unit-5 directory.

The thread pool/worker pool

It’s tough to talk about Node without discussing the worker pool, which is also referred to as the thread pool. I use these two terms synonymously.

Don’t worry about the worker pool

I want to be very clear about something: Don’t worry about the worker pool. Why? Because:

  • As a Node developer, you don’t have direct access to the worker pool.
  • The thread where your JavaScript code runs is not part of the worker pool.
  • The thread pool is used by libuv internally to improve performance on multi-processor architectures.

So, there’s no reason to worry about the thread pool.

In case you’re worried about the worker pool

If you’re like me, you’re now probably wondering about the worker pool. Here’s a brief overview of a few options you can use to get the worker pool to run your JavaScript code.

I listed them in ascending order of difficulty, with links for your further study.

  • You can use a module from the NPM registry like worker pool or Hamsters.js that allows you to run your JavaScript code on a worker thread. You can also search for “worker pool” at npmjs.com to see what else is available.
  • There is an experimental feature in the Node API called Worker Threads that lets you run JavaScript code on the worker pool (check out this link for what the Node team considers as “experimental”).
  • You can write a C++ extension yourself that allows you to tap into the Node Core, the V8 engine, libuv, and so on. If you want to learn more about that, I recommend you start here.

Okay, we’re done talking about running JavaScript code on the thread pool. Let’s move on to the meat of the course.

Why you need to understand the event loop

Business processes have well defined steps, and mini-steps within those steps. Well-writen software ensures your computer performs those steps, and the mini-steps in between, in the correct order.

Node is asynchronous and circular. At its center is an event loop which loops constantly and with extreme speed, processing callbacks during each phase of that loop. In my experience, when a Node application seems to deliver steps out of order, it’s because the developer didn’t clearly understand the event loop. They thought their code should run in one order, when in fact, it didn’t, creating noise. Can you write Node applications without really understanding the event loop? Sure. But, you will write better Node apps when you understand this important concept.

Event loop phases overview

When I was writing this series, there was only one illustration on the Node.js website: Event Loop Explained. If it’s the only picture on the site, then the Node team must think the event loop concept is important to understand.

I reproduced this illustration to match my mental model of the Node lifecycle, including the phases of the event loop.

Node application lifecycle

I grayed out the Pending, Idle/Prepare, and Close phases of the event loop because these are used internally by Node. Node developers write code that runs only in the mainline, Timers phase, Poll phase, and Check phase, as a microtask.

What exactly does that mean? Let’s find out. First, we’re going to start with a broad overview of the event phases, and then we are going to drill down into the Timers, Poll, and Check phases for more detail.

Before the event loop: node mynodeapp

When you start Node, you provide it the name of a JavaScript file to be processed, such as mynodeapp. Node then processes that script, and hands it to V8 to be contextified, which involves conversion of your JavaScript code to its runnable C++ counterparts, and other stuff that is way beyond the scope of this course (check out this link or this StackOverflow question if you want to learn more).

Your contextified JavaScript code is then run on the Node thread. From now on, I’m going to refer to the thread that runs the V8 engine, the event loop, and all contextified JavaScript (including JavaScript code in the Node API and third party modules) as the Node thread.

Your script’s “mainline” (the user’s JavaScript code; in this case, mynodeapp) runs from top to bottom. If as part of your script’s mainline you make even a single call to some non-blocking code (to create a timer, to read a file, etc), the callback you pass on that call will be run by the event loop on the Node thread (after mainline finishes).

If your code does not make a non-blocking call, the event loop has nothing to do, and the Node process ends. Furthermore, when the event loop runs out of callbacks to execute, it has nothing to do, and, again, the Node process ends.

Callback queue

Each phase has a FIFO queue of callbacks that is executed during that phase. I didn’t show each phase’s callback queue in Figure 1 to save space, so picture the queue inside of every phase.

In general, any logic specific to a particular phase is executed at the beginning of the phase. After that, the callbacks in the queue run until the queue is empty or the system-dependent limit is reached. The Node docs aren’t clear on this.

Microtasks

Microtasks execute immediately following mainline and after every phase of the event loop.

If you’re familiar with the JavaScript event loop, then you should feel right at home with microtasks, which work the same way in Node. If you want a refresher on event loops and microtask queues, check out this link (though I’ll warn you, it’s pretty low-level).

In the land of Node, microtasks are callbacks from:

  • process.nextTick()
  • then() handlers for resolved or rejected Promises

I refer to microtasks and microtask callbacks synonymously when I want to stress that a callback function is running in between phases of the event loop. Yes, I know microtasks callbacks is technically redundant.

Immediately after mainline finishes and after every phase of the event loop, the microtask callbacks run.

In the examples later in this tutorial, you use microtasks callbacks as delimiters to map out the event loop’s phases.

Timers phase

Any expired timer callbacks run during this phase of the event loop.

The two categories of timers are:

An immediate timer is a Node object that runs immediately during the next Check phase. I’ll talk about Immediate timers later in this unit.

A timeout timer is a Node object that runs a callback as soon as possible after the timer expires. You provide the callback and an optional delay parameter (value is in milliseconds) when you create the timer, which defaults to 1ms if you either do not provide a value or if you specify a value of 0.

Once the timer expires, the callback is invoked during the next Timers phase of the event loop. This might be later than the actual timeout value, depending on when the next Timers phase runs.

There are two types of Timeout timers:

  • Interval: which you create with setInterval(). The callback runs once every time the timer expires (after delay ms) and repeats as long as the Node process is alive: (1) unless you call clearInterval() before it runs the first time or (2) until you call clearInterval() after it has run one or more times.

  • Timeout: which you create with setTimeout(). Once the delay has passed, the callback is run once, unless you call clearTimeout() before the callback has a chance to run.

When there are no more expired timer callbacks to run, the event loop runs any microtasks. After running microtasks, the event loop moves to the Pending phase.

Pending phase

Certain system-level callback are executed during this phase. You don’t really need to worry about this phase (and honestly there is not very much information to be found about it), but I wanted you to know it’s there.

Idle and Prepare phase

Apparently, this phase is “only used internally”, so that’s all I’ll say about it. Again, just know it’s there.

Poll phase

I/O callbacks are executed during this phase. You saw those in Units 3 and 4, where the fs.readFile() function call expected you to provide a callback when the I/O operation was complete, in order to pass the file’s contents:

.
.
    fs.readFile(fileName, 'utf8', function(err, fileContents) {
        if (err) throw err;
        logger.debug('File read complete. File contents length: ' + fileContents.length);
.
.
        logger.trace('fs.readFile(): END', startTime);
    });
};

The anonymous callback in the listing above is run during the poll phase.

Normally, if the poll queue is empty, it blocks and waits for any in-flight I/O operations to complete, then execute their callbacks right away. However, if timers are scheduled the poll phase will end. Any microtasks will be run as necessary, and the event loop proceeds to the check phase.

Check phase

This phase is a sort of “post I/O” phase during which only setImmediate() callbacks are executed. This allows you to run code that executes as soon as the poll phase becomes idle.

Once the check phase callback queue is empty, any microtasks run, and the event loop proceeds to the close phase.

Close phase

This phase is executed if a socket or handle is closed suddenly (for example, if a socket’s socket.destroy() method is called), in which case its ‘close’ event is emitted here.

Since this condition is not likely to occur, I’m going to omit this phase from further discussion (since I’m limiting the discussion to the phases in which you will be likely have callbacks executed).

Event loop phases in more detail

Now that you saw an overview of all the phases, let’s take a deeper look at the three phases where callbacks are typically invoked:

  • Timers
  • Poll
  • Check

I’ll show you examples of callbacks that run during each phase. The source code for the examples in this section is in the GitHub repo for the course in the /Course/Unit-5 directory. Common code (for example, logger) is in the Node.js/Course/common directory.

Timers Phase callbacks

During the timers phase, you run callbacks for expired Interval and Timeout timers. Let’s look first at the Interval timers.

setInterval()

If you need a repeating loop on a timer, an Interval timer is the ticket. To create one, use simple code like the following:

Example 1. setInterval()

01 const logger = require('../common/logger');
02 const ITERATIONS_MAX = 5;
03 let iteration = 0;
04 logger.info('START', 'MAINLINE');
05 const timeout = setInterval(() => {
06     logger.info('START: setInterval', 'TIMERS PHASE');
07     if (iteration >= ITERATIONS_MAX) {
08         logger.info('Max interval count exceeded. Goodbye.', 'TIMERS PHASE');
09         // Kill the interval timer
10        clearInterval(timeout);
11     }
12     iteration++;
13     logger.info('END: setInterval', 'TIMERS PHASE');
14 }, 10);
15 logger.info('END', 'MAINLINE');

setInterval() creates a repeating timer that repeats five times and runs no sooner than every 10 milliseconds (the delay is specified on line 14). Each time the timer expires, the callback (lines 6-13) is run until clearInterval() is called (line 10).

The output of example1.js looks like this:

$ node example1
1530377268828:INFO: mainline: START
1530377268830:INFO: mainline: END
1530377268843:INFO: TIMERS PHASE: START: setInterval
1530377268844:INFO: TIMERS PHASE: END: setInterval
1530377268856:INFO: TIMERS PHASE: START: setInterval
1530377268856:INFO: TIMERS PHASE: END: setInterval
1530377268866:INFO: TIMERS PHASE: START: setInterval
1530377268866:INFO: TIMERS PHASE: END: setInterval
1530377268878:INFO: TIMERS PHASE: START: setInterval
1530377268879:INFO: TIMERS PHASE: END: setInterval
1530377268891:INFO: TIMERS PHASE: START: setInterval
1530377268892:INFO: TIMERS PHASE: END: setInterval
1530377268903:INFO: TIMERS PHASE: START: setInterval
1530377268903:INFO: TIMERS PHASE: Max interval count exceeded. Goodbye.
1530377268904:INFO: TIMERS PHASE: END: setInterval
$

In order to clear the timer, you have to keep a reference to the Timeout object that is returned from the setInterval() call and pass that reference to the clearInterval() function (line 10). If you don’t call clearInterval(), the timer will run forever.

setTimeout()

A setTimeout() timer is a one-shot timer. You create one like this (lines 8-10):

Example 2. setTimeout() example showing its timers phase callback

01 const logger = require('../common/logger');
02 const ITERATIONS_MAX = 5;
03 let iteration = 0;
04 logger.info('START', 'MAINLINE');
05 const timeout = setInterval(() => {
06     logger.info('START: setInterval', 'TIMERS PHASE');
07     if (iteration < ITERATIONS_MAX) {
08         setTimeout(() => {
09             logger.info('setInterval.setTimeout', 'TIMERS PHASE');
10         });
11     } else {
12         logger.info('Max interval count exceeded. Goodbye.', 'TIMERS PHASE');
13         clearInterval(timeout);
14     }
15     iteration++;
16     logger.info('END: setInterval', 'TIMERS PHASE');
17 }, 0);
18 logger.info('MAINLINE: END');

Notice I’m building on the previous example. I’m going to do that for each example going forward through Example 6. You will understand why I’m doing that soon enough.

A one-shot timer is boring, so I added it to the code from the setInterval() example. I changed the interval timeout to zero and have not set a delay for the setTimeout() call, so it will expire 1ms after it’s created.

When you run example2.js you see output like this:

$ node example2
1530377605443:INFO: MAINLINE: START
1530377605446:INFO: MAINLINE: END
1530377605447:INFO: TIMERS PHASE: START: setInterval
1530377605447:INFO: TIMERS PHASE: END: setInterval
1530377605449:INFO: TIMERS PHASE: setInterval.setTimeout
1530377605449:INFO: TIMERS PHASE: START: setInterval
1530377605449:INFO: TIMERS PHASE: END: setInterval
1530377605450:INFO: TIMERS PHASE: setInterval.setTimeout
1530377605450:INFO: TIMERS PHASE: START: setInterval
1530377605450:INFO: TIMERS PHASE: END: setInterval
1530377605452:INFO: TIMERS PHASE: setInterval.setTimeout
1530377605452:INFO: TIMERS PHASE: START: setInterval
1530377605452:INFO: TIMERS PHASE: END: setInterval
1530377605454:INFO: TIMERS PHASE: setInterval.setTimeout
1530377605454:INFO: TIMERS PHASE: START: setInterval
1530377605454:INFO: TIMERS PHASE: END: setInterval
1530377605455:INFO: TIMERS PHASE: setInterval.setTimeout
1530377605455:INFO: TIMERS PHASE: START: setInterval
1530377605455:INFO: TIMERS PHASE: Max interval count exceeded. Goodbye.
1530377605456:INFO: TIMERS PHASE: END: setInterval
$

What effectively happens here is that you’ve set up an interval timer that runs as fast as possible (on a 1ms timeout). When its callback runs, it creates another one-shot timer that expires 1ms after it is created.

You have the beginnings of an event loop map. To build on it, add some I/O, which means poll phase callbacks!

Poll phase callbacks

All non-blocking I/O request callbacks run during the poll phase. Below is a fs.readdir() example of a poll phase callback:

Example 3. fs.readdir() example showing its poll phase callback

 01 const fs = require('fs');
 02 const logger = require('../common/logger');
 03 const ITERATIONS_MAX = 3;
 04 let iteration = 0;
 05 logger.info('START', 'MAINLINE');
 06 const timeout = setInterval(() => {
 07     logger.info('START: setInterval', 'TIMERS PHASE');
 08     if (iteration < ITERATIONS_MAX) {
 09         setTimeout(() => {
 10             logger.info('TIMERS PHASE', 'setInterval.setTimeout');
 11         });
 12         fs.readdir('../data', (err, files) => {
 13             if (err) throw err;
 14             logger.info('fs.readdir() callback: Directory contains: ' + files.length + ' files', 'POLL PHASE');
 15         });
 16     } else {
 17         logger.info('Max interval count exceeded. Goodbye.', 'TIMERS PHASE');
 18         clearInterval(timeout);
 19     }
 20     iteration++;
 21     logger.info('END: setInterval', 'TIMERS PHASE');
 22 }, 0);
 23 logger.info('END', 'MAINLINE');

The non-blocking I/O call to fs.readdir() starts on line 12, and its callback executes during the poll phase after the I/O operation is complete.

The output of example3.js looks like this:

$ node example3
1530377719473:INFO: MAINLINE: START
1530377719475:INFO: MAINLINE: END
1530377719477:INFO: TIMERS PHASE: START: setInterval
1530377719477:INFO: TIMERS PHASE: END: setInterval
1530377719477:INFO: POLL PHASE: fs.readdir() callback: Directory contains: 7 files
1530377719477:INFO: setInterval.setTimeout: TIMERS PHASE
1530377719478:INFO: TIMERS PHASE: START: setInterval
1530377719478:INFO: TIMERS PHASE: END: setInterval
1530377719478:INFO: POLL PHASE: fs.readdir() callback: Directory contains: 7 files
1530377719479:INFO: setInterval.setTimeout: TIMERS PHASE
1530377719479:INFO: TIMERS PHASE: START: setInterval
1530377719479:INFO: TIMERS PHASE: END: setInterval
1530377719480:INFO: POLL PHASE: fs.readdir() callback: Directory contains: 7 files
1530377719481:INFO: setInterval.setTimeout: TIMERS PHASE
1530377719481:INFO: TIMERS PHASE: START: setInterval
1530377719481:INFO: TIMERS PHASE: Max interval count exceeded. Goodbye.
1530377719482:INFO: TIMERS PHASE: END: setInterval
$

To limit the amount of output, I reduced the number of iterations of the setInterval() timer callback to three (see Example 3, line 3).

If there are any microtasks scheduled during a poll phase callback, they are executed immediately on MacOS (rather than waiting for the poll phase to complete before running microtasks). You’ll see more of this in the Microtask callbacks section later in this unit.

When the poll phase callback queue is empty, the poll phase becomes idle.

If no timers are scheduled, the poll phase waits for any pending I/O requests to complete, then executes their callbacks immediately.

If there are any timers scheduled, the event loop proceeds to the check phase.

Check phase callbacks

Callbacks for Immediate timers are run during the check phase. The following example shows a check phase callback; again, this example builds on the previous one.

Example 4. setImmediate() example showing its check phase callback

 01 const fs = require('fs');
 02 const logger = require('../common/logger');
 03 const ITERATIONS_MAX = 3;
 04 let iteration = 0;
 05 logger.info('START', 'MAINLINE');
 06 const timeout = setInterval(() => {
 07     logger.info('START: setInterval', 'TIMERS PHASE');
 08     if (iteration < ITERATIONS_MAX) {
 09         setTimeout(() => {
 10             logger.info('setInterval.setTimeout', 'TIMERS PHASE');
 11         });
 12         fs.readdir('../data', (err, files) => {
 13             if (err) throw err;
 14             logger.info('fs.readdir() callback: Directory contains: ' + files.length + ' files', 'POLL PHASE');
 15         });
 16         setImmediate(() => {
 17             logger.info('setInterval.setImmediate', 'CHECK PHASE');
 18         });
 19     } else {
 20         logger.info('Max interval count exceeded. Goodbye.', 'TIMERS PHASE');
 21         clearInterval(timeout);
 22     }
 23     iteration++;
 24     logger.info('END: setInterval', 'TIMERS PHASE');
 25 }, 0);
 26 logger.info('END', 'MAINLINE');

The Immediate timer is created on line 16 during the timers phase (because line 16 executes as part of the setInterval() callback), but its callback executes during the check phase.

The output of example4.js looks like this:

$ node example4
1530377921982:INFO: MAINLINE: START
1530377921985:INFO: MAINLINE: END
1530377921986:INFO: TIMERS PHASE: START: setInterval
1530377921986:INFO: TIMERS PHASE: END: setInterval
1530377921987:INFO: POLL PHASE: fs.readdir() callback: Directory contains: 7 files
1530377921987:INFO: CHECK PHASE: setInterval.setImmediate
1530377921989:INFO: TIMERS PHASE: setInterval.setTimeout
1530377921989:INFO: TIMERS PHASE: START: setInterval
1530377921989:INFO: TIMERS PHASE: END: setInterval
1530377921989:INFO: CHECK PHASE: setInterval.setImmediate
1530377921989:INFO: POLL PHASE: fs.readdir() callback: Directory contains: 7 files
1530377921990:INFO: TIMERS PHASE: setInterval.setTimeout
1530377921991:INFO: TIMERS PHASE: START: setInterval
1530377921991:INFO: TIMERS PHASE: END: setInterval
1530377921991:INFO: CHECK PHASE: setInterval.setImmediate
1530377921991:INFO: POLL PHASE: fs.readdir() callback: Directory contains: 7 files
1530377921992:INFO: TIMERS PHASE: setInterval.setTimeout
1530377921992:INFO: TIMERS PHASE: START: setInterval
1530377921992:INFO: TIMERS PHASE: Max interval count exceeded. Goodbye.
1530377921993:INFO: TIMERS PHASE: END: setInterval
$

To limit the amount of output, I reduced the number of iterations of the setInterval() timer callback to three (see Example 4, line 3).

Microtask callbacks

Microtasks are callbacks provided to process.nextTick() or Promise.resolve().then() that are made during mainline or a phase of the event loop. When they are scheduled, they go into the microtask callback queue that is executed after that phase completes.

Below are examples of process.nextTick() and Promise.resolve().then():

process.nextTick()

In mapping out the event loop, you can use a microtask as a sort of “phase delimiter”. The following process.nextTick() example shows how microtask callbacks act as phase delimiters**

Example5. process.nextTick() example showing how microtask callbacks act as phase delimiters

01 const fs = require('fs');
02 const logger = require('../common/logger');
03 const ITERATIONS_MAX = 2;
04 let iteration = 0;
05 process.nextTick(() => {
06     logger.info('process.nextTick', 'MAINLINE MICROTASK');
07 });
08 logger.info('START', 'MAINLINE');
09 const timeout = setInterval(() => {
10     logger.info('START iteration ' + iteration + ': setInterval', 'TIMERS PHASE');
11
12     if (iteration < ITERATIONS_MAX) {
13         setTimeout((iteration) => {
14             logger.info('TIMER EXPIRED (from iteration ' + iteration + '): setInterval.setTimeout', 'TIMERS PHASE');
15             process.nextTick(() => {
16                 logger.info('setInterval.setTimeout.process.nextTick', 'TIMERS PHASE MICROTASK');
17             });
18         }, 0, iteration);
19         fs.readdir('../data', (err, files) => {
20             logger.info('fs.readdir() callback: Directory contains: ' + files.length + ' files', 'POLL PHASE');
21             process.nextTick(() => {
22                 logger.info('setInterval.fs.readdir.process.nextTick', 'POLL PHASE MICROTASK');
23             });
24         });
25         setImmediate(() => {
26             logger.info('setInterval.setImmediate', 'CHECK PHASE');
27             process.nextTick(() => {
28                 logger.info('setInterval.setTimeout.process.nextTick', 'CHECK PHASE MICROTASK');
29             });
30         });
31     } else {
32         logger.info('Max interval count exceeded. Goodbye.', 'TIMERS PHASE');
33         clearInterval(timeout);
34     }
35     logger.info('END iteration ' + iteration + ': setInterval', 'TIMERS PHASE');
36     iteration++;
37 }, 0);
38 logger.info('MAINLINE: END');

During each callback there is a process.nextTick() call that flags the end of the phase in which that callback runs.

For example, the setTimeout() callback that starts on line 14 runs during the timers phase, and schedules a microtask on line 16, which consists of a single logger() call.

Similarly, there are process.nextTick() delimiters for all of the other phases too (including mainline).

The output of Example 5 looks like this:

$ node example5
1530401857782:INFO: MAINLINE: START
1530401857784:INFO: MAINLINE: END
1530401857785:INFO: MAINLINE MICROTASK: process.nextTick
1530401857786:INFO: TIMERS PHASE: START iteration 0: setInterval
1530401857786:INFO: TIMERS PHASE: END iteration 0: setInterval
1530401857787:INFO: POLL PHASE: fs.readdir() callback: Directory contains: 8 files
1530401857787:INFO: POLL PHASE MICROTASK: setInterval.fs.readdir.process.nextTick
1530401857787:INFO: POLL PHASE: fs.readdir() callback: Directory contains: 8 files
1530401857787:INFO: POLL PHASE MICROTASK: setInterval.fs.readdir.process.nextTick
1530401857787:INFO: CHECK PHASE: setInterval.setImmediate
1530401857787:INFO: CHECK PHASE MICROTASK: setInterval.setTimeout.process.nextTick
1530401857787:INFO: TIMERS PHASE: TIMER EXPIRED (from iteration 0): setInterval.setTimeout
1530401857787:INFO: TIMERS PHASE: START iteration 1: setInterval
1530401857788:INFO: TIMERS PHASE: END iteration 1: setInterval
1530401857788:INFO: TIMERS PHASE MICROTASK: setInterval.setTimeout.process.nextTick
1530401857788:INFO: POLL PHASE: fs.readdir() callback: Directory contains: 8 files
1530401857788:INFO: POLL PHASE MICROTASK: setInterval.fs.readdir.process.nextTick
1530401857788:INFO: POLL PHASE: fs.readdir() callback: Directory contains: 8 files
1530401857788:INFO: POLL PHASE MICROTASK: setInterval.fs.readdir.process.nextTick
1530401857788:INFO: CHECK PHASE: setInterval.setImmediate
1530401857788:INFO: CHECK PHASE MICROTASK: setInterval.setTimeout.process.nextTick
1530401857788:INFO: TIMERS PHASE: TIMER EXPIRED (from iteration 1): setInterval.setTimeout
1530401857788:INFO: TIMERS PHASE: START iteration 2: setInterval
1530401857788:INFO: TIMERS PHASE: Max interval count exceeded. Goodbye.
1530401857788:INFO: TIMERS PHASE: END iteration 2: setInterval
1530401857788:INFO: TIMERS PHASE MICROTASK: setInterval.setTimeout.process.nextTick
$

First, mainline runs, followed by its microtask. Then the timers phase, the poll phase, check phase, and so on. To limit the amount of output, I limited the number of iterations to two (see Example 5, line 3), which is enough to show the pattern.

After each event loop phase, there is a process.nextTick() delimiter callback to mark the end of that phase. Since you know the phase delimiter callback MUST run after that phase, whatever output follows MUST be coming from a subsequent phase of the event loop.

Promise.resolve().then()

A resolved promise’s then() callback is executed as a microtask just like process.nextTick(). Although, if both are in the same microtask queue, the callback for process.nextTick() will be executed first.

For example, if a promise is resolved during the timers phase and has a bound then() handler function, it will run immediately following the timers phase before the event loop continues.

Consider Example 6, which is a Promise.resolve().then() example showing how microtask callbacks act as phase delimiters

Example 6. Promise.resolve().then() example showing how microtask callbacks act as phase delimiters

01 const fs = require('fs');
02 const logger = require('../common/logger');
03 const ITERATIONS_MAX = 2;
04 let iteration = 0;
05 Promise.resolve().then(() => {
06     // Microtask callback runs AFTER mainline, even though the code is here
07     logger.info('Promise.resolve.then', 'MAINLINE MICROTASK');
08 });
09 logger.info('START', 'MAINLINE');
10 const timeout = setInterval(() => {
11     logger.info('START iteration ' + iteration + ': setInterval', 'TIMERS PHASE');
12     if (iteration < ITERATIONS_MAX) {
13         setTimeout((iteration) => {
14             logger.info('TIMER EXPIRED (from iteration ' + iteration + '): setInterval.setTimeout', 'TIMERS PHASE');
15             Promise.resolve().then(() => {
16                 logger.info('setInterval.setTimeout.Promise.resolve.then', 'TIMERS PHASE MICROTASK');
17             });
18         }, 0, iteration);
19         fs.readdir('../data', (err, files) => {
20             if (err) throw err;
21             logger.info('fs.readdir() callback: Directory contains: ' + files.length + ' files', 'POLL PHASE');
22             Promise.resolve().then(() => {
23                 logger.info('setInterval.fs.readdir.Promise.resolve.then', 'POLL PHASE MICROTASK');
24             });
25         });
26         setImmediate(() => {
27             logger.info('setInterval.setImmediate', 'CHECK PHASE');
28             Promise.resolve().then(() => {
29                 logger.info('setInterval.setTimeout.Promise.resolve.then', 'CHECK PHASE MICROTASK');
30             });
31         });
32     } else {
33         logger.info('Max interval count exceeded. Goodbye.', 'TIMERS PHASE');
34         clearInterval(timeout);
35     }
36     logger.info('END iteration ' + iteration + ': setInterval', 'TIMERS PHASE');
37     iteration++;
38 }, 0);
39 logger.info('END', 'MAINLINE');

Example 6 is just like Example 5 except that it uses resolved promise handlers as phase delimiters. The output looks like this:

$ node example6
1530402106144:INFO: MAINLINE: START
1530402106146:INFO: MAINLINE: END
1530402106147:INFO: MAINLINE MICROTASK: Promise.resolve.then
1530402106148:INFO: TIMERS PHASE: START iteration 0: setInterval
1530402106148:INFO: TIMERS PHASE: END iteration 0: setInterval
1530402106149:INFO: POLL PHASE: fs.readdir() callback: Directory contains: 8 files
1530402106149:INFO: POLL PHASE MICROTASK: setInterval.fs.readdir.Promise.resolve.then
1530402106149:INFO: CHECK PHASE: setInterval.setImmediate
1530402106149:INFO: CHECK PHASE MICROTASK: setInterval.setTimeout.Promise.resolve.then
1530402106151:INFO: TIMERS PHASE: TIMER EXPIRED (from iteration 0): setInterval.setTimeout
1530402106151:INFO: TIMERS PHASE: START iteration 1: setInterval
1530402106151:INFO: TIMERS PHASE: END iteration 1: setInterval
1530402106151:INFO: TIMERS PHASE MICROTASK: setInterval.setTimeout.Promise.resolve.then
1530402106151:INFO: POLL PHASE: fs.readdir() callback: Directory contains: 8 files
1530402106151:INFO: POLL PHASE MICROTASK: setInterval.fs.readdir.Promise.resolve.then
1530402106151:INFO: CHECK PHASE: setInterval.setImmediate
1530402106151:INFO: CHECK PHASE MICROTASK: setInterval.setTimeout.Promise.resolve.then
1530402106153:INFO: TIMERS PHASE: TIMER EXPIRED (from iteration 1): setInterval.setTimeout
1530402106153:INFO: TIMERS PHASE: START iteration 2: setInterval
1530402106153:INFO: TIMERS PHASE: Max interval count exceeded. Goodbye.
1530402106153:INFO: TIMERS PHASE: END iteration 2: setInterval
1530402106153:INFO: TIMERS PHASE MICROTASK: setInterval.setTimeout.Promise.resolve.then
$

As you would expect, the output looks much like the output for Example 5. I wanted to show you that both types of microtasks run immediately following the phase in which they were scheduled.

Events

An event is something of significance that happens in an application. An event-driven runtime like Node emits events in certain places and responds to them in others.

It’s super easy to create your own custom event, as Example 7 shows:

Example 7. Using a custom Event: simpleEvent

01   // The Node EventEmitter
02   const EventEmitter = require('events');
03   // Create an instance of EventEmitter
04   const eventEmitter = new EventEmitter();
05
06   // The common logger
07   const logger = require('../common/logger');
08
09   logger.info('START', 'MAINLINE');
10
11   logger.info('Registering simpleEvent handler', 'MAINLINE');
12   eventEmitter.on('simpleEvent', (eventName, message, source, timestamp) => {
13       logger.info('Received event: ' + timestamp + ': ' + source + ':[' + eventName + ']: ' + message, 'EventEmitter.on()');
14   });
15
16   // Get the current time
17   let hrtime = process.hrtime();
18   eventEmitter.emit('simpleEvent', 'simpleEvent', 'Custom event says what?', 'MAINLINE', (hrtime[0] * 1e9 + hrtime[1] ) / 1e6);
19
20   logger.info('END', 'MAINLINE');

First, you need a reference to the events module (line 2), and an instance of the EventEmitter object (line 4).

Then, you register an event listener Function using the EventEmitter.on() function (line 12). When the simpleEvent event is emitted, the listener function will be invoked and log a message (line 13).

Then, you emit the simpleEvent, along with some additional parameters (line 18), which need to match the argument list of the handler.

When you run it, the output looks like this:

$ node example7
1530379926998:INFO: MAINLINE: START
1530379927000:INFO: MAINLINE: Registering simpleEvent handler
1530379927000:INFO: EventEmitter.on(): Received event: 553491474.966337: MAINLINE:[simpleEvent]: Custom event says what?
1530379927000:INFO: MAINLINE: END
$

That was pretty simple. See? I told you it was super easy.

However, something bugs me about this code. I’d really like to clean up the following:

  • Repeated string literals: move them into a common module
  • Timestamp function: move this function into simple-utils because this looks like something you might want to reuse
  • The event attributes (eventName, message, and so forth) can be moved into a common module and reused as an object
  • Replace the console logger (logger) with an event-based logger with the same interface for backward-compatibility
  • Create an immediately invocable function expression (IIFE) called mainline that contains the mainline code so there’s no doubt where mainline is located

The refactored code looks like this:

Example 8. Refactored Example 7 code

01 const EventEmitter = require('events');
02 const eventEmitter = new EventEmitter();
03
04 // EventInfo module
05 const { EventInfo } = require('../common/event-info');
06 // Event Logger module
07 const logger = require('../common/event-logger');
08 // Simple utilities module
09 const simpleUtils = require('../common/simple-utils');
10
11 // Constants (from constants module)
12 const { MAINLINE, START, END } = require('../common/constants');
13
14 // The custom event name
15 const EVENT_NAME = 'simpleEvent';
16
17 /**
18  * The mainline function.
19  */
20 (function mainline() {
21
22     logger.info(START, MAINLINE);
23
24     logger.info('Registering ' + EVENT_NAME + ' handler', MAINLINE);
25     eventEmitter.on(EVENT_NAME, (eventInfo) => {
26         logger.info('Received event: ' + eventInfo.toString(), 'EventEmitter.on()');
27     });
28     // Emit the event
29     eventEmitter.emit(EVENT_NAME, new EventInfo(EVENT_NAME, 'Custom event says what?', MAINLINE, simpleUtils.hrtimeToMillis(process.hrtime())));
30
31     logger.info(END, MAINLINE);
32
33 })();

Go ahead, study it, and run it for yourself (there will be a quiz later).

The output looks like this:

$ node example8
553643510.792406: MAINLINE:[INFO]: START
553643510.975569: MAINLINE:[INFO]: Registering simpleEvent handler
553643511.05733: EventEmitter.on():[INFO]: Received event: 553643510.994694: MAINLINE:[simpleEvent]: Custom event says what?
553643511.060924: MAINLINE:[INFO]: END

The output is very similar to the output for the previous example, with the exception of the timestamp, which is now the milliseconds value from process.hrtime(), rather than the millis since the epoch.

I have addressed all of my concerns:

  • Repeated string literals (lines 12, 22, 24, 29, 31): move into a common module
  • Timestamp function (lines 9, 29): move into simple-utils (this looks like something you might want to reuse)
  • The event attributes (eventName, message, and so forth) can be moved into a common module and reused as the EventInfo object – lines 5, 29
  • Replace the console logger (logger) with an event-based logger with the same interface – lines 7, 22, 24, 26, 31
  • Create an immediately invocable function expression (IIFE) called mainline that contains the mainline code – lines 20 – 33

You should study Example 8, as well as all the refactored code I moved into modules. There will be some questions on the quiz about the code (including the modules it uses), and how it works.

If you want to learn more about Events, check out the Node docs.

Now that you’ve studied Example 8, you should have a feeling for how Node events work. It’s time to see how events work with the Streams API.

Streams

A Stream is an EventEmitter used to process things that are “streamable.” This includes files and HTTP connections, for example.

The examples are getting too large to show them in their entirety, so I will show them in pieces and describe each piece as I show it. The line numbers in each code snippet from example9.js that follows are only relevant for that snippet and the explanatory text that follows.

Now have a look at Example 9, starting with its mainline():

Example 9. The mainline() function from example9.js

01 /**
02  * The mainline function - IIFE
03  */
04 (function mainline() {
05     // Create the ReadableStream
06     const readableStream = fs.createReadStream(appSettings.inputFileName, 'utf8');
07     // Register event listeners for the input file
08     registerReadableStreamEventListeners(readableStream);
09     // The output file (WritableStream)
10     const writableStream = fs.createWriteStream(appSettings.outputFileName, 'utf8');
11     // Register event listeners for the output file
12     registerWritableStreamEventListeners(writableStream, readableStream);
13 })();

When you run node example9.js, the mainline() function is executed as an immediately invocable function expression (IIFE), as you saw in Example 8. I use that pattern for all input scripts from this point forward in the course.

It does four things:

  1. Line 6: Creates a ReadableStream using the specified settings (from a new module called appSettings, also a pattern I follow from now on).
  2. Line 8: Registers event listeners for the ReadableStream
  3. Line 10: Creates a WritableStream using the specified settings from the appSettings module.
  4. Line 12: Registers event listeners for the WritableStream

Take a look at the code that registers event listeners for the ReadableStream:

Example 9. The registerReadableStreamEventListeners() function from example9.js

01 function registerReadableStreamEventListeners(readableStream) {
02     readableStream.on('open', (fd) => {
03         logger.info('open event received, file descriptor: ' + fd, 'ReadableStream.on(open).callback');
04     });
05     readableStream.on('data', (chunk) => {
06         logger.info('data event received: chunk size: ' + chunk.length, 'ReadableStream.on(data).callback');
07     });
08     readableStream.on('error', (err) => {
09         logger.info('Something has gone horribly wrong: ' + err.message, 'ReadableStream.on(error).callback');
10     });
11     readableStream.on('close', () => {
12         logger.info('close event received', 'ReadableStream.on(close).callback');
13     });
14 }

This code registers four event listener callbacks:

  1. Line 2: the open event, which is emitted when the file that backs the stream is opened. It uses fd, which is the integer file descriptor
  2. Line 5: the data event, emitted whenever a “chunk” of data (64kb on my Mac, ymmv) has been read. it uses chunk, which denotes the chunk of data that was read
  3. Line 8: the ‘error’ event, emitted when an error occurs (you should always provide an error handler unless you have a really good reason not to). It uses err – the Error object
  4. Line 11: the close event, emitted when the stream has been closed. It uses no arguments.

Now have a look at the event listeners for the WritableStream:

Example 9. The registerWritableStreamEventListeners() function from example9.js

01 function registerWritableStreamEventListeners(writableStream, readableStream) {
02     writableStream.on('open', (fd) => {
03         logger.info('open event received, file descriptor: ' + fd, 'WritableStream.on(open).callback');
04         // Connect the readableStream to the writableStream
05         readableStream.pipe(writableStream);
06     });
07     writableStream.on('pipe', (src) => {
08         logger.info('pipe event received, let the data flow!', 'WritableStream.on(pipe).callback');
09     });
10     writableStream.on('error', (err) => {
11         logger.info('Something has gone horribly wrong: ' + err.message, 'WritableStream.on(error).callback');
12     });
13     writableStream.on('close', () => {
14         logger.info('close event received', 'WritableStream.on(close).callback');
15     });
16 }

The registerWritableStreamEventListeners() function does pretty much what its counterpart does, with two differences. Can you spot them?

On line 5, in the open event handler, this code connects the ReadbleStream directly to the WritableStream via the ReadableStream.pipe() function, which makes a copy of the input file. The second difference is this code registers a handler for the pipe event and logs a message saying the event has been received.

I’ll leave the rest of the code for you to study as an exercise. The only addition to the supporting modules, which you’ve already seen in Example 8, is the use of an application settings module called appSettings that provides a way to centralize those settings, rather than hardcode them in the Node input script as I’ve been doing up to this point.

Okay, when you run example9.js, the output looks like this:

$ node example9
527160650.291643: ReadableStream.on(open).callback:[INFO]: open event received, file descriptor: 13
527160650.956652: WritableStream.on(open).callback:[INFO]: open event received, file descriptor: 14
527160651.230392: WritableStream.on(pipe).callback:[INFO]: pipe event received, let the data flow!
527160651.686702: ReadableStream.on(data).callback:[INFO]: data event received: chunk size: 65536
527160653.008806: ReadableStream.on(data).callback:[INFO]: data event received: chunk size: 3009
527160654.401119: ReadableStream.on(close).callback:[INFO]: close event received
527160654.459593: WritableStream.on(close).callback:[INFO]: close event received

That covers the intro to Streams. I placed links to resources throughout this unit. I encourage you to follow them to the Node docs to deepen your understanding of the concepts.

Mapping the event loop using streams

As you saw in Examples 5 and 6, you can tap into much of Node’s plumbing to see and understand what the event loop is doing.

Now do that using the Stream API, too. Example 10 uses a modified version of Example 9 (without the WritableStream stuff) to map out the event loop. When you run example10.js the output looks like this:

Example 10. Use the Stream API to map out the event loop as it reads the input stream

$ node example10
528214326.789891: setInterval:[DEBUG]: TIMERS PHASE: GREETINGS
528214327.081744: ReadableStream.on(open).callback(process.nextTick):[DEBUG]: TIMERS PHASE DONE
528214327.303483: ReadableStream.on(open).callback:[INFO]: open event received
528214331.93755: ReadableStream.on(open).callback(process.nextTick):[DEBUG]: POLL PHASE DONE
528214332.141504: ReadableStream.on(ready).callback(setImmediate):[DEBUG]: CHECK PHASE: GREETINGS
528214332.176539: ReadableStream.on(ready).callback(setImmediate.process.nextTick):[DEBUG]: CHECK PHASE DONE
528214332.205251: setInterval:[DEBUG]: TIMERS PHASE: GREETINGS
528214332.245918: ReadableStream.on(ready).callback(setTimeout):[DEBUG]: TIMER EXPIRED
528214332.261408: ReadableStream.on(open).callback(process.nextTick):[DEBUG]: TIMERS PHASE DONE
528214332.28407: ReadableStream.on(ready).callback(setTimeout.process.nextTick):[DEBUG]: TIMERS PHASE DONE
528214332.795419: ReadableStream.on(data).callback:[INFO]: data event received: chunk size: 65536
528214332.870552: ReadableStream.on(data).callback(process.nextTick):[DEBUG]: POLL PHASE DONE
528214333.019428: ReadableStream.on(data).callback(setImmediate):[DEBUG]: CHECK PHASE: GREETINGS
528214333.046891: ReadableStream.on(data).callback(setImmediate.process.nextTick):[DEBUG]: CHECK PHASE DONE
528214333.057797: setInterval:[DEBUG]: TIMERS PHASE: GREETINGS
528214333.089672: ReadableStream.on(data).callback(setTimeout):[DEBUG]: TIMER EXPIRED
528214333.101422: ReadableStream.on(open).callback(process.nextTick):[DEBUG]: TIMERS PHASE DONE
528214333.117819: ReadableStream.on(data).callback(setTimeout.process.nextTick):[DEBUG]: TIMERS PHASE DONE
528214333.161942: ReadableStream.on(data).callback:[INFO]: data event received: chunk size: 3009
528214333.181389: ReadableStream.on(data).callback(process.nextTick):[DEBUG]: POLL PHASE DONE
528214333.228088: ReadableStream.on(data).callback(setImmediate):[DEBUG]: CHECK PHASE: GREETINGS
528214333.235674: ReadableStream.on(data).callback(setImmediate.process.nextTick):[DEBUG]: CHECK PHASE DONE
528214333.770969: ReadableStream.on(close).callback:[INFO]: close event received
528214336.751145: ReadableStream.on(close).callback(process.nextTick):[DEBUG]: POLL PHASE DONE
528214336.790267: ReadableStream.on(close).callback(setImmediate):[DEBUG]: CHECK PHASE: GREETINGS
528214336.819611: ReadableStream.on(close).callback(setImmediate.process.nextTick):[DEBUG]: CHECK PHASE DONE
528214336.832176: ReadableStream.on(data).callback(setTimeout):[DEBUG]: TIMER EXPIRED
528214336.858322: ReadableStream.on(close).callback(setTimeout):[DEBUG]: TIMER EXPIRED
528214336.873914: ReadableStream.on(data).callback(setTimeout.process.nextTick):[DEBUG]: TIMERS PHASE DONE
528214336.889914: ReadableStream.on(close).callback(setTimeout.process.nextTick):[DEBUG]: TIMERS PHASE DONE

Can you spot the phases and when they run? How about the delimiters?

Play around with example10.js for yourself and get a feeling for how the event loop works with Streams. There will be questions on the quiz related to Streams and event loop mapping.

Passing arguments to timers

I’ll wrap up this unit of the tutorial by showing you how to pass arguments to the various timer functions, since you’ll have the need to do this from time to time. This will come in handy in later units.

I’ve put together an example that shows how to pass arguments to the following timer functions (I’m including process.nextTick() as well, even though it’s not a timer function). The source file is example11.js, which you can check out for yourself. It’s a bit long to include in its entirety, so I’ll cover it piecemeal.

setInterval() timer

The following code shows you how to pass arguments to setInterval():

01 const timeout = setInterval((startTime) => {
02     logger.info('START iteration ' + iteration + ': setInterval', 'TIMERS PHASE');
03
04     // Run for about 10 ms
05     if (Date.now() < startTime + 10) {
06 .
07 .
08     } else {
09         logger.info('Max interval count exceeded. Goodbye.', 'TIMERS PHASE');
10         // Kill the interval timer
11         clearInterval(timeout);
12     }
13     logger.info('END iteration ' + iteration + ': setInterval', 'TIMERS PHASE');
14     iteration++;
15 }, 0, Date.now());

The interval timer is created on line 1, and its argument list provided on line 15, which consists of: (1) the delay (0ms), and (2) the current time in milliseconds (from Date.now()). The current time is passed to the callback as the startTime parameter on line 1, which the callback uses to help determine when to call clearInterval() (line 11).

setTimeout() timer

The following code shows you how to pass arguments to setTimeout()

01 const timeout = setInterval((startTime) => {
02     logger.info('START iteration ' + iteration + ': setInterval', 'TIMERS PHASE');
03
04     // Run for about 10 ms
05     if (Date.now() < startTime + 10) {
06         setTimeout((currentIteration) => {
07             logger.info('TIMER EXPIRED (from iteration ' + currentIteration + '): setInterval.setTimeout', 'TIMERS PHASE');
08             process.nextTick(() => {
09                 logger.info('setInterval.setTimeout.process.nextTick', 'TIMERS PHASE MICROTASK');
10             });
11         }, 0, iteration);
12 .
13 .
14     logger.info('END iteration ' + iteration + ': setInterval', 'TIMERS PHASE');
15
16     iteration++;
17 }, 0, Date.now());

setTimeout() is called on line 6, and its argument list is provided on line 11, which consists of the (1) delay (0ms), and (2) the current iteration value. The current iteration is passed when the timer is created, creating a closure, so that when the argument is passed when setTimeout()‘s callback is run, it can report what iteration the interval loop was on when it was scheduled.

setImmediate() timer

You can also pass multiple arguments to any of these timer functions, as I’ll show with setImmediate():

01 const timeout = setInterval((startTime) => {
02     logger.info('START iteration ' + iteration + ': setInterval', 'TIMERS PHASE');
03
04     // Run for about 10 ms
05     if (Date.now() < startTime + 10) {
06 .
07 .
08         setImmediate((startTime, currentIteration) => {
09             logger.info('Callback executed (scheduled during iteration ' + currentIteration + '): setInterval.setImmediate', 'CHECK PHASE');
10             logger.info('Elapsed time: ' + (Date.now() - startTime) + 'ms', 'CHECK PHASE');
11             process.nextTick((startTime) => {
12                 logger.info('setInterval.setTimeout.process.nextTick', 'CHECK PHASE MICROTASK');
13                 logger.info('Elapsed time: ' + (Date.now() - startTime) + 'ms', 'CHECK PHASE');
14             }, startTime);
15         }, startTime, iteration);
16     } else {
17 .
18 .
19     iteration++;
20 }, 0, Date.now());
21
22 logger.info('END', 'mainline');

The immediate timer is created on line 8, and its argument list is passed on line 15, which consists of (1) the startTime and (2) iteration (that is, the current iteration). Again, when the timer is created, the argument values become part of the closure for the callback so that when it is invoked it gets the values of the variable when the closure was created.

process.nextTick() timer

You can also pass an arbitrary number of arguments to process.nextTick() as well. I’ll refer you to the previous listing. On line 11, the process.nextTick() call is made and the startTime value is passed on line 14. When the callback is invoked, the startTime is passed, and the callback uses that value to create an elapsed time.

Conclusion to Unit 5

In this unit we took a closer look at the event loop. You learned how to map out its phases using callbacks for timers, I/O, process.nextTick(), and promises.

Next, you learned about Node events and how to create a custom event. Then you learned about Streams, and even used those to map out the event loop’s phases. Finally, you learned how to pass arguments to timer callbacks.

Everything you’ve learned so far has been in preparation for Unit 6, where you’ll build your first Node application: an online Shopping List.

Video

Test your understanding

Take this quiz to test your Node knowledge. Answers are below.

True or False

  1. True/False: A Node application will terminate if the event loop has no callbacks to process.

  2. True/False: Node contains many pre-defined Events that you must reuse in your code, since you are not allowed to create your own events.

  3. True/False: The Stream I/O API will notify your application automatically when a stream is closed by throwing a StreamClosedException that you must catch.

  4. True/False: You are allowed to pass as many arguments to timers as you wish.

Check your answers

Choose the best answer

  1. Which of the following is NOT a phase of the event loop?

    A – Timers

    B – Closure

    C – Poll

    D – Immediate

    E – A and B

    F – B and D

  2. Which of the following statements about the event-logger module (see event-logger.js) are false?

    A – The event-logger module has a different interface from logger.

    Bevent-logger maintains an internal array of messages, which it will flush when it reaches a pre-set limit so as to minimize its footprint on the runtime.

    Cevent-logger is an event listener, and registers an event listener for each of the possible log message types (for example, TRACE, WARN, and so forth).

    Devent-logger is missing the off() method, which is an integral part of the logger interface.

    E – A and D

    F – B and D

    G – A and C

  3. Suppose you wish to cancel an interval timer that has been scheduled. Which of the following are true?

    A – Call the cancel() function on the timer to cancel its next cycle.

    B – Keep the Timeout object returned from the call to setInterval() and pass it to the clearInterval() function.

    C – You don’t need to do anything. Interval timers eventually expire on the own.

    D – There is nothing you can do. Interval timers are designed to run for the life of the Node process and are impossible to cancel.

Check your answers

Fill in the Blank

  1. To create a timer that executes a callback repeatedly when the timer expires, you use the __ function.

  2. To be notified when a ReadableStream has been opened you register a listener handler function for the __ event.

  3. Events in Node require two participants (though both may be in the same module): the __ sends the event, and the __ receives it.

Check your answers

Programming exercises

  1. Study the following listing. Each logger statement consists of a single letter. Predict the order of the letters in the output based on your knowledge of the event loop.

    quiz-listing-problem-12.js:

     const fs = require('fs');
     (function mainline() {
         process.nextTick(() => {
             console.log('A');
         });
         console.log('B');
         setTimeout(() => {
             console.log('C');
         }, 5000);
         setImmediate(() => {
             console.log('D');
         });
         fs.readdir('./', 'utf8', (err, files) => {
             console.log('E');
             setTimeout(() => {
                 console.log('F');
             }, 0);
             setImmediate(() => {
                 console.log('G');
             });
             process.nextTick(() => {
                 console.log('H');
             });
         });
         console.log('I');
     })();
    
  2. Write a program to prove BEYOND ANY DOUBT that the check phase always follows the poll phase.

  3. Write a program to do the following:

    • Create an interval timer that runs 6 times
    • The timer’s callback will log the elapsed time to the console at INFO level. The source parameter is setInterval callback.
    • Use event-logger to perform the logging.
    • Use 10ms as the delay for the interval timer.
    • Wrap all code (except calls to require()) in an IIFE called mainline
    • Use process.hrtime() to get the system time, rather than Date.now()

Check your answers

Check your answers

Answers to true or false questions

  1. True – If there are no callbacks to run, the event loop has nothing to do, and Node will exit.

  2. False – While Node does have a lot of events defined (such as the ‘open’, ‘error’, and ‘close’ events for I/O Streams) you can create your own custom events to use within your application.

  3. False – If you wish to be notified when a Stream is closed, you need to register an on('close') listener with the Stream. If an error occurs, you may be notified of that too by registering an on('error') listener.

  4. True – There is no limit to the number of arguments you may pass to any of the timer functions (within reason, and subject to the limits of the ES6 specification).

Answers to multiple choice questions

  1. F – There are no phases called Closure and Immediate in the event loop.

  2. E – The interface to event-logger is identical to logger (by design), and there is no off() method in the logger module (though it is possible to call setLogLevel(Level.OFF)).

  3. B – you call clearInterval() and pass it the Timeout object returned from the setInterval() call.

Answers for fill in the blank questions

  1. setInterval() – To create a timer that executes a callback repeatedly when the timer expires, you use the setInterval() function.

  2. open – To be notified when a ReadableStream has been opened you register a listener handler function for the open event.

  3. emitter, listener – Events in Node require two participants (though both may be in the same module): the emitter sends the event, and the listener receives it.

Answers to programming questions

  1. The letters come out in the following order:

    B I A E H D G F C

    B, I – executes on the mainline code path. A – executes as a mainline microtask, before any event loop callbacks are executed E – callback executes during the poll phase H – callback executes as a poll phase microtask D, G – callbacks execute during the check phase, and in the order they were added to the check phase callback queue F – expires immediately after scheduled, and executes during the next timers phase C – expires after 50ms and executes last

  2. Write a program to prove BEYOND ANY DOUBT that the check phase always follows the poll phase. Answer:

     const fs = require('fs');
    
     const logger = require('../common/event-logger');
    
     (function mainline() {
         const ITERATIONS_MAX = 3;
    
         let iterationNumber = 0;
    
         let intervalTimeout = setInterval(() => {
             if (iterationNumber < ITERATIONS_MAX) {
                 fs.readdir('../data', (err, files) => {
                     logger.info('setInterval.fs.readdir', 'POLL');
                     // In poll phase
                     process.nextTick(() => {
                         logger.info('setInterval.fs.readdir.process.nextTick', 'POLL MICROTASK');
                     });
                     setTimeout(() => {
                         logger.info('setInterval.fs.readdir.setTimeout', 'TIMERS');
                         process.nextTick(() => {
                             logger.info('setInterval.fs.readdir.setTimeout.process.nextTick', 'TIMERS MICROTASK')
                         });
                     });
                     setImmediate(() => {
                         logger.info('setInterval.fs.readdir.setImmediate', 'CHECK');
                         process.nextTick(() => {
                             logger.info('setInterval.fs.readdir.setImmediate.process.nextTick', 'CHECK MICROTASK')
                         });
                     });
                 });
             } else {
                 clearInterval(intervalTimeout);
                 logger.flush();
             }
             iterationNumber++;
         });
     })();
    

    The output looks like this:

     $ node exercise1
     576564554.279092: POLL:[INFO]: setInterval.fs.readdir
     576564554.960544: POLL MICROTASK:[INFO]: setInterval.fs.readdir.process.nextTick
     576564555.164437: CHECK:[INFO]: setInterval.fs.readdir.setImmediate
     576564555.214067: CHECK MICROTASK:[INFO]: setInterval.fs.readdir.setImmediate.process.nextTick
     576564555.314071: TIMERS:[INFO]: setInterval.fs.readdir.setTimeout
     576564555.356228: TIMERS MICROTASK:[INFO]: setInterval.fs.readdir.setTimeout.process.nextTick
     576564555.376874: POLL:[INFO]: setInterval.fs.readdir
     576564555.420391: POLL MICROTASK:[INFO]: setInterval.fs.readdir.process.nextTick
     576564555.434952: CHECK:[INFO]: setInterval.fs.readdir.setImmediate
     576564555.4429: CHECK MICROTASK:[INFO]: setInterval.fs.readdir.setImmediate.process.nextTick
     576564556.935556: TIMERS:[INFO]: setInterval.fs.readdir.setTimeout
     576564556.966728: TIMERS MICROTASK:[INFO]: setInterval.fs.readdir.setTimeout.process.nextTick
     576564557.048783: POLL:[INFO]: setInterval.fs.readdir
     576564557.084104: POLL MICROTASK:[INFO]: setInterval.fs.readdir.process.nextTick
     576564557.100706: CHECK:[INFO]: setInterval.fs.readdir.setImmediate
     576564557.109529: CHECK MICROTASK:[INFO]: setInterval.fs.readdir.setImmediate.process.nextTick
     576564561.335471: TIMERS:[INFO]: setInterval.fs.readdir.setTimeout
     576564561.417681: TIMERS MICROTASK:[INFO]: setInterval.fs.readdir.setTimeout.process.nextTick
    

    There are three full iterations of the setInterval() timer, along with the corresponding phases of the event loop. The check phase output always comes immediately after the poll phase microtask (delimiter). The check phase microtask (delimiter) ALWAYS comes immediately before the timers phase output, whose microtask (delimiter) is immediately before the poll phase. This pattern repeats for all three iterations, proving the order of the event loop is as we expect.

  3. Write a program to do the following:

    • Create an interval timer that runs 6 times
    • The timer’s callback will log the elapsed time to the console at INFO level. The source parameter is setInterval callback.
    • Use event-logger to perform the logging.
    • Use 10ms as the delay for the interval timer.
    • Wrap all code (except calls to require()) in an IIFE called mainline
    • Use process.hrtime() to get the system time, rather than Date.now()

      Answer:

      'use strict'
      const logger = require('../common/event-logger');
      const simpleUtils = require('../common/simple-utils');
      
      (function mainline() {
        const ITERATIONS_MAX = 6;
      
        var iterationNumber = 0;
      
        var intervalTimeout = setInterval((startTime) => {
      
            let currentTime = simpleUtils.hrtimeToMillis(process.hrtime());
      
            if (iterationNumber < ITERATIONS_MAX) {
                logger.info('Elapsed time: ' + (currentTime - startTime), 'setInterval callback');
            } else {
                clearInterval(intervalTimeout);
                logger.flush();
            }
            iterationNumber++;
        }, 10, simpleUtils.hrtimeToMillis(process.hrtime()));
      })();
      

      The output looks like this:

      $ node exercise2
      576695873.629884: setInterval callback:[INFO]: Elapsed time: 14.082288026809692
      576695884.074989: setInterval callback:[INFO]: Elapsed time: 24.693628072738647
      576695894.912868: setInterval callback:[INFO]: Elapsed time: 35.545942068099976
      576695907.607486: setInterval callback:[INFO]: Elapsed time: 48.227020025253296
      576695917.756489: setInterval callback:[INFO]: Elapsed time: 58.388832092285156
      576695928.921889: setInterval callback:[INFO]: Elapsed time: 69.5587830543518
      

      There are six iterations of the setInterval() loop, and its callback outputs the elapsed time (using process.hrtime()).