Sunday, January 26, 2020

How to debug a Node.js app running on a VM from local Windows

I'm working on an application where the frontend is React and the backend is Node running on CentOS 7.  Below I list steps on how to debug a PM2 managed clustered Node backend application with two different clustering methods:
  1. Node cluster module is used to configure cluster processes
  2. PM2 cluster mode is used to configure cluster processes
Environment:
Windows 10 Pro
CentOS Linux release 7.3.1611 (Core)
node v8.16.0

Node cluster module is used to configure cluster processes
NOTE: In this example PM2 starts the Node application via a npm script, and the backend code is spawning two cluster instances.

Update the command where you start node with the --inspect attribute. For us, we start node with the "startdev" npm script located in package.json. "startdev" uses the "server" script.

OLD
"scripts": {
  ..
  "startdev": "concurrently \"npm run server\" \"npm run client\"",
  "server": "cross-env node --max-old-space-size=8192 ./bin/cherryshoeServer.js",
  ..
}

NEW - You'll see that the "server" script is not changed as other npm scripts are also dependent on it. "startdev" uses a new "serverdev" script that was created to add the --inspect attribute.
"scripts": {
  ..
  "server": "cross-env node --max-old-space-size=8192 ./bin/cherryshoeServer.js",
  "startdev": "concurrently \"npm run serverdev\" \"npm run client\"",
  "serverdev": "cross-env node --max-old-space-size=8192 --inspect ./bin/cherryshoeServer.js",
  ..
}

A PM2 ecosystem configuration file is used; the config options of note are:

apps : [ {
  ..
  script: 'npm',
  // call appropriate npm script from package.json
  args: 'run startdev',
  ..
} ]

Start node with command "pm2 start", which calls the npm script "startdev", which calls npm script "serverdev", and runs cherryshoeServer.js on the local development environment.

Perform a ps command to verify the backend node processes are running. When cherryshoeServer.js is started, it spawns two worker processes on the local development environment (based on code to spawn two processes using Node cluster module).  Because of this, you'll see the first process below is the parent process with PID 5281, and the remaining two are worker processes with parent PPID 5281.

cs_admin  5281  5263  0 11:09 ?        00:00:00 node --max-old-space-
size=8192 --inspect ./bin/cherryshoeServer.js
cs_admin  5298  5281  0 11:09 ?        00:00:00 /usr/bin/node --max-old-
space-size=8192 --inspect --inspect-port=9230 /opt/cherryshoe/bin/cherryshoeServer.js
cs_admin  5303  5281  0 11:09 ?        00:00:00 /usr/bin/node --max-old-
space-size=8192 --inspect --inspect-port=9231 /opt/cherryshoe/bin/cherryshoeServer.js

Verify in the log file that debugger processes are listening. PM2 is used to manage logging, which is located in /var/log/cherryshoe/pm2/cs-out.log.  By default, the debugger listens on port 9229, then each additional debugger listener for each worker processeis incremented appropriately (9230 and 9231 respectively).
2020-01-26T11:09:22.657: [0] Debugger listening on ws://127.0.0.1:9229
/62dd92b9-a978-4cce-9e91-84b87835e014
2020-01-26T11:09:22.657: [0] For help see https://nodejs.org/en/docs
/inspector
2020-01-26T11:09:22.882: [1]
2020-01-26T11:09:22.882: [1] > origin-destination-client@0.2.0 start /opt
/cherryshoe/client
2020-01-26T11:09:22.882: [1] > concurrently "yarn watch-css" "cross-env
NODE_PATH=src/ react-scripts start"
2020-01-26T11:09:22.882: [1]
2020-01-26T11:09:22.965: [0] Running 2 processes
2020-01-26T11:09:22.975: [0] Debugger listening on ws://127.0.0.1:9230
/3e05b482-b186-4c7c-908d-7f5188353bb2
2020-01-26T11:09:22.975: [0] For help see https://nodejs.org/en/docs
/inspector
2020-01-26T11:09:22.978: [0] Debugger listening on ws://127.0.0.1:9231
/e3264361-6c0e-4843-8a4d-91b5ba9a8e4f
2020-01-26T11:09:22.978: [0] For help see https://nodejs.org/en/docs
/inspector

Back on your Windows local machine, open up your favorite app to ssh tunnel (I'm using git bash for this example but I am a big fan of MobaXterm) into the VM with appropriate ports to attach to the ports that the debuggers are listening on. This starts a ssh tunnel session where a connection to ports 8889-8891 (make sure these ports are not in use first) on your local machine will be forwarded to port 9229-9231 on the cherryshoe-dev.cherryshoe.com machine.  NOTES: I had to use 127.0.0.1 instead of localhost for this to work. Use a user account that has access to the VM. You may want to set up ssh passwordlessly so you don't have to enter passwords.
    ssh -L 8889:127.0.0.1:9229 cs_admin@cherryshoe-dev.cherryshoe.com
    ssh -L 8890:127.0.0.1:9230 cs_admin@cherryshoe-dev.cherryshoe.com
    ssh -L 8891:127.0.0.1:9231 cs_admin@cherryshoe-dev.cherryshoe.com

You can now attach a debugger client of choice to the X processes, as if the Node.js application was running locally. I will use Chrome DevTools as an example.

Open Chrome and enter "chrome://inspect" into the URL

Click "Discover network targets" Configure button and configure each of the ports to attach to:
  • Enter "127.0.0.1:8889"
  • Enter "127.0.0.1:8890"
  • Enter "127.0.0.1:8891"


You should now see the 3 processes attached in the debugger client:


Click the "inspect" link for one of the processes, this will open up the DevTools for Node. Under "Sources" tab you can click "Ctrl-P" to open up a file of choice to debug that is attached to the process. You do NOT need to 'Add folder to workspace'.

Open up each remaining process by clicking the "inspect" link.

Invoke the Node application, i.e. call a REST endpoint that it responds to
One of the worker processes will process the request. Any breakpoints will be reached and any console logs will be printed.

You have to open a window for each worker process running because you don't know which process will get picked and if you don't have them all open you can miss it and think debugging isn't working!

If you restart the Node backend, the DevTools Targets will recognize the new process IDs, but the DevTools windows won't. Therefore, you need to open up the DevTools windows again for each process via the "inspect" link.


PM2 cluster mode is used to configure cluster processes
NOTE: It was discovered that PM2 cluster mode and starting node via npm do not play nicely. The first process would listen on port X, but each subsequent process would error out saying port X was in use. Because of this, the node application was changed to start directly by invoking the appropriate js script.


The steps from the "Node cluster module" is essentially the same with some minor differences, but will list all steps for clarity: A PM2 ecosystem configuration file is used, the config options of note are:
apps : [ {
  ..
  // run node directly without npm script
  script: './bin/cherryshoeServer.js',
  node_args: '--max-old-space-size=8192 --inspect',
  ..
  // do not postfix log file with process id of sub-processes
  merge_logs: true,
  // clustering
  exec_mode: 'cluster',
  instances: '2',
  ..
} ]

Start node with command "pm2 start", which calls the ecosystem configured script with node_args on the local development environment.

Perform a ps command to verify the backend node processes are running. PM2 runs cherryshoeServer.js with two worker processes on the local development environment. NOTE: You won't see any parent process managing the worker processes like you did with Node cluster module, but you will see they have the same parent PPID.
cs_admin 18328 17488  0 12:44 ?        00:00:00 node /opt/cherryshoe/bin/cherryshoeServer.js
cs_admin 18341 17488  0 12:44 ?        00:00:00 node /opt/cherryshoe/bin/cherryshoeServer.js

Verify in the log file that debugger processes are listening, this is located in PM2's internal log <home>/.pm2/pm2.log. NOTE: This is different than Node cluster logging which goes in the application logs. By default, the debugger listens on port 9330, then each additional debugger listener for each worker processes is incremented appropriately (i.e. 9231).

Debugger listening on ws://127.0.0.1:9230/f826768a-76d8-4048-a169-
849c3c20d3fb
For help see https://nodejs.org/en/docs/inspector
2020-01-26T12:44:41: PM2 log: App [cs-client:2] online
2020-01-26T12:44:41: PM2 log: App [cs:1] online
2020-01-26T12:44:41: PM2 log: App [cs:3] starting in -cluster mode-
2020-01-26T12:44:41: PM2 error: (node:17488) [DEP0007] DeprecationWarning:
worker.suicide is deprecated. Please use worker.exitedAfterDisconnect.
Debugger listening on ws://127.0.0.1:9231/60da3960-e805-4580-a2fb-
7a210fae30e7
For help see https://nodejs.org/en/docs/inspector
2020-01-26T12:44:42: PM2 log: App [cs:3] online
2020-01-26T12:44:42: PM2 error: (node:17488) [DEP0007] DeprecationWarning:
worker.suicide is deprecated. Please use worker.exitedAfterDisconnect.

Back on your Windows local machine, open up your favorite app to ssh tunnel (I'm using git bash for this example) into the VM with appropriate ports to attach to the ports that the debuggers are listening on. This starts a ssh tunnel session where a connection to ports 8890-8891 (make sure these ports are not in use first) on your local machine will be forwarded to port 9230-9231 on the cherryshoe-dev.cherryshoe.com machine.  NOTES: I had to use 127.0.0.1 instead of localhost for this to work. Use a user account that has access to the VM. You may want to set up ssh passwordlessly so you don't have to enter passwords.
    ssh -L 8890:127.0.0.1:9230 cs_admin@cherryshoe-dev.cherryshoe.com
    ssh -L 8891:127.0.0.1:9231 cs_admin@cherryshoe-dev.cherryshoe.com

You can now attach a debugger client of choice to the X processes, as if the Node.js application was running locally. I will use Chrome DevTools as an example.

Open Chrome and enter "chrome://inspect" into the URL

Click "Discover network targets" Configure button and configure each of the ports to attach to, you can see the processes are already attached.

  • Enter "127.0.0.1:8890"
  • Enter "127.0.0.1:8891"



 Click the "inspect" link for one of the processes, this will open up the DevTools for Node. Under "Sources" tab you can click "Ctrl-P" to open up a file of choice to debug that is attached to the process. You do NOT need to 'Add folder to workspace'.

Open up each remaining process by clicking the "inspect" link.

Invoke the Node application, i.e. call a REST endpoint that it responds to
One of the worker processes will process the request. Any breakpoints will be reached and any console logs will be printed.

You have to open a window for each worker process running because you don't know which process will get picked and if you don't have them all open you can miss it and think debugging isn't working!

If you restart the Node backend, the DevTools Targets will recognize the new process IDs, but the DevTools windows won't. Therefore, you need to open up the DevTools windows again for each process via the "inspect" link.

Helpful articles:

2 comments:

I appreciate your time in leaving a comment!