After that, run your web server using node app.js, visit http://localhost:3000, and you will see a message ‘Hello World’.

Debugging Guide

This guide will help you get started debugging your Node.js apps and scripts.

Enable Inspector

When started with the –inspect switch, a Node.js process listens via WebSockets for diagnostic commands as defined by the Inspector Protocol, by default at host and port 127.0.0.1:9229.

Each process is also assigned a unique UUID (e.g. 0f2c936f-b1cd-4ac9-aab3-f63b0f33d55e ).

Inspector clients must know and specify host address, port, and UUID to connect to the WebSocket interface.

The full URL is ws://127.0.0.1:9229/0f2c936f-b1cd-4ac9-aab3-f63b0f33d55e , of course dependent on actual host and port and with the correct UUID for the instance.

Inspector also includes an HTTP endpoint to serve metadata about the debuggee, including its WebSocket URL, UUID, and Chrome DevTools URL.

Get this metadata by sending an HTTP request to http://[host:port]/json/list . This returns a JSON object like the following; use the webSocketDebuggerUrl property as the URL to connect directly to Inspector.

{
  "description": "node.js instance",
  "devtoolsFrontendUrl": "chrome-devtools://devtools/bundled/inspector.html?experiments=true&v8only=true&ws=127.0.0.1:9229/0f2c936f-b1cd-4ac9-aab3-f63b0f33d55e",
  "faviconUrl": "https://nodejs.org/static/favicon.ico",
  "id": "0f2c936f-b1cd-4ac9-aab3-f63b0f33d55e",
  "title": "node",
  "type": "node",
  "url": "file://",
  "webSocketDebuggerUrl": "ws://127.0.0.1:9229/0f2c936f-b1cd-4ac9-aab3-f63b0f33d55e"
}

A Node.js process started without –inspect can also be instructed to start listening for debugging messages by signaling it with SIGUSR1 (on Linux and OS X).

As of Node 7 this activates the legacy Debugger API; in Node 8 and later it will activate the Inspector API.

Enabling remote debugging scenarios

It’s recommended that you never have the debugger listen on a public IP address. If you need to allow remote debugging connections we recommend the use of ssh tunnels instead. We provide the following example for illustrative purposes only.

Please understand the security risk of allowing remote access to a privileged service before proceeding.

Let’s say you are running Node on remote machine, remote.example.com, that you want to be able to debug. On that machine, you should start the node process with the inspector listening only to localhost (the default).

$ node --inspect server.js

Now, on your local machine from where you want to initiate a debug client connection, you can setup an ssh tunnel:

$ ssh -L 9221:localhost:9229 user@remote.example.com

This starts a ssh tunnel session where a connection to port 9221 on your local machine will be forwarded to port 9229 on remote.example.com.

You can now attach a debugger such as Chrome DevTools or Visual Studio Code to localhost:9221, which should be able to debug as if the Node.js application was running locally.

Node Inspector

Debug your Node.js app with Chrome DevTools by using an intermediary process which translates the Inspector Protocol used in Chromium to the V8 Debugger protocol used in Node.js.

Learn Easy profiling for Node.js Applications

The built-in profiler uses the profiler inside V8 which samples the stack at regular intervals during program execution. It records the results of these samples, along with important optimization events such as jit compiles, as a series of ticks:

code-creation,LazyCompile,0,0x2d5000a337a0,396,"bp native array.js:1153:16",0x289f644df68,~
code-creation,LazyCompile,0,0x2d5000a33940,716,"hasOwnProperty native v8natives.js:198:30",0x289f64438d0,~
code-creation,LazyCompile,0,0x2d5000a33c20,284,"ToName native runtime.js:549:16",0x289f643bb28,~
code-creation,Stub,2,0x2d5000a33d40,182,"DoubleToIStub"
code-creation,Stub,2,0x2d5000a33e00,507,"NumberToStringStub"

In the past you need the V8 source code to be able to interpret the ticks. Luckily, tools have recently been introduced into Node.js 4.4.0 that facilitate the consumption of this information without separately building V8 from source. Let’s see how the built-in profiler can help provide insight into application performance.

To illustrate the use of the tick profiler, we will work with a simple Express application. Our application will have two handlers, one for adding new users to our system:

app.get('/newUser', (req, res) => {
  let username = req.query.username || '';
  const password = req.query.password || '';

  username = username.replace(/[!@#$%^&*]/g, '');

  if (!username || !password || users.username) {
    return res.sendStatus(400);
  }

  const salt = crypto.randomBytes(128).toString('base64');
  const hash = crypto.pbkdf2Sync(password, salt, 10000, 512, 'sha512');

  users[username] = { salt, hash };

  res.sendStatus(200);
});

and another for validating user authentication attempts:

Please note that these are NOT recommended handlers for authenticating users in your Node.js applications and are used purely for illustration purposes. You should not be trying to design your own cryptographic authentication mechanisms in general. It is much better to use existing, proven authentication solutions.

Now assume that we’ve deployed our application and users are complaining about high latency on requests. We can easily run the app with the built in profiler:

NODE_ENV=production node --prof app.js

and put some load on the server using ab (ApacheBench):

curl -X GET "http://localhost:8080/newUser?username=matt&password=password"
ab -k -c 20 -n 250 "http://localhost:8080/auth?username=matt&password=password"

and get an ab output of:

Concurrency Level:      20
Time taken for tests:   46.932 seconds
Complete requests:      250
Failed requests:        0
Keep-Alive requests:    250
Total transferred:      50250 bytes
HTML transferred:       500 bytes
Requests per second:    5.33 [#/sec] (mean)
Time per request:       3754.556 [ms] (mean)
Time per request:       187.728 [ms] (mean, across all concurrent requests)
Transfer rate:          1.05 [Kbytes/sec] received

...

Percentage of the requests served within a certain time (ms)
  50%   3755
  66%   3804
  75%   3818
  80%   3825
  90%   3845
  95%   3858
  98%   3874
  99%   3875
 100%   4225 (longest request)

From this output, we see that we’re only managing to serve about 5 requests per second and that the average request takes just under 4 seconds round trip.

In a real world example, we could be doing lots of work in many functions on behalf of a user request but even in our simple example, time could be lost compiling regular expressions, generating random salts, generating unique hashes from user passwords, or inside the Express framework itself.

Since we ran our application using the –prof option, a tick file was generated in the same directory as your local run of the application. It should have the form isolate-0xnnnnnnnnnnnn-v8.log (where n is a digit).

In order to make sense of this file, we need to use the tick processor bundled with the Node.js binary. To run the processor, use the –prof-process flag:

node --prof-process isolate-0xnnnnnnnnnnnn-v8.log > processed.txt

Opening processed.txt in your favorite text editor will give you a few different types of information. The file is broken up into sections which are again broken up by language. First, we look at the summary section and see:

This tells us that 97% of all samples gathered occurred in C++ code and that when viewing other sections of the processed output we should pay most attention to work being done in C++ (as opposed to JavaScript).

With this in mind, we next find the [C++] section which contains information about which C++ functions are taking the most CPU time and see:

 [C++]:
   ticks  total  nonlib   name
  19557   51.8%   52.9%  node::crypto::PBKDF2(v8::FunctionCallbackInfo const&)
   4510   11.9%   12.2%  _sha1_block_data_order
   3165    8.4%    8.6%  _malloc_zone_malloc

We see that the top 3 entries account for 72.1% of CPU time taken by the program. From this output, we immediately see that at least 51.8% of CPU time is taken up by a function called PBKDF2 which corresponds to our hash generation from a user’s password.

However, it may not be immediately obvious how the lower two entries factor into our application (or if it is we will pretend otherwise for the sake of example).

To better understand the relationship between these functions, we will next look at the [Bottom up (heavy) profile] section which provides information about the primary callers of each function. Examining this section, we find:

 ticks parent  name
  19557   51.8%  node::crypto::PBKDF2(v8::FunctionCallbackInfo const&)
  19557  100.0%    v8::internal::Builtins::~Builtins()
  19557  100.0%      LazyCompile: ~pbkdf2 crypto.js:557:16

   4510   11.9%  _sha1_block_data_order
   4510  100.0%    LazyCompile: *pbkdf2 crypto.js:557:16
   4510  100.0%      LazyCompile: *exports.pbkdf2Sync crypto.js:552:30

   3165    8.4%  _malloc_zone_malloc
   3161   99.9%    LazyCompile: *pbkdf2 crypto.js:557:16
   3161  100.0%      LazyCompile: *exports.pbkdf2Sync crypto.js:552:30

Parsing this section takes a little more work than the raw tick counts above. Within each of the “call stacks” above, the percentage in the parent column tells you the percentage of samples for which the function in the row above was called by the function in the current row.

For example, in the middle “call stack” above for sha1block_data_order , we see that _sha1_block_data_order occurred in 11.9% of samples, which we knew from the raw counts above.

However, here, we can also tell that it was always called by the pbkdf2 function inside the Node.js crypto module. We see that similarly, _malloc_zone_malloc was called almost exclusively by the same pbkdf2 function.

Thus, using the information in this view, we can tell that our hash computation from the user’s password accounts not only for the 51.8% from above but also for all CPU time in the top 3 most sampled functions since the calls to _sha1_block_data_order and _malloc_zone_malloc were made on behalf of the pbkdf2 function.

At this point, it is very clear that the password based hash generation should be the target of our optimization. Thankfully, you’ve fully internalized the benefits of asynchronous programming and you realize that the work to generate a hash from the user’s password is being done in a synchronous way and thus tying down the event loop. This prevents us from working on other incoming requests while computing a hash.

To remedy this issue, you make a small modification to the above handlers to use the asynchronous version of the pbkdf2 function:

app.get('/auth', (req, res) => {
  let username = req.query.username || '';
  const password = req.query.password || '';

  username = username.replace(/[!@#$%^&*]/g, '');

  if (!username || !password || !users[username]) {
    return res.sendStatus(400);
  }

  crypto.pbkdf2(password, users[username].salt, 10000, 512, (err, hash) => {
    if (users[username].hash.toString() === hash.toString()) {
      res.sendStatus(200);
    } else {
      res.sendStatus(401);
    }
  });
});

A new run of the ab benchmark above with the asynchronous version of your app yields:

Concurrency Level:      20
Time taken for tests:   12.846 seconds
Complete requests:      250
Failed requests:        0
Keep-Alive requests:    250
Total transferred:      50250 bytes
HTML transferred:       500 bytes
Requests per second:    19.46 [#/sec] (mean)
Time per request:       1027.689 [ms] (mean)
Time per request:       51.384 [ms] (mean, across all concurrent requests)
Transfer rate:          3.82 [Kbytes/sec] received

...

Percentage of the requests served within a certain time (ms)
  50%   1018
  66%   1035
  75%   1041
  80%   1043
  90%   1049
  95%   1063
  98%   1070
  99%   1071
 100%   1079 (longest request)

Your app is now serving about 20 requests per second, roughly 4 times more than it was with the synchronous hash generation. Additionally, the average latency is down from the 4 seconds before to just over 1 second.

Hopefully, through the performance investigation of this (admittedly contrived) example, you’ve seen how the V8 tick processor can help you gain a better understanding of the performance of your Node.js applications.

Creating a Node.js web app

How to create a simple web application in Node.js.

First, create a new directory where all the files would live. In this directory create a package.json file that describes your app and its dependencies:

{
  "name": "docker_web_app",
  "version": "1.0.0",
  "description": "Node.js on Docker",
  "author": "First Last <first.last@example.com>",
  "main": "server.js",
  "scripts": {
    "start": "node server.js"
  },
  "dependencies": {
    "express": "^4.16.1"
  }
}

With your new package.json file, run npm install. If you are using npm version 5 or later, this will generate a package-lock.json file which will be copied to your Docker image.

Then, create a server.js file that defines a web app using the Express.js framework:

'use strict';

const express = require('express');

// Constants
const PORT = 8080;
const HOST = '0.0.0.0';

// App
const app = express();
app.get('/', (req, res) => {
  res.send('Hello world\n');
});

app.listen(PORT, HOST);
console.log(`Running on http://${HOST}:${PORT}`);

View the rest of the guide to Creating a Dockerfile.

Migrate to safe Buffer constructor methods

The Buffer() and new Buffer() constructors are not recommended for use due to security and usability concerns. Please use the new Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() construction methods instead.

Finding problematic bits of code using grep

Just run grep -nrE '[^a-zA-Z](Slow)?Buffer\s*\(' --exclude-dir node_modules.

It will find all the potentially unsafe places in your own code (with some considerably unlikely exceptions).

Finding problematic bits of code using Node.js 8

If you’re using Node.js ≥ 8.0.0 (which is recommended), Node.js exposes multiple options that help with finding the relevant pieces of code:

• –trace-warnings will make Node.js show a stack trace for this warning and other warnings that are printed by Node.js.
• –trace-deprecation does the same thing, but only for deprecation warnings.
• –pending-deprecation will show more types of deprecation warnings. In particular, it will show the Buffer() deprecation warning, even on Node.js 8.

You can set these flags using environment variables:

$ export NODE_OPTIONS='--trace-warnings --pending-deprecation'
$ cat example.js
'use strict';
const foo = new Buffer('foo');
$ node example.js
(node:7147) [DEP0005] DeprecationWarning: The Buffer() and new Buffer() constructors are not recommended for use due to security and usability concerns. Please use the new Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() construction methods instead.
at showFlaggedDeprecation (buffer.js:127:13)
at new Buffer (buffer.js:148:3)
at Object. (/path/to/example.js:2:13)
[... more stack trace lines ...]

Node.js API Reference Documentation

The API reference documentation provides detailed information about a function or object in Node.js.

Node.js core concepts

• Overview of Blocking vs Non-Blocking
• Node.js Event Loop, Timers, and process.nextTick()
• Don’t Block the Event Loop (or the Worker Pool)
• Timers in Node.js

Read More Guides

Learn more topics regarding Front-End Web Development, User Experience Design, and Industry-related Technology topics.

View our post on LinkedIn