Skip to content

fix: drop bus subscribers that stopped reading - #6157

Open
diyorbekrustamjonov wants to merge 1 commit into
Unitech:developmentfrom
diyorbekrustamjonov:fix/pub-slow-subscriber
Open

fix: drop bus subscribers that stopped reading#6157
diyorbekrustamjonov wants to merge 1 commit into
Unitech:developmentfrom
diyorbekrustamjonov:fix/pub-slow-subscriber

Conversation

@diyorbekrustamjonov

Copy link
Copy Markdown
Q A
Bug fix? yes
New feature? no
BC breaks? no
Deprecations? no
Tests pass? yes
Fixed tickets #5145, likely #6113 #5802 #5917 #4737 #4647 #3049 (see below)
License MIT
Doc PR none yet, new env var PM2_PUB_MAX_PENDING_BYTES is described below

What happens

Any client subscribed to pub.sock that stops reading makes the God Daemon grow without limit until it dies with FATAL ERROR: Reached heap limit and every frame of the stack in [PM2 ...: God Daemon]. The easiest way to get such a client is pm2 logs <id> suspended with Ctrl+Z instead of Ctrl+C, or left in an ssh session that died. After the crash the fork children survive as orphans, and pm2 resurrect starts a second copy of each of them.

On a production host with 63 apps (pm2 5.4.2, Node 20) two suspended pm2 logs 1 clients made the daemon grow by about 170 MB per minute and hit the 4 GB heap limit in 14 minutes. ss -xan showed the two pub.sock connections with Send-Q stuck at 215040 bytes (the kernel buffer), the clients were in state T.

Root cause

modules/pm2-axon/lib/sockets/pub.js:

for (var sock of socks) {
    if (sock.writable) sock.write(buf);
}

writable stays true while the peer is alive, so once the kernel buffer is full every message is queued in sock.writableLength forever. pm2 logs <id> receives the events of all apps (the filter runs client side), so each stuck client costs the daemon the full log stream of the host.

Fix

  • PubSocket gets a max pending bytes setting (default Infinity, no behaviour change for the library itself). In send and sendv2 a peer with more than that pending is destroyed and a slow subscriber event is emitted with the socket and the pending byte count. The socket is destroyed before the event is emitted on purpose: the daemon logs through the bus, so a listener that logs re-enters send and must find the peer not writable.
  • The daemon sets it to cst.PUB_MAX_PENDING_BYTES, 16 MB by default, PM2_PUB_MAX_PENDING_BYTES overrides it, 0 disables. A dropped client shows up in pm2.log as Bus subscriber is not reading (N bytes pending), dropping it. Sub sockets reconnect on their own, so a pm2 logs that is resumed just continues.
  • Unit test modules/pm2-axon/test/test.pub.slow-subscriber.js: a paused raw subscriber is dropped, a reading one is kept. npm run test:axon passes.

Reproduction and measurements

Linux container, Node 22, one app writing ~3.3 MB/s of JSON lines to stdout, daemon started with PM2_NODE_OPTIONS=--max-old-space-size=200, pm2 logs noisy started and then kill -STOP:

before after
ss -xan Send-Q of the pub.sock connection 236032, constant connection closed within 5 s
daemon RSS after 60 s 327 MB 77 MB
daemon RSS after 227 s 939 MB, still growing ~4 MB/s 77 MB
pm2.log nothing until the OOM Bus subscriber is not reading (16783360 bytes pending), dropping it

With 30 apps at 200 lines/s each the unpatched daemon reaches the 200 MB heap limit in about 5 minutes and dies with the same stack trace as in the issues below.

Related issues

@CLAassistant

Copy link
Copy Markdown

CLA assistant check
Thank you for your submission! We really appreciate it. Like many open source projects, we ask that you sign our Contributor License Agreement before we can accept your contribution.
You have signed the CLA already but the status is still pending? Let us recheck it.

A `pm2 logs` or `pm2 monit` client that stops reading pub.sock (suspended
with Ctrl+Z, dead ssh session) fills the kernel socket buffer, after which
PubSocket.send queues every log line of every app in the daemon memory
without any limit. The God Daemon then dies with "Reached heap limit" and
its fork children are left behind as orphans.

PubSocket gets a `max pending bytes` setting: once a peer has more than
that waiting in its write queue it is destroyed (it may reconnect) and a
`slow subscriber` event is emitted. The daemon enables it with 16 MB by
default, configurable with PM2_PUB_MAX_PENDING_BYTES (0 disables), and
logs the drop in pm2.log.

Refs Unitech#5145 Unitech#6113 Unitech#5802 Unitech#5917 Unitech#4737 Unitech#4647 Unitech#3049
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

None yet

Projects

None yet

Development

Successfully merging this pull request may close these issues.

2 participants