Skip to content

Overlapping reloads collide on the single _old_<pm_id> registry slot, orphaning a cluster worker that keeps serving traffic with stale code #6129

Description

@ahrrfy

Environment

  • PM2: 6.0.14 (global install, Linux)
  • Node.js: 20.20.2
  • OS: Ubuntu (VPS)
  • App config: exec_mode: "cluster", instances: 1, wait_ready: true, listen_timeout (30s at the time), kill_timeout: 30000, autorestart: true

TL;DR

Reload.js parks the outgoing worker under a registry key derived only from the pm_id ('_old_' + id). If a second reload of the same app starts while a first reload is still pending (e.g. the new worker is slow to emit ready), the second reload overwrites that slot. Both pending cleanups then resolve the same key — so one worker is stopped twice and the other worker loses its registry entry without ever being stopped. The orphan:

  • keeps receiving round-robin traffic forever (distribution lives in Node's cluster.workers, which is untouched);
  • is invisible to pm2 list (filtered out by the isNaN(pm_id) guard);
  • is immune to pm2 delete / pm2 reload (they walk clusters_db only);
  • spams pm2.log with AXM MONITOR Unknown id _old_N at ~1 Hz indefinitely.

In our production incident the orphan served ~50% of all requests with 3-day-old code before being found and killed manually. The only remedy is a manual kill <pid>.

Issues #3624 (the 1 Hz Unknown id _old_1 noise filling 3 GB of logs) and #2028 (phantom _old_N processes) look like earlier sightings of the same defect; both went stale without a root-cause analysis.

The three code paths involved (quoted from the shipped 6.0.14 source)

1. The parking slot is keyed by pm_id alone — unconditional overwrite

lib/God/Reload.js, both softReload (line 26) and hardReload (line 109):

var t_key = '_old_' + id;

// Move old worker to tmp id
God.clusters_db[t_key] = God.clusters_db[id];   // <-- unconditional: clobbers any pending reload's slot
delete God.clusters_db[id];

var old_worker = God.clusters_db[t_key];
...
old_worker.pm2_env.pm_id = t_key;
old_worker.pm_id = t_key;

There is no per-app mutex in the God daemon and no check whether clusters_db[t_key] is already occupied by a previous, still-pending reload. Two CLI clients (or a CLI client plus a programmatic reload) can interleave freely.

2. Cleanup re-resolves the string key instead of using the captured worker

hardReload's success and timeout paths both end in:

return God.deleteProcessId(t_key, cb);

Because the key is resolved at stop time (not the old_worker object captured in the closure), after a slot overwrite both pending cleanups act on whatever the key currently points to — the newer of the two parked workers. It gets stopped/killed twice (we observed duplicated Stopping app:... id:_old_16 and duplicated pid=X msg=process killed lines for the same pid in the same second), while the earlier parked worker is never stopped by anyone.

3. The ready matcher can't distinguish generations

hardReload, lines ~135–142:

var listener = function (packet) {
    if (packet.raw === 'ready' &&
        packet.process.name === old_worker.pm2_env.name &&
        packet.process.pm_id === id) {

Every generation of the app shares (name, pm_id). A reload whose own worker never sends ready stays pending with a live listener until its timeout — and a later worker's single ready packet fires the stale listener (together with the current one). This is what synchronizes both cleanups into the same instant, and it means the collision does not require tight timing: a hung reload collides with any subsequent reload started within its listen_timeout window.

Why the orphan keeps serving traffic and can't be managed

  • Round-robin distribution is performed by the Node cluster module over cluster.workers; deleting the clusters_db entry does not remove the worker from rotation. The God daemon owns the listening socket, so the orphan keeps receiving connections.

  • getFormatedProcesses() (lib/God/Methods.js line 77) skips it, so pm2 list/pm2 jlist show nothing:

    // Avoid _old type pm_ids
    if (isNaN(God.clusters_db[key].pm2_env.pm_id)) continue;
  • pm2 delete <name> walks clusters_db only → the orphan is untouchable. Only a manual kill works.

  • Its pm2_env.pm_id was renamed to _old_16 before the slot was clobbered, so every @pm2/io heartbeat it emits fails the daemon-side lookup, producing AXM MONITOR Unknown id _old_16 once per second, forever (265,000 occurrences over 3 days in our logs — see How to disable log message "Unknown id _old_1"? #3624 for the same signature).

Evidence from our incident (timestamps from pm2.log)

10:44:58  App [app:16] starting in -cluster mode-        <- reload #1 spawns worker Y
10:45:28  App [app:16] online                            <- Y never sends 'ready' (CPU-starved by a build)
10:45:44  App [app:16] starting in -cluster mode-        <- reload #2 spawns worker Z, clobbers _old_16 (was X, now Y)
10:45:45  -reload- New worker listening                  <- Z's single 'ready' fires BOTH pending listeners
10:45:45  Stopping app:app id:_old_16
10:45:45  -reload- New worker listening                  <- duplicated
10:45:45  Stopping app:app id:_old_16                    <- duplicated
10:45:45  App [app:_old_16] exited ... via signal [SIGINT]   (once)
10:45:45  pid=2038426 msg=process killed                 <- worker Y killed...
10:45:45  pid=2038426 msg=process killed                 <- ...twice (same pid)
10:45:46  PM2 error: AXM MONITOR Unknown id _old_16      <- worker X orphaned; repeats at 1 Hz for 3 days

Note the selective duplication: the stop-path lines appear twice while disconnected / exited / online appear once — two cleanup invocations, one victim. Worker X (the orphan) never appears in any kill line because PM2 only logs pids on the kill path, and nobody ever killed it.

Minimal reproduction (concept)

  1. Cluster app, instances: 1, wait_ready: true, generous listen_timeout (e.g. 30s).
  2. Make the new worker slow to send ready (simplest: setTimeout(() => process.send('ready'), 25_000) — in the wild this was CPU starvation from a concurrent npm ci && npm run build).
  3. pm2 reload app — while it is pending, pm2 reload app again from a second shell.
  4. Observe: duplicated Stopping app:... id:_old_N lines, the same pid killed twice, pm2 list showing one worker while ps/pgrep shows two, and AXM MONITOR Unknown id _old_N at 1 Hz. The extra ps process serves traffic (hit any endpoint returning a per-process value and watch it alternate).

Suggested fixes (any one of these breaks the failure chain)

  1. Serialize reloads per app in the God daemon — reject or queue a reload for an app id that already has a _old_<id> entry pending (a one-line guard on the unconditional slot assignment would already prevent the orphan: if clusters_db[t_key] exists, fail fast).
  2. Make the parking key unique per reload (e.g. '_old_' + id + '_' + unique), and have cleanup operate on the captured worker object rather than re-resolving the string key at stop time.
  3. Match the ready packet to the specific spawned worker (pid or a per-reload nonce passed via env) instead of (name, pm_id), so a stale pending listener can't be fired by a later generation.
  4. Defense in depth: on any axm:monitor lookup miss for an _old_* id, log once and reconcile (the 1 Hz error is a perfect detection signal that today only fills disks — How to disable log message "Unknown id _old_1"? #3624).

Workarounds we deployed (for anyone else hitting this)

  • Funnel every mutating pm2 command through a wrapper that takes the same flock as the deploy pipeline (prevents overlapping reloads at the operational layer).
  • A cron watchdog that (a) greps new pm2.log bytes for Unknown id _old_ and (b) diffs pgrep output against pm2 jlist pids — alerting within a minute of an orphan's birth.
  • A post-reload deploy step that kills any pgrep-visible process absent from pm2 jlist (after a stabilization wait longer than kill_timeout).
  • Reduced listen_timeout and moved builds out of the live tree, so a pending reload's collision window is seconds, not tens of seconds.

Happy to provide fuller logs or test a patch.

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Projects

    No projects

    Milestone

    No milestone

    Relationships

    None yet

    Development

    No branches or pull requests

    Issue actions