Unitech / Unitech/pm2

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

Open
#5,816 0 comments 0 reactions 0 assignees View on GitHub

Nobody has claimed this yet.

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

Description

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:
https://github.com/Unitech/pm2/blob/a092db2d89e7206ef446d9eb6e385d182d2f0c58/lib/ProcessContainer.js#L309

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-

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

Start in lib/ProcessContainer.js at getUncaughtExceptionListener(), especially the logging call around line 309. Reproduce the issue with a clustered PM2 process that throws from a timeout, then inspect the corresponding ~/.pm2/logs/*.log file. Done means the uncaught exception and stack trace appear in that file as well as in pm2 logs output.

Written by the indexing model from the issue text.

Assessment

Tech stack
javascript, node.js
Domain
cli, devops
Issue type
Bug
Difficulty
2/5
Estimated time
1-3 hours
Activity status
Stale
Clarity
Clearly specified
Newbie friendliness
50/100

Get new issues in your inbox

A short digest of beginner-friendly GitHub issues.