-
Notifications
You must be signed in to change notification settings - Fork 6
fix(kernel-cli): log fatal exits from daemon-entry before terminating #966
New issue
Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.
By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.
Already on GitHub? Sign in to your account
Open
FUDCo
wants to merge
2
commits into
main
Choose a base branch
from
chip/daemon-entry-fatal-logging
base: main
Could not load branches
Branch not found: {{ refName }}
Loading
Could not load tags
Nothing to show
Loading
Are you sure you want to change the base?
Some commits from the old base branch may be removed from the timeline,
and old review comments may become outdated.
+93
−3
Open
Changes from all commits
Commits
Show all changes
2 commits
Select commit
Hold shift + click to select a range
File filter
Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
There are no files selected for viewing
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
| Original file line number | Diff line number | Diff line change | ||||
|---|---|---|---|---|---|---|
|
|
@@ -4,12 +4,24 @@ import { startDaemon } from '@metamask/kernel-node-runtime/daemon'; | |||||
| import type { DaemonHandle } from '@metamask/kernel-node-runtime/daemon'; | ||||||
| import type { LogEntry } from '@metamask/logger'; | ||||||
| import { Logger } from '@metamask/logger'; | ||||||
| import { appendFileSync } from 'node:fs'; | ||||||
| import { mkdir, readFile, rm, writeFile } from 'node:fs/promises'; | ||||||
| import { join } from 'node:path'; | ||||||
|
|
||||||
| import { getOcapHome } from '../ocap-home.ts'; | ||||||
| import { isProcessAlive } from '../utils.ts'; | ||||||
|
|
||||||
| // Install exit-cause handlers at module load, before main() runs, so | ||||||
| // failures during kernel init also leave a fingerprint. daemon-entry | ||||||
| // runs with `stdio: 'ignore'` under the CLI spawner (see | ||||||
| // `daemon-spawn.ts`); without these, an uncaught exception, an | ||||||
| // unhandled rejection, or a SIGHUP terminates the process silently | ||||||
| // with no record in `daemon.log`. Silent deaths cost real debugging | ||||||
| // time — see the run-notes for two past cases where a daemon | ||||||
| // disappeared with no trace. Every terminating path now writes at | ||||||
| // least one line before the process goes away. | ||||||
| installFatalHandlers(join(getOcapHome(), 'daemon.log')); | ||||||
|
|
||||||
| main().catch((error) => { | ||||||
| process.stderr.write(`Daemon fatal: ${String(error)}\n`); | ||||||
| process.exitCode = 1; | ||||||
|
|
@@ -133,11 +145,87 @@ async function readDaemonPid(pidPath: string): Promise<number | undefined> { | |||||
| * @returns A log transport function. | ||||||
| */ | ||||||
| function makeFileTransport(logPath: string) { | ||||||
| // eslint-disable-next-line @typescript-eslint/no-require-imports, n/global-require -- need sync fs for log transport | ||||||
| const fs = require('node:fs') as typeof import('node:fs'); | ||||||
| return (entry: LogEntry): void => { | ||||||
| const line = `[${new Date().toISOString()}] [${entry.level}] ${entry.message ?? ''} ${(entry.data ?? []).map(String).join(' ')}\n`; | ||||||
| // eslint-disable-next-line n/no-sync -- synchronous write needed for log transport reliability | ||||||
| fs.appendFileSync(logPath, line); | ||||||
| appendFileSync(logPath, line); | ||||||
| }; | ||||||
| } | ||||||
|
|
||||||
| /** | ||||||
| * Append a fatal-path entry to `daemon.log` synchronously. Used from | ||||||
| * `process.on('uncaughtException' | 'unhandledRejection' | 'SIGHUP')` | ||||||
| * handlers where the async logger pipeline can't be trusted to | ||||||
| * flush before the process exits. Best-effort: if the log file is | ||||||
| * unwritable we swallow the error rather than throw from a fatal | ||||||
| * handler. | ||||||
| * | ||||||
| * @param logPath - The daemon-log file path. | ||||||
| * @param message - Short label for the entry. | ||||||
| * @param detail - Optional extra data (stack, error, etc.) — coerced | ||||||
| * to string. | ||||||
| */ | ||||||
| function logFatalSync( | ||||||
| logPath: string, | ||||||
| message: string, | ||||||
| detail?: string | number, | ||||||
| ): void { | ||||||
| try { | ||||||
| const tail = detail === undefined ? '' : ` ${detail}`; | ||||||
| const line = `[${new Date().toISOString()}] [error] ${message}${tail}\n`; | ||||||
| // eslint-disable-next-line n/no-sync -- fatal handler must flush before exit | ||||||
| appendFileSync(logPath, line); | ||||||
| } catch { | ||||||
| // Best-effort — the daemon is dying either way. | ||||||
| } | ||||||
| } | ||||||
|
|
||||||
| /** | ||||||
| * Install process-level handlers that guarantee a log line is | ||||||
| * written for every terminating event before the daemon exits. | ||||||
| * | ||||||
| * Handlers registered: | ||||||
| * | ||||||
| * - `uncaughtException` — the classic silent-death path. Node's | ||||||
| * default is to print the stack to stderr and exit with code 1; | ||||||
| * under `stdio: 'ignore'` (how the daemon is spawned) that | ||||||
| * default writes nowhere. | ||||||
| * - `unhandledRejection` — currently defaults to a warning in | ||||||
| * Node, but future Node versions treat it as uncaughtException; | ||||||
| * either way we want a fingerprint. | ||||||
| * - `SIGHUP` — sent when the controlling terminal disappears | ||||||
| * (ssh session closed, laptop lid closed while the daemon was | ||||||
| * under an interactive shell). Default action terminates the | ||||||
| * process; installing a handler lets us log the fact before | ||||||
| * exiting. | ||||||
| * - `exit` — last-ditch record. Fires during every exit, including | ||||||
| * the ones already logged by the handlers above. Sync-safe: only | ||||||
| * sync APIs are usable here. | ||||||
| * | ||||||
| * @param logPath - The daemon-log file path. | ||||||
| */ | ||||||
| function installFatalHandlers(logPath: string): void { | ||||||
| /* eslint-disable n/no-sync, n/no-process-exit -- fatal handlers must flush synchronously and terminate deterministically */ | ||||||
| process.on('uncaughtException', (error: unknown) => { | ||||||
| const detail = | ||||||
| error instanceof Error ? (error.stack ?? error.message) : String(error); | ||||||
| logFatalSync(logPath, 'Uncaught exception (about to exit):', detail); | ||||||
|
Member
There was a problem hiding this comment. Choose a reason for hiding this commentThe reason will be displayed to describe this comment to others. Learn more.
Suggested change
|
||||||
| process.exit(1); | ||||||
| }); | ||||||
| process.on('unhandledRejection', (reason: unknown) => { | ||||||
| const detail = | ||||||
| reason instanceof Error | ||||||
| ? (reason.stack ?? reason.message) | ||||||
| : String(reason); | ||||||
| logFatalSync(logPath, 'Unhandled rejection (about to exit):', detail); | ||||||
| process.exit(1); | ||||||
| }); | ||||||
| process.on('SIGHUP', () => { | ||||||
| logFatalSync(logPath, 'SIGHUP received; exiting.'); | ||||||
| process.exit(0); | ||||||
| }); | ||||||
| process.on('exit', (code) => { | ||||||
| logFatalSync(logPath, `Process exiting (code=${code}).`); | ||||||
| }); | ||||||
| /* eslint-enable n/no-sync, n/no-process-exit */ | ||||||
| } | ||||||
Oops, something went wrong.
Add this suggestion to a batch that can be applied as a single commit.
This suggestion is invalid because no changes were made to the code.
Suggestions cannot be applied while the pull request is closed.
Suggestions cannot be applied while viewing a subset of changes.
Only one suggestion per line can be applied in a batch.
Add this suggestion to a batch that can be applied as a single commit.
Applying suggestions on deleted lines is not supported.
You must change the existing code in this line in order to create a valid suggestion.
Outdated suggestions cannot be applied.
This suggestion has been applied or marked resolved.
Suggestions cannot be applied from pending reviews.
Suggestions cannot be applied on multi-line comments.
Suggestions cannot be applied while the pull request is queued to merge.
Suggestion cannot be applied right now. Please check back later.
There was a problem hiding this comment.
Choose a reason for hiding this comment
The reason will be displayed to describe this comment to others. Learn more.
The logger dispatch routine is already synchronous; async methods follow 'spray and pray' semantics, i.e. best effort.
I think the
process.onhandlers are doing the work here, not this function.