Exception is not written to ~/.pm2/logs/*.log file from uncaughtException since it's synchronous

[dimikot]

What's going wrong?

Node v20.13.0 (I saw that in older versions too). When an exception is handled via uncaughtException in getUncaughtExceptionListener(), it tries to write it to the log file:

pm2/lib/ProcessContainer.js

Line 309 in a092db2

stds[type] && typeof stds[type].write == 'function' && stds[type].write(error + '\n');

But since uncaughtException is sync, and Node process dies immediately after it, the text is actually never written to the file.

This can be worked around with replacing .write() with:

fs.appendFileSync(stds[type]._file, error + '\n')

It's supposed to be safe, since it's anyway the very last IO the process is doing before dying. I don't propose to do it in other places, only in the exception handler.

How could we reproduce this issue?

Run some process under PM2 in cluster mode and add the following to its top-level code:

process.stderr.writer("test\n");
setTimeout(() => {
  throw Error("test!");
}, 1000);

You'll see that the error and stacktrace will correctly be displayed in pm2 logs output running simultaneously (since it's delivered through the bus directly to it), but it won't appear in any of ~/.pm2/logs/*.log files (despite the test message WILL be in the lohg.

Supporting information

--- PM2 report ----------------------------------------------------------------
Date                 : Tue May 07 2024 21:21:56 GMT-0700 (Pacific Daylight Time)
===============================================================================
--- Daemon -------------------------------------------------
pm2d version         : 5.3.1
node version         : 20.13.0
node path            : /Users/dmitry/.nvm/versions/node/v20.13.0/bin/pm2
argv                 : /Users/dmitry/.nvm/versions/node/v20.13.0/bin/node,/Users/dmitry/.nvm/versions/node/v20.13.0/lib/node_modules/pm2/lib/Daemon.js
argv0                : node
user                 : dmitry
uid                  : 501
gid                  : 20
uptime               : 7min
===============================================================================
--- CLI ----------------------------------------------------
local pm2            : 5.3.1
node version         : 20.13.0
node path            : /Users/dmitry/.nvm/versions/node/v20.13.0/bin/pm2
argv                 : /Users/dmitry/.nvm/versions/node/v20.13.0/bin/node,/Users/dmitry/.nvm/versions/node/v20.13.0/bin/pm2,report
argv0                : node
user                 : dmitry
uid                  : 501
gid                  : 20
===============================================================================
--- System info --------------------------------------------
arch                 : arm64
platform             : darwin
type                 : Darwin
cpus                 : Apple M1 Pro
cpus nb              : 10
freemem              : 276856832
totalmem             : 34359738368
home                 : /Users/dmitry
===============================================================================
--- PM2 list -----------------------------------------------
┌────┬───────────┬─────────────┬─────────┬─────────┬──────────┬────────┬──────┬───────────┬──────────┬──────────┬──────────┬──────────┐
│ id │ name      │ namespace   │ version │ mode    │ pid      │ uptime │ ↺    │ status    │ cpu      │ mem      │ user     │ watching │
├────┼───────────┼─────────────┼─────────┼─────────┼──────────┼────────┼──────┼───────────┼──────────┼──────────┼──────────┼──────────┤
│ 0  │ server    │ default     │ N/A     │ cluster │ 55907    │ 0      │ 203  │ launching │ 0%       │ 0b       │ dmitry   │ disabled │
└────┴───────────┴─────────────┴─────────┴─────────┴──────────┴────────┴──────┴───────────┴──────────┴──────────┴──────────┴──────────┘
[PM2][WARN] Current process list is not synchronized with saved list. App graphql pm2-rotate graphql graphql graphql graphql graphql graphql graphql graphql graphql differs. Type 'pm2 save' to synchronize.
===============================================================================
--- Daemon logs --------------------------------------------
/Users/dmitry/.pm2/pm2.log last 20 lines:
PM2        | 2024-05-07T21:21:46: PM2 log: App [server:0] online
PM2        | 2024-05-07T21:21:48: PM2 log: App name:server id:0 disconnected
PM2        | 2024-05-07T21:21:48: PM2 log: App [server:0] exited with code [0] via signal [SIGINT]
PM2        | 2024-05-07T21:21:48: PM2 log: App [server:0] starting in -cluster mode-
PM2        | 2024-05-07T21:21:48: PM2 log: App [server:0] online
PM2        | 2024-05-07T21:21:50: PM2 log: App name:server id:0 disconnected
PM2        | 2024-05-07T21:21:50: PM2 log: App [server:0] exited with code [0] via signal [SIGINT]
PM2        | 2024-05-07T21:21:50: PM2 log: App [server:0] starting in -cluster mode-
PM2        | 2024-05-07T21:21:51: PM2 log: App [server:0] online
PM2        | 2024-05-07T21:21:52: PM2 log: App name:server id:0 disconnected
PM2        | 2024-05-07T21:21:52: PM2 log: App [server:0] exited with code [0] via signal [SIGINT]
PM2        | 2024-05-07T21:21:52: PM2 log: App [server:0] starting in -cluster mode-
PM2        | 2024-05-07T21:21:53: PM2 log: App [server:0] online
PM2        | 2024-05-07T21:21:54: PM2 log: App name:server id:0 disconnected
PM2        | 2024-05-07T21:21:54: PM2 log: App [server:0] exited with code [0] via signal [SIGINT]
PM2        | 2024-05-07T21:21:54: PM2 log: App [server:0] starting in -cluster mode-
PM2        | 2024-05-07T21:21:55: PM2 log: App [server:0] online
PM2        | 2024-05-07T21:21:56: PM2 log: App name:server id:0 disconnected
PM2        | 2024-05-07T21:21:56: PM2 log: App [server:0] exited with code [0] via signal [SIGINT]
PM2        | 2024-05-07T21:21:56: PM2 log: App [server:0] starting in -cluster mode-