Unitech / Unitech/pm2

Race condition when trying to run 2 CLI command concurrently

Open
#4,885 0 comments 1 reaction 0 assignees View on GitHub

Nobody has claimed this yet.

Dominant language
JavaScript
Stars
43.3k
Forks
2.7k
No merged PRs in 30d

Description

What's going wrong?

When trying to run multiple pm2 commands concurrently, both will fail to detect the existence of each other and start their own Daemon. In that case, pm2 start will hang forever because the binding to the RPC socket cannot be done.

How could we reproduce this issue?

  1. Run pm2 start path/to/pm2.config.json --no-daemon
  2. Run pm2 list concurrently after 100-200ms delay from previous command

Supporting information

Latest version 4.5.0

Log of the pm2 start command

The lines that are suspicious / important are marked in red

  2020-10-21T01:20:27.813Z pm2:paths pm2 home resolved to /redacted/.pm2 /redacted
  2020-10-21T01:20:27.814Z pm2:conf Using 2 parallelism (CONCURRENT_ACTIONS)
  2020-10-21T01:20:27.926Z pm2:client Using RPC file /redacted/.pm2/rpc.sock
  2020-10-21T01:20:27.926Z pm2:client Using PUB file /redacted/.pm2/pub.sock
  2020-10-21T01:20:27.927Z interactor:client [PING INTERACTOR] Trying to connect to Interactor daemon
  2020-10-21T01:20:27.928Z axon:sock connect attempt null:/redacted/.pm2/interactor.sock
  pm2 launched in no-daemon mode (you can add DEBUG="*" env variable to get more messages)
  2020-10-21T01:20:27.930Z pm2:client Using RPC file /redacted/.pm2/rpc.sock
  2020-10-21T01:20:27.930Z pm2:client Using PUB file /redacted/.pm2/pub.sock
  2020-10-21T01:20:27.930Z interactor:client [PING INTERACTOR] Trying to connect to Interactor daemon
  2020-10-21T01:20:27.930Z axon:sock connect attempt null:/redacted/.pm2/interactor.sock
  2020-10-21T01:20:27.931Z pm2:client [PING PM2] Trying to connect to server
  2020-10-21T01:20:27.931Z axon:sock connect attempt null:/redacted/.pm2/rpc.sock
  2020-10-21T01:20:27.934Z axon:sock error ENOENT
  2020-10-21T01:20:27.934Z axon:sock ignored ENOENT
  2020-10-21T01:20:27.934Z axon:sock error ENOENT
  2020-10-21T01:20:27.934Z axon:sock ignored ENOENT
  2020-10-21T01:20:27.934Z axon:sock error ECONNREFUSED
  2020-10-21T01:20:27.935Z axon:sock ignored ECONNREFUSED
  2020-10-21T01:20:28.039Z axon:sock attempting reconnect
  2020-10-21T01:20:28.039Z axon:sock closing
  2020-10-21T01:20:28.039Z axon:sock closing 0 connections
- 2020-10-21T01:20:28.039Z pm2:client Daemon not launched
  2020-10-21T01:20:28.039Z axon:sock connect attempt null:/redacted/.pm2/rpc.sock
  2020-10-21T09:20:28: PM2 log: Launching in no daemon mode
  2020-10-21T01:20:28.089Z axon:sock bind null:/redacted/.pm2/pub.sock
  2020-10-21T01:20:28.090Z axon:sock bind null:/redacted/.pm2/rpc.sock
- 2020-10-21T01:20:28.091Z axon:sock Got error while trying to bind Error: listen EADDRINUSE: address already in use /redacted/.pm2/pub.sock
      at Server.setupListenHandle [as _listen2] (net.js:1296:21)
      at listenInCluster (net.js:1361:12)
      at Server.listen (net.js:1458:5)
      at PubSocket.Socket.bind (/redacted/.config/yarn/global/node_modules/pm2-axon/lib/sockets/sock.js:413:15)
      at module.exports.Daemon.innerStart (/redacted/.config/yarn/global/node_modules/pm2/lib/Daemon.js:104:30)
      at /redacted/.config/yarn/global/node_modules/pm2/lib/Client.js:78:14
      at /redacted/.config/yarn/global/node_modules/pm2/lib/Client.js:320:14
      at processTicksAndRejections (internal/process/task_queues.js:79:11)
      at runNextTicks (internal/process/task_queues.js:66:3)
      at listOnTimeout (internal/timers.js:518:9)
- 2020-10-21T01:20:28.091Z axon:sock Got error while trying to bind Error: listen EADDRINUSE: address already in use /redacted/.pm2/rpc.sock
      at Server.setupListenHandle [as _listen2] (net.js:1296:21)
      at listenInCluster (net.js:1361:12)
      at Server.listen (net.js:1458:5)
      at RepSocket.Socket.bind (/redacted/.config/yarn/global/node_modules/pm2-axon/lib/sockets/sock.js:413:15)
      at module.exports.Daemon.innerStart (/redacted/.config/yarn/global/node_modules/pm2/lib/Daemon.js:134:30)
      at /redacted/.config/yarn/global/node_modules/pm2/lib/Client.js:78:14
      at /redacted/.config/yarn/global/node_modules/pm2/lib/Client.js:320:14
      at processTicksAndRejections (internal/process/task_queues.js:79:11)
      at runNextTicks (internal/process/task_queues.js:66:3)
      at listOnTimeout (internal/timers.js:518:9)
  2020-10-21T01:20:28.092Z axon:sock attempting reconnect
  2020-10-21T01:20:28.092Z axon:sock closing
  2020-10-21T01:20:28.092Z axon:sock closing 0 connections
  2020-10-21T01:20:28.092Z interactor:client Interactor Daemon not launched
  2020-10-21T01:20:28.092Z axon:sock connect attempt null:/redacted/.pm2/interactor.sock
  2020-10-21T01:20:28.092Z axon:sock attempting reconnect
  2020-10-21T01:20:28.092Z axon:sock closing
  2020-10-21T01:20:28.092Z axon:sock closing 0 connections
  2020-10-21T01:20:28.092Z interactor:client Interactor Daemon not launched
  2020-10-21T01:20:28.092Z axon:sock connect attempt null:/redacted/.pm2/interactor.sock
  2020-10-21T01:20:28.093Z axon:sock error ECONNREFUSED
  2020-10-21T01:20:28.093Z axon:sock ignored ECONNREFUSED
  2020-10-21T01:20:28.093Z axon:sock error ENOENT
  2020-10-21T01:20:28.093Z axon:sock ignored ENOENT
  2020-10-21T01:20:28.093Z axon:sock error ENOENT
  2020-10-21T01:20:28.093Z axon:sock ignored ENOENT
  2020-10-21T01:20:58.594Z pm2:worker [PM2][WORKER] My job here is done, next job in 30 seconds
  2020-10-21T01:21:28.599Z pm2:worker [PM2][WORKER] My job here is done, next job in 30 seconds
  2020-10-21T01:21:58.605Z pm2:worker [PM2][WORKER] My job here is done, next job in 30 seconds
  2020-10-21T01:22:28.611Z pm2:worker [PM2][WORKER] My job here is done, next job in 30 seconds
  2020-10-21T01:22:58.617Z pm2:worker [PM2][WORKER] My job here is done, next job in 30 seconds
Log of the pm2 list command

The lines that are suspicious / important are marked in red

  2020-10-21T01:20:27.699Z pm2:paths pm2 home resolved to /redacted/.pm2 /redacted
  2020-10-21T01:20:27.700Z pm2:conf Using 2 parallelism (CONCURRENT_ACTIONS)
  2020-10-21T01:20:27.823Z pm2:client Using RPC file /redacted/.pm2/rpc.sock
  2020-10-21T01:20:27.823Z pm2:client Using PUB file /redacted/.pm2/pub.sock
  2020-10-21T01:20:27.824Z interactor:client [PING INTERACTOR] Trying to connect to Interactor daemon
  2020-10-21T01:20:27.825Z axon:sock connect attempt null:/redacted/.pm2/interactor.sock
  2020-10-21T01:20:27.826Z pm2:client [PING PM2] Trying to connect to server
  2020-10-21T01:20:27.827Z axon:sock connect attempt null:/redacted/.pm2/rpc.sock
  2020-10-21T01:20:27.829Z axon:sock error ENOENT
  2020-10-21T01:20:27.829Z axon:sock ignored ENOENT
  2020-10-21T01:20:27.830Z axon:sock error ECONNREFUSED
  2020-10-21T01:20:27.830Z axon:sock ignored ECONNREFUSED
  2020-10-21T01:20:27.930Z axon:sock attempting reconnect
  2020-10-21T01:20:27.930Z axon:sock closing
  2020-10-21T01:20:27.930Z axon:sock closing 0 connections
- 2020-10-21T01:20:27.930Z pm2:client Daemon not launched
  2020-10-21T01:20:27.931Z axon:sock connect attempt null:/redacted/.pm2/rpc.sock
  [PM2] Spawning PM2 daemon with pm2_home=/redacted/.pm2
  2020-10-21T01:20:27.936Z axon:sock error ECONNREFUSED
  2020-10-21T01:20:27.936Z axon:sock ignored ECONNREFUSED
  2020-10-21T01:20:27.936Z axon:sock attempting reconnect
  2020-10-21T01:20:27.936Z axon:sock closing
  2020-10-21T01:20:27.936Z axon:sock closing 0 connections
  2020-10-21T01:20:27.936Z interactor:client Interactor Daemon not launched
  2020-10-21T01:20:27.936Z axon:sock connect attempt null:/redacted/.pm2/interactor.sock
  2020-10-21T01:20:27.936Z axon:sock error ENOENT
  2020-10-21T01:20:27.937Z axon:sock ignored ENOENT
- 2020-10-21T01:20:28.083Z pm2:client PM2 daemon launched with return message:  { online: true, success: true, pid: 8540, pm2_version: '4.5.0' }
  2020-10-21T01:20:28.085Z interactor:client Interaction file does not exists
  2020-10-21T01:20:28.085Z interactor:client Secret key is not defined in configuration {
    version_management: { active: true },
    public_key: undefined,
    secret_key: undefined,
    machine_name: 'redacted',
    pm2_version: '4.5.0',
    reverse_interact: true,
    info_node: 'https://root.keymetrics.io',
    agent_transport_websocket: 'false',
    agent_transport_axon: 'true'
  }
  [PM2] PM2 Successfully daemonized
- 2020-10-21T01:20:28.085Z pm2:client Launching RPC client on socket file /redacted/.pm2/rpc.sock
- 2020-10-21T01:20:28.085Z axon:sock connect attempt null:/redacted/.pm2/rpc.sock
- 2020-10-21T01:20:28.086Z axon:sock connect
  2020-10-21T01:20:28.087Z axon:sock add socket 0
  2020-10-21T01:20:28.088Z axon:queue flush 0 messages
  2020-10-21T01:20:28.088Z pm2:client RPC Connected to Daemon
  2020-10-21T01:20:28.093Z pm2:cli Now connected to daemon
  2020-10-21T01:20:28.093Z pm2:client Calling daemon method pm2:getVersion on rpc socket:/redacted/.pm2/rpc.sock
  2020-10-21T01:20:28.094Z pm2:client Calling daemon method pm2:getMonitorData on rpc socket:/redacted/.pm2/rpc.sock
  2020-10-21T01:20:28.097Z pm2:client Calling daemon method pm2:getSystemData on rpc socket:/redacted/.pm2/rpc.sock
  2020-10-21T01:20:28.098Z pm2:client Calling daemon method pm2:getMonitorData on rpc socket:/redacted/.pm2/rpc.sock
  ┌─────┬───────────┬─────────────┬─────────┬─────────┬──────────┬────────┬──────┬───────────┬──────────┬──────────┬──────────┬──────────┐
  │ id  │ name      │ namespace   │ version │ mode    │ pid      │ uptime │ ↺    │ status    │ cpu      │ mem      │ user     │ watching │
  └─────┴───────────┴─────────────┴─────────┴─────────┴──────────┴────────┴──────┴───────────┴──────────┴──────────┴──────────┴──────────┘
  2020-10-21T01:20:28.100Z interactor:client Disconnect RPC
  2020-10-21T01:20:28.100Z interactor:client RPC not launched
  2020-10-21T01:20:28.100Z axon:sock closing
  2020-10-21T01:20:28.100Z axon:sock closing 1 connections
  2020-10-21T01:20:28.101Z axon:sock remove socket 0
  2020-10-21T01:20:28.101Z pm2:client PM2 RPC cleanly closed
  2020-10-21T01:20:28.101Z pm2:cli This command took 0.275s to execute
Contents of the .pm2/pm2.pid file
8539

Contributor guide

Open the contributing guide

First steps

  1. Read the whole issue, then the project's contributing guide.
  2. Comment on the issue to say you are picking it up — it saves two people doing the same work.
  3. Fork the repository and make your change on a branch.
  4. Open a pull request that references the issue number.

Research direction

Reproduce the race with pm2 start path/to/pm2.config.json --no-daemon and a concurrent pm2 list after a short delay. Start by reading lib/Client.js and lib/Daemon.js, which appear in the socket-binding stack traces. Done means concurrent commands do not launch competing daemons, encounter EADDRINUSE, or leave pm2 start hanging.

Written by the indexing model from the issue text.

Assessment

Tech stack
javascript, nodejs
Domain
cli
Issue type
Bug
Difficulty
4/5
Estimated time
3-5 days
Activity status
Stale
Clarity
Mostly clear
Newbie friendliness
35/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.