diff --git a/profiler-cli/README.md b/profiler-cli/README.md index d8b941f0ac..2593de72ce 100644 --- a/profiler-cli/README.md +++ b/profiler-cli/README.md @@ -116,6 +116,25 @@ For `filter push`, exactly one flag per push. For ephemeral use, multiple flags Sessions are stored in `~/.profiler-cli/` (or `$PROFILER_CLI_SESSION_DIR` to override). +Each session keeps a metadata file, a Unix domain socket (a named pipe on Windows), and a daemon log in that directory. The daemon log is the first place to look when a session misbehaves, and `profiler-cli` prints its path in error messages. + +## Running in a sandbox + +`profiler-cli` runs its daemon in a separate process and talks to it over a Unix domain socket in the session directory, so a sandbox has to allow two things: + +- writing to the session directory, and +- creating and connecting to Unix domain sockets inside it. + +If the home directory is not writable, point the CLI somewhere it can write: + +```bash +export PROFILER_CLI_SESSION_DIR=/tmp/profiler-cli +``` + +Keep that path short. Unix socket paths are limited to 104 bytes on macOS and 108 on Linux, and the session directory is part of the socket path. + +If Unix domain sockets are blocked outright, allow them in the sandbox policy or run `profiler-cli` outside the sandbox. + ## Contributing See [CONTRIBUTING.md](CONTRIBUTING.md) for architecture, build instructions, and how to add new commands. diff --git a/profiler-cli/src/client.ts b/profiler-cli/src/client.ts index 4704c2a063..c9b41c5192 100644 --- a/profiler-cli/src/client.ts +++ b/profiler-cli/src/client.ts @@ -17,16 +17,31 @@ import type { CommandResult, } from './protocol'; import { + cleanupIfDaemonGone, cleanupSession, generateSessionId, getCurrentSessionId, getCurrentSocketPath, + getLogPath, + getLogSize, getSocketPath, + getStartupErrorPath, isDaemonReachable, loadSessionMetadata, + probeDaemonSocket, + readLogTail, + takeStartupError, validateSession, waitForSocketClose, } from './session'; +import { + assertSocketPathUsable, + describeManualKill, + describeSocketConnectError, + ensureSessionDirUsable, + indentBlock, + toErrorMessage, +} from './diagnostics'; import { BUILD_HASH } from './constants'; type BuildMismatchShutdownResult = 'stopped' | 'already-dead' | 'still-running'; @@ -62,12 +77,16 @@ async function sendMessageToSocket( }); socket.on('error', (error) => { - reject(new Error(`Socket error: ${error.message}`)); + reject(new Error(describeSocketConnectError(socketPath, error))); }); socket.on('timeout', () => { socket.destroy(); - reject(new Error('Connection timeout')); + reject( + new Error( + `Timed out after ${timeoutMs}ms waiting for the daemon on ${socketPath} to answer.` + ) + ); }); socket.setTimeout(timeoutMs); @@ -118,6 +137,53 @@ async function attemptShutdownOnBuildMismatch( } } +/** + * Explain why a session that has metadata on disk cannot be reached, and clean + * up after it when the daemon is provably gone. + * + * A dead daemon and a sandbox that forbids connect() look identical to + * `validateSession`, but only the first one justifies deleting the session + * files. Throwing away a healthy session because this process is not allowed + * to talk to it would make the situation worse. + */ +export async function explainUnreachableSession( + sessionDir: string, + sessionId: string +): Promise { + const metadata = loadSessionMetadata(sessionDir, sessionId); + + if (!metadata) { + // Read the startup record before cleaning up, which deletes it. + const startupError = takeStartupError(sessionDir, sessionId); + cleanupSession(sessionDir, sessionId); + if (startupError) { + return [ + `The daemon for session ${sessionId} failed to start:`, + indentBlock(startupError), + ].join('\n'); + } + return `Unknown session ${sessionId}: no metadata found in ${sessionDir}. Run "profiler-cli load " to start a session.`; + } + + const unreachable = await cleanupIfDaemonGone( + sessionDir, + sessionId, + metadata.socketPath + ); + if (!unreachable) { + // The daemon answered on the retry, so the original check was a blip. + return `Session ${sessionId} could not be validated, but its daemon is responding again. Please retry the command.`; + } + + return [ + `Session ${sessionId} is not reachable.`, + describeSocketConnectError(metadata.socketPath, unreachable.error), + ...(unreachable.cleanedUp + ? [] + : [`Daemon log: ${metadata.logPath}`, describeManualKill(metadata.pid)]), + ].join('\n'); +} + /** * Send a message to the daemon and return the raw response. */ @@ -134,9 +200,8 @@ async function sendRawMessage( // Validate the session if (!(await validateSession(sessionDir, resolvedSessionId))) { - cleanupSession(sessionDir, resolvedSessionId); throw new Error( - `Session ${resolvedSessionId} is not running or is invalid.` + await explainUnreachableSession(sessionDir, resolvedSessionId) ); } @@ -222,15 +287,103 @@ function hasProxyEnvVar(): boolean { ); } -function formatEarlyExitError(earlyExit: { +type DaemonEarlyExit = { code: number | null; signal: NodeJS.Signals | null; -}): string { - const reason = - earlyExit.signal !== null - ? `signal ${earlyExit.signal}` - : `exit code ${earlyExit.code}`; - return `Daemon process exited unexpectedly during startup (${reason}). Run with PROFILER_CLI_SESSION_DIR set and check the session directory for a log file, or re-run after upgrading Node.js.`; +}; + +/** + * What is needed to dig a failure reason out of a session directory. + * `logStartByte` is where the log stood before this daemon was spawned, so that + * a session id reused after an earlier failure cannot pass off that earlier + * daemon's output as this one's. + */ +type DaemonFailureContext = { + sessionDir: string; + sessionId: string; + logStartByte: number; +}; + +/** + * What the client knows about the daemon at the point it gives up on it. + */ +type DaemonCondition = + // The process is gone. `foregroundCommand` reproduces the spawn with stdio + // attached, which is the only way to see output from a daemon that died + // without writing anything. + | { kind: 'exited'; foregroundCommand: string } + // The process is alive but has not published its session metadata yet. + | { kind: 'still-starting'; pid: number | undefined }; + +/** + * Describe the daemon's condition, to go under a headline that has already + * stated what went wrong. `silent` says the daemon left neither a startup error + * nor a log, so this is all the message will have to go on. + */ +function describeDaemonCondition( + condition: DaemonCondition, + silent: boolean +): string[] { + if (condition.kind === 'still-starting') { + return [ + 'It has not exited, so it is most likely still starting, and retrying often works.', + ...(condition.pid ? [describeManualKill(condition.pid)] : []), + ]; + } + + if (!silent) { + // Whatever it managed to log says more about how far it got than a guess. + return []; + } + + return [ + 'It died before it could report a reason, so either the runtime failed to start or something outside the process killed it (out of memory, or a sandbox shutting it down).', + `Run it in the foreground to see what the runtime prints: ${condition.foregroundCommand}`, + ]; +} + +/** + * Turn a daemon that never came up into an actionable message. + * + * The daemon runs detached with its stdio discarded, so the reason has to be + * recovered from the session directory: first the startup error file the daemon + * writes on the way out, then the tail of its log, and failing both, whatever + * its condition allows us to say. + */ +function formatDaemonFailure( + context: DaemonFailureContext, + headline: string, + condition: DaemonCondition +): string { + const { sessionDir, sessionId, logStartByte } = context; + + const startupError = takeStartupError(sessionDir, sessionId); + if (startupError) { + // The daemon said why itself, which beats anything inferred here. + return [`${headline}:`, indentBlock(startupError)].join('\n'); + } + + const logPath = getLogPath(sessionDir, sessionId); + const logTail = readLogTail(sessionDir, sessionId, logStartByte); + if (logTail) { + return [ + `${headline}.`, + ...describeDaemonCondition(condition, false), + `Last lines of ${logPath}:`, + indentBlock(logTail), + ].join('\n'); + } + + return [ + `${headline}, without writing anything to ${logPath}.`, + ...describeDaemonCondition(condition, true), + ].join('\n'); +} + +function describeDaemonExit(earlyExit: DaemonEarlyExit): string { + return earlyExit.signal !== null + ? `killed by signal ${earlyExit.signal}` + : `exit code ${earlyExit.code}`; } /** @@ -261,16 +414,62 @@ export async function startNewDaemon( // session to wait for (avoids race condition with existing sessions) const targetSessionId = sessionId || generateSessionId(); + // Before ensureSessionDirUsable(), so a path the kernel will never accept is + // rejected without first creating a directory tree for it. + assertSocketPathUsable(getSocketPath(sessionDir, targetSessionId)); + + // The daemon cannot report an unusable session directory, because it needs + // that directory to reach us at all, so check it here, while there is still + // a terminal to print to. + ensureSessionDirUsable(sessionDir); + + // A record left by an earlier daemon on this session id would be mistaken + // for this one's. The log cannot be deleted the same way, since it is kept + // on purpose for debugging, so note where it ends instead. + fs.rmSync(getStartupErrorPath(sessionDir, targetSessionId), { force: true }); + const failureContext: DaemonFailureContext = { + sessionDir, + sessionId: targetSessionId, + logStartByte: getLogSize(sessionDir, targetSessionId), + }; + if (sessionId) { + const alreadyRunning = `Session ${targetSessionId} is already running. Stop it first or choose a different session id.`; + const existingSession = await validateSession(sessionDir, targetSessionId); if (existingSession) { - throw new Error( - `Session ${targetSessionId} is already running. Stop it first or choose a different session id.` - ); + throw new Error(alreadyRunning); } - if (loadSessionMetadata(sessionDir, targetSessionId)) { - cleanupSession(sessionDir, targetSessionId); + // Taking over the id unlinks the socket and overwrites the metadata, so + // only retire the old session once its daemon is provably gone. + const staleMetadata = loadSessionMetadata(sessionDir, targetSessionId); + if (staleMetadata) { + const unreachable = await cleanupIfDaemonGone( + sessionDir, + targetSessionId, + staleMetadata.socketPath + ); + + if (unreachable === null) { + // Answered on the retry, so the failed validation was a blip. + throw new Error(alreadyRunning); + } + + if (!unreachable.cleanedUp) { + throw new Error( + [ + `Session ${targetSessionId} already exists and cannot be reached, so its files were left in place.`, + describeSocketConnectError( + staleMetadata.socketPath, + unreachable.error + ), + `Daemon log: ${staleMetadata.logPath}`, + describeManualKill(staleMetadata.pid), + 'Alternatively, load the profile under a different session id with --session.', + ].join('\n') + ); + } } } @@ -319,7 +518,7 @@ export async function startNewDaemon( // Observe early daemon death so spawn-time failures surface immediately // instead of as a generic 500ms validation timeout. const daemonStartupState: { - earlyExit: { code: number | null; signal: NodeJS.Signals | null } | null; + earlyExit: DaemonEarlyExit | null; spawnError: Error | null; } = { earlyExit: null, spawnError: null }; child.once('exit', (code, signal) => { @@ -329,6 +528,17 @@ export async function startNewDaemon( daemonStartupState.spawnError = err; }); + const foregroundCommand = `${process.execPath} ${scriptPath} --daemon ${absolutePath} --session ${targetSessionId}`; + + const daemonExitedError = (earlyExit: DaemonEarlyExit, what: string) => + new Error( + formatDaemonFailure( + failureContext, + `The profiler-cli daemon ${what} (${describeDaemonExit(earlyExit)})`, + { kind: 'exited', foregroundCommand } + ) + ); + // Phase 1: Wait for daemon to be validated (short timeout) const daemonStartMaxAttempts = 10; // 10 * 50ms = 500ms let attempts = 0; @@ -339,11 +549,18 @@ export async function startNewDaemon( if (daemonStartupState.spawnError) { throw new Error( - `Failed to spawn daemon: ${daemonStartupState.spawnError.message}` + [ + `Failed to spawn the profiler-cli daemon (${process.execPath}).`, + `Underlying error: ${daemonStartupState.spawnError.message}`, + 'Sandboxes and process-limited environments can refuse to start detached child processes.', + ].join('\n') ); } if (daemonStartupState.earlyExit) { - throw new Error(formatEarlyExitError(daemonStartupState.earlyExit)); + throw daemonExitedError( + daemonStartupState.earlyExit, + 'exited during startup' + ); } // Validate the session (checks metadata exists, process running, socket exists) @@ -356,10 +573,38 @@ export async function startNewDaemon( // Check if daemon started successfully after polling if (!(await validateSession(sessionDir, targetSessionId))) { if (daemonStartupState.earlyExit) { - throw new Error(formatEarlyExitError(daemonStartupState.earlyExit)); + throw daemonExitedError( + daemonStartupState.earlyExit, + 'exited during startup' + ); } + + // The daemon is still alive, so either it published its socket and this + // process is not allowed to connect to it, or it has not got that far yet. + const metadata = loadSessionMetadata(sessionDir, targetSessionId); + if (metadata) { + const probeError = await probeDaemonSocket(metadata.socketPath); + if (probeError) { + throw new Error( + [ + `The profiler-cli daemon started but cannot be reached.`, + describeSocketConnectError(metadata.socketPath, probeError), + `Daemon log: ${metadata.logPath}`, + describeManualKill(metadata.pid), + ].join('\n') + ); + } + } + + // It has not exited and has not published its metadata, so it is still + // starting. Saying it died here would be wrong, and would send the user + // looking for an environment problem that the checks above have ruled out. throw new Error( - `Failed to start daemon: session not validated after ${daemonStartMaxAttempts * 50}ms` + formatDaemonFailure( + failureContext, + `The profiler-cli daemon did not become ready within ${daemonStartMaxAttempts * 50}ms`, + { kind: 'still-starting', pid: child.pid } + ) ); } @@ -376,6 +621,15 @@ export async function startNewDaemon( await new Promise((resolve) => setTimeout(resolve, 100)); attempts++; + // A daemon that dies while loading (out of memory, killed by the sandbox) + // would otherwise keep us polling a dead socket until the load timeout. + if (daemonStartupState.earlyExit) { + throw daemonExitedError( + daemonStartupState.earlyExit, + 'died while loading the profile' + ); + } + try { const response = await sendStatusMessage(sessionDir, targetSessionId); @@ -426,6 +680,10 @@ export async function startNewDaemon( /** * Stop a running daemon. + * + * Only reports success once the daemon is known to be gone. One that merely + * cannot be reached may still be running, and saying it stopped would leave + * the user with a process no command can find. */ export async function stopDaemon( sessionDir: string, @@ -437,16 +695,47 @@ export async function stopDaemon( throw new Error('No active session to stop.'); } - // Send shutdown command + const metadata = loadSessionMetadata(sessionDir, resolvedSessionId); + if (!metadata) { + cleanupSession(sessionDir, resolvedSessionId); + console.log(`Session ${resolvedSessionId} was not running.`); + return; + } + try { await sendMessage(sessionDir, { type: 'shutdown' }, resolvedSessionId); } catch (error) { - // If the daemon is already dead, that's fine - console.error(`Note: ${error}`); + // An already-dead daemon is a successful stop, an unreachable live one is + // not. + const unreachable = await cleanupIfDaemonGone( + sessionDir, + resolvedSessionId, + metadata.socketPath + ); + if (unreachable === null || !unreachable.cleanedUp) { + // The quoted reason already ends with the kill advice, so no + // describeManualKill(). + throw new Error( + [ + `Session ${resolvedSessionId} could not be stopped, and its daemon (pid ${metadata.pid}) may still be running:`, + indentBlock(toErrorMessage(error)), + ].join('\n') + ); + } + + console.error(['Note:', indentBlock(toErrorMessage(error))].join('\n')); + console.log(`Session ${resolvedSessionId} is no longer running.`); + return; } - // Wait a bit for cleanup - await new Promise((resolve) => setTimeout(resolve, 500)); + if (!(await waitForSocketClose(metadata.socketPath))) { + throw new Error( + [ + `Session ${resolvedSessionId} acknowledged the shutdown but its daemon is still listening on ${metadata.socketPath}.`, + describeManualKill(metadata.pid), + ].join('\n') + ); + } console.log(`Session ${resolvedSessionId} stopped`); } diff --git a/profiler-cli/src/commands/session.ts b/profiler-cli/src/commands/session.ts index 889c1d3ad0..5f2f975158 100644 --- a/profiler-cli/src/commands/session.ts +++ b/profiler-cli/src/commands/session.ts @@ -7,14 +7,23 @@ */ import type { Command } from 'commander'; +import type { SessionMetadata } from '../protocol'; import { wasExplicit } from './shared'; import { + cleanupIfDaemonGone, cleanupSession, getCurrentSessionId, listSessions, + loadSessionMetadata, setCurrentSession, validateSession, } from '../session'; +import { explainUnreachableSession } from '../client'; +import { + SOCKET_SANDBOX_HINT, + isPermissionErrno, + toErrorMessage, +} from '../diagnostics'; export function registerSessionCommand( program: Command, @@ -31,15 +40,43 @@ export function registerSessionCommand( const sessionIds = listSessions(sessionDir); let numCleaned = 0; const runningSessionMetadata = []; + const unreachableSessions: Array<{ + metadata: SessionMetadata; + error: NodeJS.ErrnoException; + }> = []; for (const sessionId of sessionIds) { const metadata = await validateSession(sessionDir, sessionId); - if (metadata === null) { + if (metadata !== null) { + runningSessionMetadata.push(metadata); + continue; + } + + const staleMetadata = loadSessionMetadata(sessionDir, sessionId); + if (staleMetadata === null) { + // No metadata to tell us where the socket is, so there is nothing + // left to protect. cleanupSession(sessionDir, sessionId); numCleaned++; continue; } - runningSessionMetadata.push(metadata); + + const unreachable = await cleanupIfDaemonGone( + sessionDir, + sessionId, + staleMetadata.socketPath + ); + if (unreachable === null) { + // The daemon answered on the retry, so the first check was a blip. + runningSessionMetadata.push(staleMetadata); + } else if (unreachable.cleanedUp) { + numCleaned++; + } else { + unreachableSessions.push({ + metadata: staleMetadata, + error: unreachable.error, + }); + } } if (numCleaned !== 0) { @@ -62,6 +99,24 @@ export function registerSessionCommand( ); } + if (unreachableSessions.length !== 0) { + console.log(); + console.log( + 'Could not reach the following sessions. Their files were left in place because their daemons may still be running:' + ); + for (const { metadata, error } of unreachableSessions) { + console.log( + ` ${metadata.id} [daemon pid: ${metadata.pid}]: ${toErrorMessage(error)}` + ); + } + if (unreachableSessions.some(({ error }) => isPermissionErrno(error))) { + console.log(SOCKET_SANDBOX_HINT); + } + console.log( + '"profiler-cli stop" needs the same socket, so kill these by pid if you no longer need them.' + ); + } + if (!wasExplicit('session', 'list')) { console.log('\nOther subcommands: profiler-cli session use '); } @@ -73,7 +128,9 @@ export function registerSessionCommand( .action(async (sessionId: string) => { const metadata = await validateSession(sessionDir, sessionId); if (metadata === null) { - console.error(`Error: session "${sessionId}" not found or not running`); + console.error( + `Error: ${await explainUnreachableSession(sessionDir, sessionId)}` + ); process.exit(1); } setCurrentSession(sessionDir, sessionId); diff --git a/profiler-cli/src/daemon.ts b/profiler-cli/src/daemon.ts index 36459fbb56..109fa51f8d 100644 --- a/profiler-cli/src/daemon.ts +++ b/profiler-cli/src/daemon.ts @@ -27,10 +27,23 @@ import { setCurrentSession, cleanupSession, ensureSessionDir, + writeStartupError, } from './session'; +import { + describeSessionDirFailure, + describeSocketListenError, + describeStaleSocketFailure, + toErrorMessage, +} from './diagnostics'; import { assertExhaustiveCheck } from 'firefox-profiler/utils/types'; import { BUILD_HASH, PACKAGE_NAME } from './constants'; +/** + * Exit code used when the daemon dies before it is able to serve requests. The + * accompanying reason is written to the session's startup error file. + */ +const DAEMON_STARTUP_FAILURE_EXIT_CODE = 3; + /** * Build a user-facing message for a profile load failure. When the profile is * too new for this build, append instructions on how to update the CLI. @@ -58,11 +71,13 @@ export class Daemon { private sessionId: string; private socketPath: string; private logPath: string; - private logStream: fs.WriteStream; + private logStream: fs.WriteStream | null = null; private profilePath: string; private symbolServerUrl?: string; private loadPhase: LoadPhase = 'fetching'; private profileLoadError: string | null = null; + private isListening: boolean = false; + private hasPublishedMetadata: boolean = false; constructor( sessionDir: string, @@ -76,7 +91,6 @@ export class Daemon { this.symbolServerUrl = symbolServerUrl; this.socketPath = getSocketPath(sessionDir, this.sessionId); this.logPath = getLogPath(sessionDir, this.sessionId); - this.logStream = fs.createWriteStream(this.logPath, { flags: 'a' }); // Redirect console to log file this.redirectConsole(); @@ -84,6 +98,14 @@ export class Daemon { // Handle shutdown signals process.on('SIGINT', () => this.shutdown('SIGINT')); process.on('SIGTERM', () => this.shutdown('SIGTERM')); + + // A crash before the socket is up would otherwise leave the client with + // nothing but an exit code to report. + process.on('uncaughtException', (error) => { + this.reportFatalError( + `The daemon crashed with an uncaught exception.\nUnderlying error: ${toErrorMessage(error)}${error instanceof Error && error.stack ? `\n${error.stack}` : ''}` + ); + }); } private redirectConsole(): void { @@ -92,7 +114,7 @@ export class Daemon { // exclusively to the log stream. const write = (level: string, args: any[]) => { const message = args.map((arg) => String(arg)).join(' '); - this.logStream.write( + this.logStream?.write( `[${level}] ${new Date().toISOString()} ${message}\n` ); }; @@ -101,54 +123,125 @@ export class Daemon { console.warn = (...args: any[]) => write('WARN', args); } - async start(): Promise { + /** + * Record why the daemon cannot serve requests and exit. + * + * A client waits for this session's metadata to appear, and gives up on the + * startup error file once it has, so the file is only worth writing before + * that point, which includes the window after listen() succeeds but before + * the metadata is saved. The message also goes to the log file and to the real + * stderr, both best effort: an unwritable session directory is one of the + * failures reported here, and the client spawns the daemon with its stdio + * discarded. + */ + private reportFatalError(message: string): never { + if (!this.hasPublishedMetadata) { + writeStartupError(this.sessionDir, this.sessionId, message); + } + + const logLine = `[ERROR] ${new Date().toISOString()} Fatal daemon error: ${message}\n`; + try { + // Synchronous: process.exit() below would discard the buffered stream. + fs.appendFileSync(this.logPath, logLine); + } catch { + // Nothing to do here. The startup error file is the channel that matters. + } try { - console.log(`Starting daemon for session ${this.sessionId}`); - console.log(`Profile path: ${this.profilePath}`); - console.log(`Socket path: ${this.socketPath}`); - console.log(`Log path: ${this.logPath}`); + process.stderr.write(logLine); + } catch { + // stdio is 'ignore' when spawned by the client. + } - // Ensure session directory exists + process.exit(DAEMON_STARTUP_FAILURE_EXIT_CODE); + } + + async start(): Promise { + // Ensure session directory exists before anything tries to write into it. + try { ensureSessionDir(this.sessionDir); + } catch (error) { + this.reportFatalError( + describeSessionDirFailure(this.sessionDir, 'create', error) + ); + } - // Create Unix socket server BEFORE loading the profile - this.server = net.createServer((socket) => this.handleConnection(socket)); + this.logStream = fs.createWriteStream(this.logPath, { flags: 'a' }); + this.logStream.on('error', (error) => { + // Losing the log is not fatal, but it must not take the daemon down with + // an unhandled 'error' event. + this.logStream = null; + try { + process.stderr.write( + `Failed to write daemon log ${this.logPath}: ${toErrorMessage(error)}\n` + ); + } catch { + // stdio is 'ignore' when spawned by the client. + } + }); - // Remove stale socket if it exists (Unix only — named pipes on Windows are not filesystem files) - if (process.platform !== 'win32' && fs.existsSync(this.socketPath)) { - fs.unlinkSync(this.socketPath); + console.log(`Starting daemon for session ${this.sessionId}`); + console.log(`Profile path: ${this.profilePath}`); + console.log(`Socket path: ${this.socketPath}`); + console.log(`Log path: ${this.logPath}`); + + // Create Unix socket server BEFORE loading the profile + this.server = net.createServer((socket) => this.handleConnection(socket)); + + this.server.on('error', (error) => { + // Before listen() succeeds this is fatal. Without a socket the daemon + // is unreachable, so the client needs to know why. + if (!this.isListening) { + this.reportFatalError( + describeSocketListenError(this.socketPath, error) + ); } + console.error(`Server error: ${error}`); + this.shutdown('error'); + }); - this.server.listen(this.socketPath, () => { - console.log(`Daemon listening on ${this.socketPath}`); - - // Save session metadata immediately - const metadata: SessionMetadata = { - id: this.sessionId, - socketPath: this.socketPath, - logPath: this.logPath, - pid: process.pid, - profilePath: this.profilePath, - createdAt: new Date().toISOString(), - buildHash: BUILD_HASH, - }; + // Remove stale socket if it exists (Unix only, since named pipes on + // Windows are not filesystem files). force: true so a socket that a + // concurrent cleanup removed first counts as success rather than aborting + // startup. + if (process.platform !== 'win32') { + try { + fs.rmSync(this.socketPath, { force: true }); + } catch (error) { + this.reportFatalError( + describeStaleSocketFailure(this.socketPath, error) + ); + } + } + + this.server.listen(this.socketPath, () => { + this.isListening = true; + console.log(`Daemon listening on ${this.socketPath}`); + + // Save session metadata immediately + const metadata: SessionMetadata = { + id: this.sessionId, + socketPath: this.socketPath, + logPath: this.logPath, + pid: process.pid, + profilePath: this.profilePath, + createdAt: new Date().toISOString(), + buildHash: BUILD_HASH, + }; + try { saveSessionMetadata(this.sessionDir, metadata); setCurrentSession(this.sessionDir, this.sessionId); + this.hasPublishedMetadata = true; + } catch (error) { + this.reportFatalError( + describeSessionDirFailure(this.sessionDir, 'write to', error) + ); + } - console.log('Daemon ready (socket listening)'); - - // Start loading the profile in the background - this.loadProfileAsync(); - }); + console.log('Daemon ready (socket listening)'); - this.server.on('error', (error) => { - console.error(`Server error: ${error}`); - this.shutdown('error'); - }); - } catch (error) { - console.error(`Failed to start daemon: ${error}`); - process.exit(1); - } + // Start loading the profile in the background + this.loadProfileAsync(); + }); } private async loadProfileAsync(): Promise { diff --git a/profiler-cli/src/diagnostics.ts b/profiler-cli/src/diagnostics.ts new file mode 100644 index 0000000000..1f30b55739 --- /dev/null +++ b/profiler-cli/src/diagnostics.ts @@ -0,0 +1,348 @@ +/* This Source Code Form is subject to the terms of the Mozilla Public + * License, v. 2.0. If a copy of the MPL was not distributed with this + * file, You can obtain one at http://mozilla.org/MPL/2.0/. */ + +/** + * Human-readable diagnostics for the ways daemon startup and client/daemon + * communication can fail. + * + * The daemon is spawned detached with its stdio discarded, so without help the + * client can only report an exit code. Most real-world failures come from + * sandboxes: a home directory that cannot be written, or a policy that refuses + * bind()/connect() on Unix domain sockets. + */ + +import * as fs from 'fs'; +import * as os from 'os'; +import * as path from 'path'; + +/** + * Advice shown whenever the failure looks like a sandbox restriction on the + * session directory. + */ +export const SESSION_DIR_SANDBOX_HINT = + 'Sandboxes (agent sandboxes, containers, restricted CI runners) commonly deny access outside the workspace, including the home directory.'; + +/** + * Advice shown whenever the failure looks like a sandbox restriction on Unix + * domain sockets themselves rather than on the directory holding them. + */ +export const SOCKET_SANDBOX_HINT = + 'profiler-cli needs a Unix domain socket to talk to its daemon. If you are inside a sandbox, allow Unix domain sockets in the sandbox policy, point PROFILER_CLI_SESSION_DIR at a directory the sandbox can write to, or run profiler-cli outside the sandbox.'; + +/** + * Length limit of `sun_path` in `struct sockaddr_un`, minus the NUL + * terminator: 108 bytes on Linux, 104 on the BSDs (macOS included). + */ +const MAX_UNIX_SOCKET_PATH_BYTES = process.platform === 'linux' ? 107 : 103; + +/** + * Extract the errno string (`EACCES`, `EPERM`, …) from an unknown thrown value. + */ +export function getErrnoCode(error: unknown): string | undefined { + const code = (error as NodeJS.ErrnoException | undefined)?.code; + return typeof code === 'string' ? code : undefined; +} + +/** + * Whether a failure is the kernel refusing an operation this process is not + * allowed to perform, which in this codebase almost always means a sandbox. + */ +export function isPermissionErrno(error: unknown): boolean { + const code = getErrnoCode(error); + return code === 'EACCES' || code === 'EPERM'; +} + +export function toErrorMessage(error: unknown): string { + return error instanceof Error ? error.message : String(error); +} + +/** + * A session directory the caller is likely to be allowed to write to. + */ +function suggestedSessionDir(): string { + return path.join(os.tmpdir(), 'profiler-cli'); +} + +/** + * Tell the user where the current session directory came from and how to move + * it somewhere usable. + */ +function sessionDirHint(): string { + const origin = process.env.PROFILER_CLI_SESSION_DIR + ? 'This directory comes from PROFILER_CLI_SESSION_DIR.' + : 'This is the default session directory (PROFILER_CLI_SESSION_DIR is not set).'; + return ( + `${origin}\n` + + `Point profiler-cli somewhere writable, for example:\n` + + ` PROFILER_CLI_SESSION_DIR=${suggestedSessionDir()} profiler-cli load \n` + + `A directory inside your workspace also works, as long as the socket path stays short.` + ); +} + +/** + * Plain-language explanation of a filesystem errno, or null when the code has + * no explanation worth adding on top of the raw message. + */ +function explainFsErrno(code: string | undefined): string | null { + switch (code) { + case 'EACCES': + case 'EPERM': + return `Permission denied. ${SESSION_DIR_SANDBOX_HINT}`; + case 'EROFS': + return 'The filesystem is read-only.'; + case 'ENOSPC': + return 'No space left on the device.'; + case 'EDQUOT': + return 'The disk quota for this user is exhausted.'; + case 'ENOTDIR': + return 'A component of the path exists but is not a directory.'; + case 'EEXIST': + return 'A file already exists at this path, so it cannot be used as a directory.'; + case 'ENOENT': + return 'A parent directory is missing and could not be created.'; + case 'ENAMETOOLONG': + return 'The path is too long.'; + default: + return null; + } +} + +/** + * Build the message for a failed filesystem operation on the session + * directory. `verb` completes the sentence "Cannot the … directory". + */ +export function describeSessionDirFailure( + sessionDir: string, + verb: string, + error: unknown +): string { + const explanation = explainFsErrno(getErrnoCode(error)); + return [ + `Cannot ${verb} the profiler-cli session directory ${sessionDir}.`, + ...(explanation ? [explanation] : []), + `Underlying error: ${toErrorMessage(error)}`, + sessionDirHint(), + ].join('\n'); +} + +/** + * Verify the session directory exists and is writable, throwing an explanatory + * error if not. Called before spawning a daemon so that an unusable directory + * is reported by the client, which still has a terminal to print to. + */ +export function ensureSessionDirUsable(sessionDir: string): void { + let stats: fs.Stats | null = null; + try { + stats = fs.statSync(sessionDir); + } catch (error) { + if (getErrnoCode(error) !== 'ENOENT') { + throw new Error(describeSessionDirFailure(sessionDir, 'read', error)); + } + } + + if (stats && !stats.isDirectory()) { + throw new Error( + [ + `The profiler-cli session directory ${sessionDir} exists but is not a directory.`, + sessionDirHint(), + ].join('\n') + ); + } + + try { + fs.mkdirSync(sessionDir, { recursive: true }); + } catch (error) { + throw new Error(describeSessionDirFailure(sessionDir, 'create', error)); + } + + // mkdirSync() is a no-op on an existing directory even when that directory is + // read-only, and sandboxes usually surface as a denied write rather than a + // denied mkdir, so probe with a real file. + const probePath = path.join(sessionDir, `.write-probe-${process.pid}`); + try { + fs.writeFileSync(probePath, ''); + } catch (error) { + throw new Error(describeSessionDirFailure(sessionDir, 'write to', error)); + } finally { + try { + fs.rmSync(probePath, { force: true }); + } catch { + // Leaving the probe behind is harmless. + } + } +} + +/** + * Reject socket paths that cannot fit in `sockaddr_un`. Node reports these as + * a bare EINVAL from listen(), which is impossible to act on. + */ +export function assertSocketPathUsable(socketPath: string): void { + if (process.platform === 'win32') { + return; + } + + const byteLength = Buffer.byteLength(socketPath); + if (byteLength <= MAX_UNIX_SOCKET_PATH_BYTES) { + return; + } + + throw new Error( + [ + `The Unix socket path for this session is ${byteLength} bytes, over this platform's ${MAX_UNIX_SOCKET_PATH_BYTES}-byte limit:`, + ` ${socketPath}`, + `Use a shorter session directory, for example:`, + ` PROFILER_CLI_SESSION_DIR=${suggestedSessionDir()} profiler-cli load `, + ].join('\n') + ); +} + +/** + * Explain a failure to create the daemon's listening socket. + */ +export function describeSocketListenError( + socketPath: string, + error: unknown +): string { + const detail = `Underlying error: ${toErrorMessage(error)}`; + + switch (getErrnoCode(error)) { + case 'EACCES': + case 'EPERM': + return [ + `Not allowed to create the Unix domain socket at ${socketPath}.`, + SOCKET_SANDBOX_HINT, + detail, + ].join('\n'); + case 'EADDRINUSE': + return [ + `Another process is already listening on ${socketPath}.`, + 'Run "profiler-cli session list" to see running sessions, or "profiler-cli stop --all" to stop them.', + detail, + ].join('\n'); + case 'ENOENT': + return [ + `The directory holding the socket ${socketPath} disappeared before the daemon could bind to it.`, + detail, + ].join('\n'); + case 'ENAMETOOLONG': + case 'EINVAL': + return [ + `The socket path ${socketPath} (${Buffer.byteLength(socketPath)} bytes) was rejected by the kernel. It is most likely too long for sockaddr_un (limit ${MAX_UNIX_SOCKET_PATH_BYTES} bytes).`, + `Use a shorter session directory, for example:`, + ` PROFILER_CLI_SESSION_DIR=${suggestedSessionDir()} profiler-cli load `, + detail, + ].join('\n'); + default: + return [`Failed to listen on ${socketPath}.`, detail].join('\n'); + } +} + +/** + * Say what is sitting at a path that was supposed to hold a socket, or null + * when nothing can be learned about it. + */ +function describePathContents(targetPath: string): string | null { + let stats: fs.Stats; + try { + stats = fs.lstatSync(targetPath); + } catch { + return null; + } + + if (stats.isSymbolicLink()) { + return 'It is a symbolic link, not a socket.'; + } + if (stats.isDirectory()) { + return 'It is a directory, not a socket.'; + } + if (stats.isFile()) { + return 'It is a regular file, not a socket.'; + } + if (stats.isSocket()) { + return 'It is a socket left behind by an earlier daemon.'; + } + return null; +} + +/** + * Explain a failure to clear the path the daemon binds its socket to. + * + * Deliberately not a `describeSessionDirFailure`: the client checks that the + * session directory is writable before it spawns the daemon, so blaming the + * directory here would contradict a check that has just passed. What is wrong + * is this one path, and the way out is to clear it or use another session id. + */ +export function describeStaleSocketFailure( + socketPath: string, + error: unknown +): string { + const contents = describePathContents(socketPath); + return [ + `Cannot clear the path the daemon needs for its socket: ${socketPath}`, + ...(contents ? [contents] : []), + 'Remove it, or load the profile under a different session id with --session.', + `Underlying error: ${toErrorMessage(error)}`, + ].join('\n'); +} + +/** + * Explain a failure to reach a daemon over its socket. + */ +export function describeSocketConnectError( + socketPath: string, + error: unknown +): string { + const detail = `Underlying error: ${toErrorMessage(error)}`; + + switch (getErrnoCode(error)) { + case 'ENOENT': + return [ + `No daemon socket at ${socketPath}.`, + 'The session is gone. Run "profiler-cli load " to start a new one.', + ].join('\n'); + case 'ECONNREFUSED': + return [ + `Nothing is accepting connections on ${socketPath}.`, + 'The daemon exited without cleaning up. Run "profiler-cli load " to start a new one.', + ].join('\n'); + case 'EACCES': + case 'EPERM': + return [ + `Not allowed to connect to the daemon socket at ${socketPath}.`, + SOCKET_SANDBOX_HINT, + detail, + ].join('\n'); + case 'ETIMEDOUT': + return [ + `Timed out connecting to the daemon at ${socketPath}.`, + 'The daemon may be busy or wedged. Run "profiler-cli stop" and load the profile again.', + ].join('\n'); + default: + return [`Failed to talk to the daemon on ${socketPath}.`, detail].join( + '\n' + ); + } +} + +/** + * How to get rid of a daemon that cannot be reached through its socket. + * "profiler-cli stop" is no help there, because it asks the daemon to shut + * itself down over that same socket, so the only way out is to signal the + * process directly. + */ +export function describeManualKill(pid: number): string { + const command = + process.platform === 'win32' ? `taskkill /PID ${pid} /F` : `kill ${pid}`; + return `The daemon may still be running as pid ${pid}. "profiler-cli stop" needs the same socket, so run "${command}" if you no longer need it.`; +} + +/** + * Indent a block of text so it reads as quoted output inside a larger message. + */ +export function indentBlock(text: string, prefix: string = ' '): string { + return text + .split('\n') + .map((line) => `${prefix}${line}`) + .join('\n'); +} diff --git a/profiler-cli/src/index.ts b/profiler-cli/src/index.ts index 45c01b89ac..7d5a2a8986 100644 --- a/profiler-cli/src/index.ts +++ b/profiler-cli/src/index.ts @@ -149,9 +149,21 @@ Examples: ).action(async (idArg: string | undefined, opts) => { if (opts.all) { const sessionIds = listSessions(SESSION_DIR); - await Promise.all( + // Settled, so one session that refuses to stop does not hide the others. + const results = await Promise.allSettled( sessionIds.map((id: string) => stopDaemon(SESSION_DIR, id)) ); + const failures = results.filter((r) => r.status === 'rejected'); + for (const failure of failures) { + console.error( + `Error: ${failure.reason instanceof Error ? failure.reason.message : failure.reason}` + ); + } + if (failures.length !== 0) { + throw new Error( + `Could not stop ${failures.length} of ${sessionIds.length} sessions.` + ); + } } else { const sessionId = idArg ?? opts.session; await stopDaemon(SESSION_DIR, sessionId); diff --git a/profiler-cli/src/session.ts b/profiler-cli/src/session.ts index 8ebbbac4ab..deeb41d51f 100644 --- a/profiler-cli/src/session.ts +++ b/profiler-cli/src/session.ts @@ -16,6 +16,7 @@ import * as net from 'net'; import * as path from 'path'; import * as crypto from 'crypto'; import type { SessionMetadata } from './protocol'; +import { describeSessionDirFailure, getErrnoCode } from './diagnostics'; /** * Ensure the session directory exists. @@ -71,6 +72,93 @@ export function getMetadataPath(sessionDir: string, sessionId: string): string { return path.join(sessionDir, `${sessionId}.json`); } +/** + * Get the path of the startup failure record for a session. + * + * The daemon is spawned detached with its stdio discarded, so this file is how + * it tells the client why it could not start. The extension deliberately isn't + * `.json`, which `listSessions` uses to enumerate sessions. + */ +export function getStartupErrorPath( + sessionDir: string, + sessionId: string +): string { + return path.join(sessionDir, `${sessionId}.error`); +} + +/** + * Record why the daemon failed to start, for the client to pick up. + */ +export function writeStartupError( + sessionDir: string, + sessionId: string, + message: string +): void { + try { + fs.writeFileSync(getStartupErrorPath(sessionDir, sessionId), message); + } catch { + // The session directory being unwritable is itself one of the failures + // this file reports, so there is nothing useful to do here. + } +} + +/** + * Read and delete the startup failure record for a session, if there is one. + */ +export function takeStartupError( + sessionDir: string, + sessionId: string +): string | null { + const errorPath = getStartupErrorPath(sessionDir, sessionId); + try { + const message = fs.readFileSync(errorPath, 'utf-8').trim(); + fs.rmSync(errorPath, { force: true }); + return message || null; + } catch { + return null; + } +} + +/** + * Current size of a session's daemon log, or 0 if it has none. + * + * Daemons append to the log of the session id they are given, and the log is + * kept on purpose across sessions, so callers that only care about one daemon's + * output record the size before starting it and read from there. + */ +export function getLogSize(sessionDir: string, sessionId: string): number { + try { + return fs.statSync(getLogPath(sessionDir, sessionId)).size; + } catch { + return 0; + } +} + +/** + * Read the last `maxLines` lines of a session's daemon log, if it has one, + * ignoring everything before `fromByte`. + */ +export function readLogTail( + sessionDir: string, + sessionId: string, + fromByte: number = 0, + maxLines: number = 15 +): string | null { + try { + const contents = fs + .readFileSync(getLogPath(sessionDir, sessionId)) + .subarray(fromByte) + .toString('utf-8') + .trimEnd(); + if (!contents) { + return null; + } + return contents.split('\n').slice(-maxLines).join('\n'); + } catch { + return null; + } +} + /** * Save session metadata to disk. */ @@ -124,7 +212,7 @@ export function getCurrentSessionId(sessionDir: string): string | null { if (error && error.code === 'ENOENT') { return null; } - throw error; + throw new Error(describeSessionDirFailure(sessionDir, 'read', error)); } } @@ -142,27 +230,46 @@ export function getCurrentSocketPath(sessionDir: string): string | null { } /** - * Check if a daemon is reachable by attempting a socket connection. + * Attempt a socket connection to a daemon. Resolves with null when the daemon + * answers, or with the connection error when it does not. + * + * Callers use the errno to tell "there is no daemon" (ENOENT, ECONNREFUSED) + * apart from "this process is not allowed to reach the daemon" (EACCES, + * EPERM), which are very different problems with the same symptom. * Works for both Unix domain sockets and Windows named pipes. */ -export async function isDaemonReachable(socketPath: string): Promise { +export async function probeDaemonSocket( + socketPath: string +): Promise { return new Promise((resolve) => { const socket = net.connect(socketPath); socket.setTimeout(1000); socket.on('connect', () => { socket.destroy(); - resolve(true); + resolve(null); }); - socket.on('error', () => { - resolve(false); + socket.on('error', (error: NodeJS.ErrnoException) => { + socket.destroy(); + resolve(error); }); socket.on('timeout', () => { socket.destroy(); - resolve(false); + const error: NodeJS.ErrnoException = new Error( + `connect ETIMEDOUT ${socketPath}` + ); + error.code = 'ETIMEDOUT'; + resolve(error); }); }); } +/** + * Check if a daemon is reachable by attempting a socket connection. + */ +export async function isDaemonReachable(socketPath: string): Promise { + return (await probeDaemonSocket(socketPath)) === null; +} + /** * Wait for a daemon's socket to become unreachable (i.e. for the daemon to stop). */ @@ -198,12 +305,22 @@ export function cleanupSession(sessionDir: string, sessionId: string): void { // cleanupSession concurrently during version-mismatch shutdown, so the file // may already be gone by the time the second caller tries to unlink it. if (process.platform !== 'win32') { - fs.rmSync(socketPath, { force: true }); + try { + fs.rmSync(socketPath, { force: true }); + } catch { + // Something that is not a socket sits at the socket path (a directory, + // say). Removing the metadata below is what actually retires the + // session, so it must not be blocked by junk we cannot unlink. + } } // Remove metadata file fs.rmSync(metadataPath, { force: true }); + // Remove any startup failure record left behind by a previous daemon that + // reused this session id. + fs.rmSync(getStartupErrorPath(sessionDir, sessionId), { force: true }); + // Remove current session file if it points to this session const currentSessionId = getCurrentSessionId(sessionDir); if (currentSessionId === sessionId) { @@ -211,6 +328,55 @@ export function cleanupSession(sessionDir: string, sessionId: string): void { } } +/** + * Errnos that prove no daemon is listening on a socket path: nothing is there + * (ENOENT), something is there but has no listener (ECONNREFUSED), or what is + * there is not a socket at all and so cannot have one (ENOTSOCK). + * + * Every other failure, such as EACCES from a sandbox policy or ETIMEDOUT from + * a busy daemon, leaves open the possibility that the daemon is alive and well. + */ +function isDaemonProvablyGone(error: NodeJS.ErrnoException): boolean { + const code = getErrnoCode(error); + return code === 'ENOENT' || code === 'ECONNREFUSED' || code === 'ENOTSOCK'; +} + +/** + * Why a session could not be reached, and whether its files were removed. + */ +export type UnreachableSession = { + error: NodeJS.ErrnoException; + cleanedUp: boolean; +}; + +/** + * Probe a session that failed validation, and clean up after it only when its + * daemon is provably gone. Resolves with null when the daemon answers after + * all, meaning the failed validation was a blip. + * + * A dead daemon and a sandbox that forbids connect() are indistinguishable to + * `validateSession`, but only the first justifies deleting the session files: + * discarding a healthy session because this process may not talk to it orphans + * a running daemon and destroys the socket it was reachable through. + */ +export async function cleanupIfDaemonGone( + sessionDir: string, + sessionId: string, + socketPath: string +): Promise { + const error = await probeDaemonSocket(socketPath); + if (!error) { + return null; + } + + const cleanedUp = isDaemonProvablyGone(error); + if (cleanedUp) { + cleanupSession(sessionDir, sessionId); + } + + return { error, cleanedUp }; +} + /** * Validate that a session is healthy (daemon reachable via socket). * If not, clean up stale files. @@ -235,8 +401,18 @@ export async function validateSession( * List all session IDs. */ export function listSessions(sessionDir: string): string[] { - ensureSessionDir(sessionDir); - const files = fs.readdirSync(sessionDir); + let files: string[]; + try { + files = fs.readdirSync(sessionDir); + } catch (error) { + // A missing session directory simply means there are no sessions, so there + // is no reason to create it just to list nothing. + if ((error as NodeJS.ErrnoException).code === 'ENOENT') { + return []; + } + throw new Error(describeSessionDirFailure(sessionDir, 'read', error)); + } + return files .filter((f) => f.endsWith('.json')) .map((f) => path.basename(f, '.json')); diff --git a/profiler-cli/src/test/integration/daemon-failures.test.ts b/profiler-cli/src/test/integration/daemon-failures.test.ts new file mode 100644 index 0000000000..2e1d3aff66 --- /dev/null +++ b/profiler-cli/src/test/integration/daemon-failures.test.ts @@ -0,0 +1,377 @@ +/* This Source Code Form is subject to the terms of the Mozilla Public + * License, v. 2.0. If a copy of the MPL was not distributed with this + * file, You can obtain one at http://mozilla.org/MPL/2.0/. */ + +/** + * Tests that daemon startup and communication failures are reported with + * enough detail to act on. These are the paths a sandbox hits: a session + * directory that cannot be written, a socket path the kernel refuses, or a + * daemon that dies before it can answer. + */ + +import { + chmodSync, + existsSync, + mkdirSync, + mkdtempSync, + rmSync, + writeFileSync, +} from 'fs'; +import { readFile } from 'fs/promises'; +import { tmpdir } from 'os'; +import { join } from 'path'; +import { + createTestContext, + cleanupTestContext, + cli, + cliFail, + type CliTestContext, +} from './utils'; + +const PROFILE = 'src/test/fixtures/upgrades/processed-1.json'; + +const isRoot = typeof process.getuid === 'function' && process.getuid() === 0; +// Unix domain sockets do not exist on Windows, and permission bits do not +// constrain root. +const skipUnix = process.platform === 'win32'; +const skipUnixPermissions = skipUnix || isRoot; + +/** + * Run profiler-cli against an arbitrary session directory, bypassing the + * per-test context (whose directory is deliberately healthy). + */ +function contextForSessionDir(sessionDir: string): CliTestContext { + return { + sessionDir, + env: { + PROFILER_CLI_SESSION_DIR: sessionDir, + PROFILER_CLI_NO_SYMBOLICATE: '1', + }, + }; +} + +function output(result: { stdout?: string; stderr?: string }): string { + return `${result.stdout ?? ''}${result.stderr ?? ''}`; +} + +describe('unusable session directory', () => { + let scratchDir: string; + + beforeEach(() => { + scratchDir = mkdtempSync(join(tmpdir(), 'profiler-cli-fail-')); + }); + + afterEach(() => { + chmodSync(scratchDir, 0o755); + rmSync(scratchDir, { recursive: true, force: true }); + }); + + it('explains a session directory that cannot be written to', async () => { + if (skipUnixPermissions) { + return; + } + + chmodSync(scratchDir, 0o555); + + const result = await cliFail(contextForSessionDir(scratchDir), [ + 'load', + PROFILE, + ]); + + const text = output(result); + expect(text).toContain('session directory'); + expect(text).toContain(scratchDir); + expect(text).toContain('Permission denied'); + expect(text).toContain('PROFILER_CLI_SESSION_DIR'); + // The old message leaked implementation details and a misleading fix. + expect(text).not.toContain('exited unexpectedly during startup'); + }); + + it('explains a session directory that cannot be created', async () => { + if (skipUnixPermissions) { + return; + } + + chmodSync(scratchDir, 0o555); + const sessionDir = join(scratchDir, 'sub'); + + const result = await cliFail(contextForSessionDir(sessionDir), [ + 'load', + PROFILE, + ]); + + const text = output(result); + expect(text).toContain('Cannot create'); + expect(text).toContain(sessionDir); + }); + + it('explains a session directory path that is a regular file', async () => { + const sessionDir = join(scratchDir, 'file'); + writeFileSync(sessionDir, ''); + + const result = await cliFail(contextForSessionDir(sessionDir), [ + 'load', + PROFILE, + ]); + + expect(output(result)).toContain('exists but is not a directory'); + }); + + it('does not silently create a session directory just to list sessions', async () => { + const sessionDir = join(scratchDir, 'never-created'); + + const result = await cli(contextForSessionDir(sessionDir), [ + 'session', + 'list', + ]); + + expect(result.stdout).toContain('Found 0 running sessions'); + expect(existsSync(sessionDir)).toBe(false); + }); +}); + +describe('socket path blocked by something else', () => { + let scratchDir: string; + + beforeEach(() => { + scratchDir = mkdtempSync(join(tmpdir(), 'profiler-cli-fail-')); + }); + + afterEach(() => { + rmSync(scratchDir, { recursive: true, force: true }); + }); + + it('names what is in the way rather than blaming the session directory', async () => { + if (skipUnix) { + return; + } + + // A directory cannot be unlinked, so the daemon fails here, after the + // client's session directory check has already passed. The reason can only + // reach the client through the startup error file. + mkdirSync(join(scratchDir, 'sess-a.sock')); + + const result = await cliFail(contextForSessionDir(scratchDir), [ + 'load', + PROFILE, + '--session', + 'sess-a', + ]); + + const text = output(result); + expect(text).toContain('needs for its socket'); + expect(text).toContain('It is a directory, not a socket.'); + expect(text).toContain('--session'); + expect(text).not.toContain('session directory'); + }); +}); + +describe('unusable socket path', () => { + it('rejects a socket path too long for sockaddr_un before spawning', async () => { + if (skipUnix) { + return; + } + + const scratchDir = mkdtempSync(join(tmpdir(), 'profiler-cli-fail-')); + const sessionDir = join(scratchDir, ...Array(12).fill('abcdefghij')); + + try { + const result = await cliFail(contextForSessionDir(sessionDir), [ + 'load', + PROFILE, + ]); + + const text = output(result); + expect(text).toContain('byte limit'); + expect(text).toContain('PROFILER_CLI_SESSION_DIR'); + } finally { + rmSync(scratchDir, { recursive: true, force: true }); + } + }); +}); + +describe('unreachable daemon', () => { + let ctx: CliTestContext; + + beforeEach(async () => { + ctx = await createTestContext(); + }); + + afterEach(async () => { + await cleanupTestContext(ctx); + }); + + it('reports the socket state when the daemon died without cleaning up', async () => { + const loadResult = await cli(ctx, ['load', PROFILE]); + const sessionId = (loadResult.stdout as string).match( + /Session started: (\w+)/ + )![1]; + + const metadata = JSON.parse( + await readFile(join(ctx.sessionDir, `${sessionId}.json`), 'utf-8') + ); + process.kill(metadata.pid, 'SIGKILL'); + await new Promise((resolve) => setTimeout(resolve, 300)); + + const result = await cliFail(ctx, ['profile', 'info']); + + const text = output(result); + expect(text).toContain(`Session ${sessionId} is not reachable`); + expect(text).toContain('profiler-cli load'); + }); + + it('reports an unknown session id instead of a bare "invalid"', async () => { + const result = await cliFail(ctx, [ + 'profile', + 'info', + '--session', + 'no-such-session', + ]); + + const text = output(result); + expect(text).toContain('Unknown session no-such-session'); + expect(text).toContain(ctx.sessionDir); + }); +}); + +describe('session denied by policy', () => { + let ctx: CliTestContext; + let sessionId: string; + let socketPath: string; + let daemonPid: number; + + // The whole fixture is a denied connect(), so it cannot even be set up where + // permission bits do not apply. + beforeEach(async () => { + if (skipUnixPermissions) { + return; + } + + ctx = await createTestContext(); + const loadResult = await cli(ctx, ['load', PROFILE]); + sessionId = (loadResult.stdout as string).match( + /Session started: (\w+)/ + )![1]; + socketPath = join(ctx.sessionDir, `${sessionId}.sock`); + daemonPid = JSON.parse( + await readFile(join(ctx.sessionDir, `${sessionId}.json`), 'utf-8') + ).pid; + // Deny connect() to a daemon that is alive and well, which is what a + // sandbox policy looks like from the client side. + chmodSync(socketPath, 0o000); + }); + + afterEach(async () => { + if (skipUnixPermissions) { + return; + } + + // A test may have stopped the daemon, which takes the socket with it. + if (existsSync(socketPath)) { + chmodSync(socketPath, 0o755); + } + await cleanupTestContext(ctx); + }); + + it('keeps a live session listed as unreachable instead of deleting it', async () => { + if (skipUnixPermissions) { + return; + } + + const result = await cli(ctx, ['session', 'list']); + + const text = output(result); + expect(text).toContain('Could not reach the following sessions'); + expect(text).toContain(`${sessionId} [daemon pid: ${daemonPid}]`); + expect(text).toContain('sandbox'); + // An unreachable daemon cannot be stopped through its own socket, so the + // pid has to be enough to act on. + expect(text).toContain('kill these by pid'); + expect(text).not.toContain('Cleaned up'); + + // The daemon is still running, so its files have to survive: deleting the + // socket would orphan it permanently. + expect(existsSync(socketPath)).toBe(true); + expect(existsSync(join(ctx.sessionDir, `${sessionId}.json`))).toBe(true); + + chmodSync(socketPath, 0o755); + const recovered = await cli(ctx, ['profile', 'info']); + expect(output(recovered)).toContain('This profile contains'); + }); + + it('explains a denied session instead of reporting it as not found', async () => { + if (skipUnixPermissions) { + return; + } + + const result = await cliFail(ctx, ['session', 'use', sessionId]); + + const text = output(result); + expect(text).toContain('Not allowed to connect'); + expect(text).toContain('sandbox'); + expect(text).toContain(`kill ${daemonPid}`); + expect(text).not.toContain('not found or not running'); + expect(existsSync(join(ctx.sessionDir, `${sessionId}.json`))).toBe(true); + }); + + it('does not claim to have stopped a daemon it cannot reach', async () => { + if (skipUnixPermissions) { + return; + } + + const result = await cliFail(ctx, ['stop', sessionId]); + + const text = output(result); + expect(text).toContain('may still be running'); + expect(text).toContain(`kill ${daemonPid}`); + // The old message announced success while the daemon kept running. + expect(text).not.toContain(`Session ${sessionId} stopped`); + + chmodSync(socketPath, 0o755); + const stopped = await cli(ctx, ['stop', sessionId]); + expect(output(stopped)).toContain(`Session ${sessionId} stopped`); + }); + + it('fails "stop --all" when one of the sessions cannot be stopped', async () => { + if (skipUnixPermissions) { + return; + } + + const result = await cliFail(ctx, ['stop', '--all']); + + const text = output(result); + expect(text).toContain('Could not stop 1 of 1 sessions'); + expect(text).not.toContain(`Session ${sessionId} stopped`); + expect(existsSync(join(ctx.sessionDir, `${sessionId}.json`))).toBe(true); + }); + + it('refuses to reuse the session id rather than orphaning its daemon', async () => { + if (skipUnixPermissions) { + return; + } + + const result = await cliFail(ctx, [ + 'load', + PROFILE, + '--session', + sessionId, + ]); + + const text = output(result); + expect(text).toContain('cannot be reached'); + expect(text).toContain(`kill ${daemonPid}`); + expect(text).toContain('--session'); + + // Taking over the id would have unlinked this socket and overwritten this + // metadata, leaving the daemon running with nothing able to find it. + expect(existsSync(socketPath)).toBe(true); + const metadata = JSON.parse( + await readFile(join(ctx.sessionDir, `${sessionId}.json`), 'utf-8') + ); + expect(metadata.pid).toBe(daemonPid); + + chmodSync(socketPath, 0o755); + const recovered = await cli(ctx, ['profile', 'info']); + expect(output(recovered)).toContain('This profile contains'); + }); +}); diff --git a/profiler-cli/src/test/unit/diagnostics.test.ts b/profiler-cli/src/test/unit/diagnostics.test.ts new file mode 100644 index 0000000000..6534c23313 --- /dev/null +++ b/profiler-cli/src/test/unit/diagnostics.test.ts @@ -0,0 +1,232 @@ +/* This Source Code Form is subject to the terms of the Mozilla Public + * License, v. 2.0. If a copy of the MPL was not distributed with this + * file, You can obtain one at http://mozilla.org/MPL/2.0/. */ + +/** + * Unit tests for the failure diagnostics used by the daemon and its clients. + */ + +import * as fs from 'fs'; +import * as net from 'net'; +import * as os from 'os'; +import * as path from 'path'; +import { + assertSocketPathUsable, + describeSessionDirFailure, + describeSocketConnectError, + describeSocketListenError, + describeStaleSocketFailure, + ensureSessionDirUsable, + getErrnoCode, + indentBlock, +} from '../../diagnostics'; + +function errnoError(code: string, message: string): NodeJS.ErrnoException { + const error: NodeJS.ErrnoException = new Error(message); + error.code = code; + return error; +} + +const isRoot = typeof process.getuid === 'function' && process.getuid() === 0; +// Unix domain sockets do not exist on Windows, and permission bits do not +// constrain root. +const skipUnix = process.platform === 'win32'; +const skipUnixPermissions = skipUnix || isRoot; + +describe('profiler-cli diagnostics', function () { + let tmpDir: string; + + beforeEach(function () { + tmpDir = fs.mkdtempSync(path.join(os.tmpdir(), 'pcli-diag-')); + }); + + afterEach(function () { + fs.chmodSync(tmpDir, 0o755); + fs.rmSync(tmpDir, { recursive: true, force: true }); + }); + + describe('getErrnoCode', function () { + it('extracts the code from an errno error', function () { + expect(getErrnoCode(errnoError('EACCES', 'nope'))).toBe('EACCES'); + }); + + it('returns undefined for values without a code', function () { + expect(getErrnoCode(new Error('plain'))).toBeUndefined(); + expect(getErrnoCode('a string')).toBeUndefined(); + expect(getErrnoCode(undefined)).toBeUndefined(); + }); + }); + + describe('ensureSessionDirUsable', function () { + it('creates a missing session directory', function () { + const sessionDir = path.join(tmpDir, 'nested', 'sessions'); + expect(() => ensureSessionDirUsable(sessionDir)).not.toThrow(); + expect(fs.existsSync(sessionDir)).toBe(true); + }); + + it('leaves no probe file behind', function () { + ensureSessionDirUsable(tmpDir); + expect(fs.readdirSync(tmpDir)).toEqual([]); + }); + + it('rejects a path that is a file', function () { + const filePath = path.join(tmpDir, 'not-a-dir'); + fs.writeFileSync(filePath, ''); + expect(() => ensureSessionDirUsable(filePath)).toThrow( + /exists but is not a directory/ + ); + }); + + it('rejects an existing directory that cannot be written to', function () { + if (skipUnixPermissions) { + return; + } + + fs.chmodSync(tmpDir, 0o555); + expect(() => ensureSessionDirUsable(tmpDir)).toThrow( + /Cannot write to the profiler-cli session directory/ + ); + expect(() => ensureSessionDirUsable(tmpDir)).toThrow( + /PROFILER_CLI_SESSION_DIR/ + ); + }); + }); + + describe('describeSessionDirFailure', function () { + it('explains permission errors and points at the env var', function () { + const message = describeSessionDirFailure( + '/some/dir', + 'create', + errnoError('EACCES', 'EACCES: permission denied') + ); + expect(message).toContain('Cannot create'); + expect(message).toContain('/some/dir'); + expect(message).toContain('Permission denied'); + expect(message).toContain('PROFILER_CLI_SESSION_DIR'); + }); + + it('always includes the underlying error', function () { + const message = describeSessionDirFailure( + '/some/dir', + 'read', + errnoError('EWEIRD', 'something unusual happened') + ); + expect(message).toContain('something unusual happened'); + }); + }); + + describe('assertSocketPathUsable', function () { + it('accepts a short path', function () { + expect(() => assertSocketPathUsable('/tmp/p/abc.sock')).not.toThrow(); + }); + + it('rejects a path that cannot fit in sockaddr_un', function () { + if (skipUnix) { + return; + } + + const longPath = `/tmp/${'a'.repeat(200)}.sock`; + expect(() => assertSocketPathUsable(longPath)).toThrow( + /over this platform's \d+-byte limit/ + ); + }); + }); + + describe('describeSocketListenError', function () { + it('blames the sandbox on EPERM', function () { + const message = describeSocketListenError( + '/tmp/s.sock', + errnoError('EPERM', 'listen EPERM') + ); + expect(message).toContain('Not allowed to create the Unix domain socket'); + expect(message).toContain('sandbox'); + }); + + it('suggests a shorter directory when the kernel rejects the path', function () { + const message = describeSocketListenError( + '/tmp/s.sock', + errnoError('EINVAL', 'listen EINVAL') + ); + expect(message).toContain('too long for sockaddr_un'); + }); + + it('mentions the other sessions on EADDRINUSE', function () { + const message = describeSocketListenError( + '/tmp/s.sock', + errnoError('EADDRINUSE', 'listen EADDRINUSE') + ); + expect(message).toContain('profiler-cli session list'); + }); + }); + + describe('describeStaleSocketFailure', function () { + it('names what is in the way and does not blame the session directory', function () { + const socketPath = path.join(tmpDir, 'sess.sock'); + fs.mkdirSync(socketPath); + + const message = describeStaleSocketFailure( + socketPath, + errnoError('ERR_FS_EISDIR', 'Path is a directory') + ); + + expect(message).toContain(socketPath); + expect(message).toContain('It is a directory, not a socket.'); + expect(message).toContain('Path is a directory'); + // The client verifies the session directory before spawning the daemon, + // so pointing at the directory here would contradict that check. + expect(message).not.toContain('session directory'); + expect(message).not.toContain('PROFILER_CLI_SESSION_DIR'); + }); + + it('recognizes a socket left behind by an earlier daemon', async function () { + if (skipUnix) { + return; + } + + const socketPath = path.join(tmpDir, 'left-behind.sock'); + const server = net.createServer(); + await new Promise((resolve) => server.listen(socketPath, resolve)); + try { + expect( + describeStaleSocketFailure(socketPath, errnoError('EPERM', 'nope')) + ).toContain('socket left behind by an earlier daemon'); + } finally { + await new Promise((resolve) => server.close(resolve)); + } + }); + + it('still reports the error when the path is gone', function () { + const message = describeStaleSocketFailure( + path.join(tmpDir, 'missing.sock'), + errnoError('EPERM', 'operation not permitted') + ); + expect(message).toContain('operation not permitted'); + }); + }); + + describe('describeSocketConnectError', function () { + it('tells the user to reload when the socket is gone', function () { + const message = describeSocketConnectError( + '/tmp/s.sock', + errnoError('ENOENT', 'connect ENOENT') + ); + expect(message).toContain('profiler-cli load'); + }); + + it('distinguishes a denied connection from a missing daemon', function () { + const message = describeSocketConnectError( + '/tmp/s.sock', + errnoError('EPERM', 'connect EPERM') + ); + expect(message).toContain('Not allowed to connect'); + expect(message).toContain('sandbox'); + expect(message).not.toContain('profiler-cli load'); + }); + }); + + describe('indentBlock', function () { + it('indents every line', function () { + expect(indentBlock('a\nb')).toBe(' a\n b'); + }); + }); +}); diff --git a/profiler-cli/src/test/unit/session.test.ts b/profiler-cli/src/test/unit/session.test.ts index c2144f20c5..81d54c725f 100644 --- a/profiler-cli/src/test/unit/session.test.ts +++ b/profiler-cli/src/test/unit/session.test.ts @@ -32,6 +32,10 @@ import { cleanupSession, validateSession, listSessions, + getLogSize, + readLogTail, + writeStartupError, + takeStartupError, } from '../../session'; import type { SessionMetadata } from '../../protocol'; @@ -377,6 +381,39 @@ describe('profiler-cli session management', function () { }); }); + describe('daemon log and startup error', function () { + it('returns null when there is no log', function () { + expect(readLogTail(testSessionDir, 'no-log')).toBe(null); + expect(getLogSize(testSessionDir, 'no-log')).toBe(0); + }); + + it('ignores everything before the given offset', function () { + const logPath = getLogPath(testSessionDir, 'reused'); + fs.writeFileSync(logPath, 'from an earlier daemon\n'); + const offset = getLogSize(testSessionDir, 'reused'); + fs.appendFileSync(logPath, 'from this daemon\n'); + + const tail = readLogTail(testSessionDir, 'reused', offset); + expect(tail).toBe('from this daemon'); + expect(readLogTail(testSessionDir, 'reused')).toContain( + 'from an earlier daemon' + ); + }); + + it('reads back and consumes a startup error', function () { + writeStartupError(testSessionDir, 'failed', 'could not bind\n'); + + expect(takeStartupError(testSessionDir, 'failed')).toBe('could not bind'); + // Consumed, so a later failure cannot inherit this one's reason. + expect(takeStartupError(testSessionDir, 'failed')).toBe(null); + }); + + it('does not make startup errors look like sessions', function () { + writeStartupError(testSessionDir, 'failed', 'could not bind'); + expect(listSessions(testSessionDir)).toEqual([]); + }); + }); + describe('listSessions', function () { it('returns empty array when no sessions exist', function () { const sessions = listSessions(testSessionDir);