Pm2: Debugging with VSCode crash - Assertion `(channel_) == (nullptr)' failed

[leonardlepadatu]

Running pm2 in docker was fine for my project until I rebuild the image and pm2 upgraded to 3.0.0 Cobra.

For details please refer to: Assertion `(channel_) == (nullptr)' failed #54044

* Working version 2.10.4*

===============================================================================
--- PM2 REPORT (Thu Jul 12 2018 10:30:29 GMT+0300 (EEST)) ---------------------
===============================================================================
--- Daemon -------------------------------------------------
pm2d version         : 2.10.4
node version         : 8.11.3
node path            : /usr/bin/pm2
argv                 : /usr/bin/node,/usr/bin/pm2,start,pm2start.leo.config.js,--update-env,--no-daemon
argv0                : node
user                 : undefined
uid                  : 0
gid                  : 0
uptime               : 974min
===============================================================================
--- CLI ----------------------------------------------------
local pm2            : 2.10.4
node version         : 8.11.3
node path            : /usr/bin/pm2
argv                 : /usr/bin/node,/usr/bin/pm2,report
argv0                : node
user                 : undefined
uid                  : 0
gid                  : 0
===============================================================================
--- System info --------------------------------------------
arch                 : x64
platform             : linux
type                 : Linux
cpus                 : Intel(R) Core(TM) i7-3632QM CPU @ 2.20GHz
cpus nb              : 8
freemem              : 345264128
totalmem             : 12442116096
home                 : /root
===============================================================================
--- PM2 list -----------------------------------------------
┌───────────────┬────┬──────┬─────┬────────┬─────────┬────────┬─────┬───────────┬──────┬──────────┐
│ App name      │ id │ mode │ pid │ status │ restart │ uptime │ cpu │ mem       │ user │ watching │
├───────────────┼────┼──────┼─────┼────────┼─────────┼────────┼─────┼───────────┼──────┼──────────┤
│ ecds-importer │ 2  │ fork │ 310 │ online │ 6       │ 15h    │ 0%  │ 65.7 MB   │ root │ enabled  │
│ ecds-server   │ 1  │ fork │ 315 │ online │ 6       │ 15h    │ 0%  │ 91.0 MB   │ root │ enabled  │
└───────────────┴────┴──────┴─────┴────────┴─────────┴────────┴─────┴───────────┴──────┴──────────┘
 Module activated
┌───────────────┬─────────┬────────────┬────────┬─────────┬─────┬─────────────┬──────┐
│ Module        │ version │ target PID │ status │ restart │ cpu │ memory      │ user │
├───────────────┼─────────┼────────────┼────────┼─────────┼─────┼─────────────┼──────┤
│ pm2-logrotate │ 2.6.0   │ N/A        │ online │ 0       │ 0%  │ 52.367 MB   │ root │
└───────────────┴─────────┴────────────┴────────┴─────────┴─────┴─────────────┴──────┘
===============================================================================
--- Daemon logs --------------------------------------------
/root/.pm2/pm2.log last 20 lines:
PM2        | [2018-07-11 15:14:43] PM2 log: ===============================================================================
PM2        | [2018-07-11 15:14:43] PM2 log: --- New PM2 Daemon started ----------------------------------------------------
PM2        | [2018-07-11 15:14:43] PM2 log: Time                 : Wed Jul 11 2018 15:14:43 GMT+0000 (UTC)
PM2        | [2018-07-11 15:14:43] PM2 log: PM2 version          : 2.10.4
PM2        | [2018-07-11 15:14:43] PM2 log: Node.js version      : 8.11.3
PM2        | [2018-07-11 15:14:43] PM2 log: Current arch         : x64
PM2        | [2018-07-11 15:14:43] PM2 log: PM2 home             : /root/.pm2
PM2        | [2018-07-11 15:14:43] PM2 log: PM2 PID file         : /root/.pm2/pm2.pid
PM2        | [2018-07-11 15:14:43] PM2 log: RPC socket file      : /root/.pm2/rpc.sock
PM2        | [2018-07-11 15:14:43] PM2 log: BUS socket file      : /root/.pm2/pub.sock
PM2        | [2018-07-11 15:14:43] PM2 log: Application log path : /root/.pm2/logs
PM2        | [2018-07-11 15:14:43] PM2 log: Process dump file    : /root/.pm2/dump.pm2
PM2        | [2018-07-11 15:14:43] PM2 log: Concurrent actions   : 2
PM2        | [2018-07-11 15:14:43] PM2 log: SIGTERM timeout      : 1600
PM2        | [2018-07-11 15:14:43] PM2 log: ===============================================================================
PM2        | [2018-07-11 15:14:51] PM2 log: Starting execution sequence in -fork mode- for app name:pm2-logrotate id:0
PM2        | [2018-07-11 15:14:51] PM2 log: App name:pm2-logrotate id:0 online

* Not working version *

===============================================================================
--- PM2 REPORT (Thu Jul 12 2018 10:33:50 GMT+0300 (EEST)) ---------------------
===============================================================================
--- Daemon -------------------------------------------------
pm2d version         : 3.0.0
node version         : 8.11.3
node path            : /usr/bin/pm2
argv                 : /usr/bin/node,/usr/bin/pm2,start,pm2start.leo.config.js,--update-env,--no-daemon
argv0                : node
user                 : undefined
uid                  : 0
gid                  : 0
uptime               : 0min
===============================================================================
--- CLI ----------------------------------------------------
local pm2            : 3.0.0
node version         : 8.11.3
node path            : /usr/bin/pm2
argv                 : /usr/bin/node,/usr/bin/pm2,report
argv0                : node
user                 : undefined
uid                  : 0
gid                  : 0
===============================================================================
--- System info --------------------------------------------
arch                 : x64
platform             : linux
type                 : Linux
cpus                 : Intel(R) Core(TM) i7-3632QM CPU @ 2.20GHz
cpus nb              : 8
freemem              : 595439616
totalmem             : 12442116096
home                 : /root
===============================================================================
--- PM2 list -----------------------------------------------
┌───────────────┬────┬──────┬─────┬────────┬─────────┬────────┬──────┬───────────┬──────┬──────────┐
│ App name      │ id │ mode │ pid │ status │ restart │ uptime │ cpu  │ mem       │ user │ watching │
├───────────────┼────┼──────┼─────┼────────┼─────────┼────────┼──────┼───────────┼──────┼──────────┤
│ ecds-importer │ 2  │ fork │ 90  │ online │ 0       │ 37s    │ 0.1% │ 56.2 MB   │ root │ enabled  │
│ ecds-server   │ 1  │ fork │ 83  │ online │ 0       │ 38s    │ 0.1% │ 84.9 MB   │ root │ enabled  │
└───────────────┴────┴──────┴─────┴────────┴─────────┴────────┴──────┴───────────┴──────┴──────────┘
 Module activated
┌───────────────┬─────────┬────────────┬────────┬─────────┬──────┬─────────────┬──────┐
│ Module        │ version │ target PID │ status │ restart │ cpu  │ memory      │ user │
├───────────────┼─────────┼────────────┼────────┼─────────┼──────┼─────────────┼──────┤
│ pm2-logrotate │ 2.6.0   │ N/A        │ online │ 0       │ 0.1% │ 44.191 MB   │ root │
└───────────────┴─────────┴────────────┴────────┴─────────┴──────┴─────────────┴──────┘
===============================================================================
--- Daemon logs --------------------------------------------
┌───────────────┬────┬──────┬─────┬────────┬─────────┬────────┬─────┬───────────┬──────┬──────────┐
│ App name      │ id │ mode │ pid │ status │ restart │ uptime │ cpu │ mem       │ user │ watching │
├───────────────┼────┼──────┼─────┼────────┼─────────┼────────┼─────┼───────────┼──────┼──────────┤
│ ecds-importer │ 2  │ fork │ 90  │ online │ 0       │ 38s    │ 0%  │ 56.2 MB   │ root │ enabled  │
│ ecds-server   │ 1  │ fork │ 83  │ online │ 0       │ 38s    │ 0%  │ 84.9 MB   │ root │ enabled  │
└───────────────┴────┴──────┴─────┴────────┴─────────┴────────┴─────┴───────────┴──────┴──────────┘
 Module activated
┌───────────────┬─────────┬────────────┬────────┬─────────┬─────┬─────────────┬──────┐
│ Module        │ version │ target PID │ status │ restart │ cpu │ memory      │ user │
├───────────────┼─────────┼────────────┼────────┼─────────┼─────┼─────────────┼──────┤
│ pm2-logrotate │ 2.6.0   │ N/A        │ online │ 0       │ 0%  │ 44.191 MB   │ root │
└───────────────┴─────────┴────────────┴────────┴─────────┴─────┴─────────────┴──────┘

[Unitech]

Hello @leonardlepadatu thanks for reporting,

Would you have a simple example so we can reproduce that issue? Thank you

[leonardlepadatu]

Hi!
In my Dockerfile I installed pm2 like this:
npm install --global pm2
When I rebuild my docker image, it is obvious that npm just install the last version of pm2, the 3.0.0

Dockerfile

FROM centos:centos6
MAINTAINER Leonard Lepadatu <[email protected]>
RUN yum -y update; yum clean all
RUN yum -y install epel-release; yum clean all
RUN yum install -y yum-utils bzip2 bzip2-devel wget curl tar; yum clean all
RUN yum groupinstall -y "Development Tools"; yum clean all
RUN curl -sL https://rpm.nodesource.com/setup_8.x | bash -
RUN yum install -y nodejs; yum clean all
RUN npm config set registry="http://registry.npmjs.org/"
RUN npm install --global pm2; pm2 install pm2-logrotate;
RUN curl -sL https://dl.yarnpkg.com/rpm/yarn.repo -o /etc/yum.repos.d/yarn.repo
RUN yum install -y yarn; yum clean all
RUN curl -sL http://people.centos.org/tru/devtools-1.1/devtools-1.1.repo -o /etc/yum.repos.d/devtools-1.1.repo
RUN yum --enablerepo=testing-1.1-devtools-6 install -y devtoolset-1.1-gcc devtoolset-1.1-gcc-c++
RUN npm install --global node-pre-gyp
CMD ["/bin/bash"]

docker-compose.yml

version: '3.3'
services:
    api:
        build: .
        container_name: "api"
#...
        volumes:
          - ./api:/var/www/project/ecds/api
        working_dir: /var/www/project/ecds/api
#...
        tty: true
        networks:
           project-esdc:
             ipv4_address: 172.19.0.10
       ports:
          - "5050:5050"
          - "9019:9019"
        command: bash -c "yarn && 
                         pm2 start pm2start.leo.config.js --update-env --no-daemon"
#...
networks:
    project-ecds:
        driver: "bridge"
        ipam:
          config:
            - subnet: 172.19.0.0/24

pm2start.leo.config.js

module.exports = {
    apps: [{
        name: 'ecds',
        script: 'src/',
        node_args: `--inspect=0.0.0.0:9019 -r dotenv/config`,
        env: {
            PORT: process.env.PORT
        },
        watch: true,
        ignore_watch: ['uploads', 'logs', '.git'],
        error_file: 'logs/err.log',
        out_file: 'logs/out.log',
        merge_logs: true,
        log_date_format: 'YYYY-MM-DD HH:mm:ss',
        max_size: '10M',
        retain: 'all',
        compress: true,
        workerInterval: 600
    }, 
   { ... }
    ]
};

vscode launch.json

{
    "version": "0.2.0",
    "configurations": [
        {
            "name": "Attach to Docker",
            "type": "node",
            "request": "attach",
            "port": 9019,
            "address": "172.19.0.10",
            "protocol": "inspector",
            "restart": true,
            "trace": true,
            "sourceMaps": false,
            "localRoot": "${workspaceRoot}",
            "remoteRoot": "/var/www/project/ecds/api"
        }
    ]
}

$ docker-compose up --build

* VSCode - start debugging 'Attach to Docker' * (actually I think is a custom version of node-inspector)

pm2 logs:

project-ecds-api | 1|ecds-ser | 2018-07-11 15:32:33: Debugger attached.
project-ecds-api | 1|ecds-ser | node /var/www/project/ecds/api/src[88]: ../src/inspector_agent.cc:353:void node::inspector::NodeInspectorClient::connectFrontend(node::inspector::InspectorSessionDelegate*): Assertion `(channel_) == (nullptr)' failed.
[.....]

After I downgrade pm2 to 2.10.4, everything work just fine: npm install --global [email protected]

Thank you

[Unitech]

Thanks for this complete example.

So after testing we isolated the issue. It is because Node 8.x does not handle multi inspector session (the new pm2 3.0 use inspector internally)

So with this basic example:

var inspector = require('inspector')

var inspectorService =  new inspector.Session();
inspectorService.connect();
inspectorService.post('Profiler.enable')
//inspectorService.post('HeapProfiler.enable')

var http = require('http');

var server = http.createServer(function(req, res) {
  res.writeHead(200);
  res.end('hey');
}).listen(process.env.PORT || 8000, function() {
  console.log('App listening on port %d', server.address().port);
});

And starting it with:

$ node -v
v8.11.3
$ node --inspect http.js

When you connect to the inspector you get this:

Debugger listening on ws://127.0.0.1:9229/a88146d4-82ce-4aec-9188-ff857f8d65fa
For help see https://nodejs.org/en/docs/inspector
App listening on port 8000
Debugger attached.
node[15480]: ../src/inspector_agent.cc:353:void node::inspector::NodeInspectorClient::connectFrontend(node::inspector::InspectorSessionDelegate*): Assertion `(channel_) == (nullptr)' failed.
 1: node::Abort() [node]
 2: 0x8c25db [node]
 3: 0x963f7d [node]
 4: 0x965e20 [node]
 5: node::NodePlatform::FlushForegroundTasksInternal() [node]
 6: 0x14125fb [node]
 7: 0x14246b8 [node]
 8: uv_run [node]
 9: node::Start(uv_loop_s*, int, char const* const*, int, char const* const*) [node]
10: node::Start(int, char**) [node]
11: __libc_start_main [/lib/x86_64-linux-gnu/libc.so.6]
12: 0x89b1b1 [node]
Aborted (core dumped)

We're looking for solution right now

[leonardlepadatu]

Thanks for the answer!

This is already known: _"It is because Node 8.x does not handle multi inspector session"_

But this not: _"the new pm2 3.0 use inspector internally"_

;)

[wallet77]

Hi @leonardlepadatu

I will update the readme and the documentation on pm2.
If you don't use keymetrics you can add flag --no-pmx or property pmx: false.
If you just don't need profiling you can add this into ecosystem file :

{
  io: {
    profiling: false
  }
}

Unfortunately we can't do much more on node 8.
Maybe we can return our own instance of inspector's session so we can provide it to you to avoid multiple sessions.

[leonardlepadatu]

Thank you @wallet77 .

I'm using logrotate from keymetrics, as you can easily see in my Dokerfile:
RUN npm install --global pm2; pm2 install

I don't know if it is documented, but I can deduct that they use pmx in logrotate also, because in your documentation said something like 'sending SIGUSR2' to pm2 to reload logrotate...

About your comment regarding profiling, I don't understand how this can help?

_'Unfortunately we can't do much more on node 8.'_
I know that but this it is my client's environment and I can't do more in this direction...

_'Maybe we can return our own instance of inspector's session so we can provide it to you to avoid multiple sessions.'_
Well this is a think, indeed, but how I can do that?
Thank you again!

[arcadia168]

Hi @leonardlepadatu, thanks for your great investigation on this. I'm also experiencing this issue, using Node v8.11.3, PM2 3.0.0 and the debugger from Visual Studio Code 1.25.0.

As @wallet77 pointed out, after putting 'pmx: false' in my pm2.json file, the VSCode debugger was able to attach once more, solving my issue.

Obviously there is still a problem if I ever needed to use 'pmx: true', which fortunately I don't.

[Unitech]

It's wip, so no need to disable pmx in the future: https://github.com/keymetrics/pm2-io-apm/pull/149

[wallet77]

Waiting to integrate the new apm version with this PR :

• https://github.com/keymetrics/pm2-io-apm/pull/149
• https://github.com/keymetrics/pm2-io-apm/pull/154

With these 2 changes it will solve issue about inspector and double session on node 8.

[Unitech]

Thanks @wallet77!
You can try it out right now:

npm install Unitech/pm2#development -g
pm2 update

And let us know if it work as expected for you guys, thanks

[wallet77]

It should work with pm2-io-apm 2.1.0 or higher.

$ npm install pm2@latest -g
$ pm2 update