diff --git a/packages/desktop/src/login-shell-env.test.ts b/packages/desktop/src/login-shell-env.test.ts index fc6ab7d0a..edd17fa8d 100644 --- a/packages/desktop/src/login-shell-env.test.ts +++ b/packages/desktop/src/login-shell-env.test.ts @@ -10,14 +10,35 @@ import { inheritLoginShellEnv } from "./login-shell-env"; const zsh = "/bin/zsh"; const describeIfZsh = existsSync(zsh) ? describe : describe.skip; const basePath = "/usr/bin:/bin:/usr/sbin:/sbin"; +const fakeHome = path.join(os.tmpdir(), "paseo-login-shell-env-fake-home"); type LoginShellEnvInput = NonNullable[0]>; type LoginShellSpawnSync = NonNullable; +interface TestClock { + advance: (ms: number) => void; + now: () => number; +} + interface RecordedLog { message: string; fields: Record; } +interface RecordedSpawn { + argv0: string | undefined; + shell: string; + args: string[]; + timeoutMs: number | undefined; +} + +interface SpawnResultFields { + stdout?: string; + stderr?: string; + status?: number | null; + signal?: NodeJS.Signals | null; + error?: Error; +} + class RecordingLoginShellLogger { readonly infos: RecordedLog[] = []; readonly warnings: RecordedLog[] = []; @@ -41,6 +62,41 @@ function createEnv(home: string): NodeJS.ProcessEnv { }; } +function createTestClock(): TestClock { + let currentMs = 1_000; + return { + advance: (ms: number) => { + currentMs += ms; + }, + now: () => currentMs, + }; +} + +function spawnResult(fields: SpawnResultFields): SpawnSyncReturns { + const stdout = fields.stdout ?? ""; + const stderr = fields.stderr ?? ""; + return { + pid: 0, + output: [null, stdout, stderr], + stdout, + stderr, + status: fields.status === undefined ? 0 : fields.status, + signal: fields.signal ?? null, + error: fields.error, + } satisfies SpawnSyncReturns; +} + +function successResult(shellCommand: string, env: NodeJS.ProcessEnv): SpawnSyncReturns { + const marker = markerFromShellCommand(shellCommand); + const stdout = `${marker}${JSON.stringify(env)}${marker}`; + return spawnResult({ stdout }); +} + +function shellArgsFromRecordedCall(call: RecordedSpawn | undefined): string[] { + if (!call) return []; + return call.args.slice(0, -1); +} + function markerFromShellCommand(shellCommand: string): string { const match = /"([0-9a-f]{12})" \+ JSON\.stringify\(process\.env\) \+ "\1"/.exec(shellCommand); if (!match?.[1]) throw new Error(`missing env marker in shell command: ${shellCommand}`); @@ -55,6 +111,344 @@ async function createShellHome(): Promise { return await mkdtemp(path.join(os.tmpdir(), "paseo-login-shell-env-")); } +describe("login shell env retry behavior", () => { + it("applies the interactive env without retrying", () => { + const env = createEnv(fakeHome); + const logger = new RecordingLoginShellLogger(); + const clock = createTestClock(); + const calls: RecordedSpawn[] = []; + const interactivePath = "/interactive/bin:/usr/bin:/bin"; + const spawnSync: LoginShellSpawnSync = (shell, args, options) => { + const recordedArgs = Array.isArray(args) ? args.map(String) : []; + calls.push({ + argv0: options?.argv0, + shell: String(shell), + args: recordedArgs, + timeoutMs: options?.timeout, + }); + clock.advance(5); + return successResult(String(recordedArgs.at(-1)), { ...env, PATH: interactivePath }); + }; + + inheritLoginShellEnv({ env, logger, now: clock.now, platform: "darwin", spawnSync }); + + expect(env.PATH).toBe(interactivePath); + expect(calls).toHaveLength(1); + expect(shellArgsFromRecordedCall(calls[0])).toEqual(["-i", "-l", "-c"]); + expect(calls[0]?.timeoutMs).toBe(15_000); + expect(logger.infos.map((entry) => entry.message)).toEqual([ + "[login-shell-env] start", + "[login-shell-env] attempt applied", + "[login-shell-env] applied", + ]); + expect(logger.infos[1]?.fields).toMatchObject({ + attemptKind: "interactive", + shellArgs: ["-i", "-l", "-c"], + reason: "success", + timeoutMs: 15_000, + }); + expect(logger.infos[2]?.fields).toMatchObject({ + attemptKind: "interactive", + durationMs: 5, + timeoutMs: 30_000, + beforePath: basePath, + afterPath: interactivePath, + pathChanged: true, + }); + expect(logger.warnings).toEqual([]); + }); + + it("retries non-interactively after an interactive timeout", () => { + const env = createEnv(fakeHome); + const logger = new RecordingLoginShellLogger(); + const clock = createTestClock(); + const calls: RecordedSpawn[] = []; + const nonInteractivePath = "/login/bin:/usr/bin:/bin"; + const timeoutError = Object.assign(new Error("spawnSync ETIMEDOUT"), { + code: "ETIMEDOUT", + }); + let timedOutStdout = ""; + const spawnSync: LoginShellSpawnSync = (shell, args, options) => { + const recordedArgs = Array.isArray(args) ? args.map(String) : []; + calls.push({ + argv0: options?.argv0, + shell: String(shell), + args: recordedArgs, + timeoutMs: options?.timeout, + }); + + if (calls.length === 1) { + const marker = markerFromShellCommand(String(recordedArgs.at(-1))); + timedOutStdout = `${marker}${JSON.stringify({ ...env, PATH: "/timed-out/bin" })}${marker}`; + clock.advance(15_000); + return spawnResult({ + stdout: timedOutStdout, + status: null, + signal: "SIGTERM", + error: timeoutError, + }); + } + + clock.advance(3); + return successResult(String(recordedArgs.at(-1)), { ...env, PATH: nonInteractivePath }); + }; + + inheritLoginShellEnv({ env, logger, now: clock.now, platform: "darwin", spawnSync }); + + expect(env.PATH).toBe(nonInteractivePath); + expect(calls).toHaveLength(2); + expect(shellArgsFromRecordedCall(calls[0])).toEqual(["-i", "-l", "-c"]); + expect(shellArgsFromRecordedCall(calls[1])).toEqual(["-l", "-c"]); + expect(calls[0]?.timeoutMs).toBe(15_000); + expect(calls[1]?.timeoutMs).toBe(15_000); + expect(logger.warnings).toHaveLength(1); + expect(logger.warnings[0]?.message).toBe("[login-shell-env] attempt failed; retrying"); + expect(logger.warnings[0]?.fields).toMatchObject({ + reason: "timeout", + attemptKind: "interactive", + shellArgs: ["-i", "-l", "-c"], + status: null, + signal: "SIGTERM", + stdoutLength: timedOutStdout.length, + markerFound: true, + errorCode: "ETIMEDOUT", + durationMs: 15_000, + timeoutMs: 15_000, + }); + expect(logger.infos[1]?.fields).toMatchObject({ + attemptKind: "non-interactive", + shellArgs: ["-l", "-c"], + reason: "success", + durationMs: 3, + timeoutMs: 15_000, + }); + expect(logger.infos[2]?.fields).toMatchObject({ + attemptKind: "non-interactive", + durationMs: 15_003, + timeoutMs: 30_000, + beforePath: basePath, + afterPath: nonInteractivePath, + pathChanged: true, + }); + expectNoRawStdout(logger.warnings[0]?.fields ?? {}); + }); + + it("retries non-interactively when the interactive marker is missing", () => { + const env = createEnv(fakeHome); + const logger = new RecordingLoginShellLogger(); + const clock = createTestClock(); + const calls: RecordedSpawn[] = []; + const nonInteractivePath = "/profile/bin:/usr/bin:/bin"; + const missingMarkerStdout = "switched shells before command\n"; + const spawnSync: LoginShellSpawnSync = (shell, args, options) => { + const recordedArgs = Array.isArray(args) ? args.map(String) : []; + calls.push({ + argv0: options?.argv0, + shell: String(shell), + args: recordedArgs, + timeoutMs: options?.timeout, + }); + + if (calls.length === 1) { + clock.advance(25); + return spawnResult({ stdout: missingMarkerStdout }); + } + + clock.advance(2); + return successResult(String(recordedArgs.at(-1)), { ...env, PATH: nonInteractivePath }); + }; + + inheritLoginShellEnv({ env, logger, now: clock.now, platform: "darwin", spawnSync }); + + expect(env.PATH).toBe(nonInteractivePath); + expect(calls).toHaveLength(2); + expect(shellArgsFromRecordedCall(calls[0])).toEqual(["-i", "-l", "-c"]); + expect(shellArgsFromRecordedCall(calls[1])).toEqual(["-l", "-c"]); + expect(calls[0]?.timeoutMs).toBe(15_000); + expect(calls[1]?.timeoutMs).toBe(29_975); + expect(logger.warnings).toHaveLength(1); + expect(logger.warnings[0]?.message).toBe("[login-shell-env] attempt failed; retrying"); + expect(logger.warnings[0]?.fields).toMatchObject({ + reason: "marker-missing", + attemptKind: "interactive", + shellArgs: ["-i", "-l", "-c"], + status: 0, + signal: null, + stdoutLength: missingMarkerStdout.length, + markerFound: false, + durationMs: 25, + timeoutMs: 15_000, + }); + expect(logger.infos[1]?.fields).toMatchObject({ + attemptKind: "non-interactive", + reason: "success", + durationMs: 2, + timeoutMs: 29_975, + }); + expectNoRawStdout(logger.warnings[0]?.fields ?? {}); + }); + + it("keeps the inherited env after both attempts fail", () => { + const env = createEnv(fakeHome); + const logger = new RecordingLoginShellLogger(); + const clock = createTestClock(); + const calls: RecordedSpawn[] = []; + const spawnError = Object.assign(new Error("spawnSync ENOENT"), { + code: "ENOENT", + }); + const spawnSync: LoginShellSpawnSync = (shell, args, options) => { + const recordedArgs = Array.isArray(args) ? args.map(String) : []; + calls.push({ + argv0: options?.argv0, + shell: String(shell), + args: recordedArgs, + timeoutMs: options?.timeout, + }); + + if (calls.length === 1) { + clock.advance(10); + return spawnResult({ stdout: "no marker\n" }); + } + + clock.advance(5); + return spawnResult({ + status: null, + signal: null, + error: spawnError, + }); + }; + + inheritLoginShellEnv({ env, logger, now: clock.now, platform: "darwin", spawnSync }); + + expect(env.PATH).toBe(basePath); + expect(calls).toHaveLength(2); + expect(calls[0]?.timeoutMs).toBe(15_000); + expect(calls[1]?.timeoutMs).toBe(29_990); + expect(logger.infos.map((entry) => entry.message)).toEqual(["[login-shell-env] start"]); + expect(logger.warnings.map((entry) => entry.message)).toEqual([ + "[login-shell-env] attempt failed; retrying", + "[login-shell-env] attempt failed", + "[login-shell-env] failed; keeping inherited env", + ]); + expect(logger.warnings[0]?.fields).toMatchObject({ + reason: "marker-missing", + attemptKind: "interactive", + shellArgs: ["-i", "-l", "-c"], + durationMs: 10, + timeoutMs: 15_000, + }); + expect(logger.warnings[1]?.fields).toMatchObject({ + reason: "spawn-error", + attemptKind: "non-interactive", + shellArgs: ["-l", "-c"], + durationMs: 5, + errorCode: "ENOENT", + timeoutMs: 29_990, + }); + expect(logger.warnings[2]?.fields).toMatchObject({ + reason: "spawn-error", + attemptKind: "non-interactive", + shellArgs: ["-l", "-c"], + errorCode: "ENOENT", + durationMs: 15, + timeoutMs: 30_000, + beforePath: basePath, + afterPath: basePath, + pathChanged: false, + }); + expectNoRawStdout(logger.warnings[2]?.fields ?? {}); + }); + + it("uses the configured shell env timeout", () => { + const env = { + ...createEnv(fakeHome), + PASEO_SHELL_ENV_TIMEOUT_MS: "1234", + }; + const logger = new RecordingLoginShellLogger(); + const clock = createTestClock(); + const calls: RecordedSpawn[] = []; + const configuredPath = "/configured/bin:/usr/bin:/bin"; + const spawnSync: LoginShellSpawnSync = (shell, args, options) => { + const recordedArgs = Array.isArray(args) ? args.map(String) : []; + calls.push({ + argv0: options?.argv0, + shell: String(shell), + args: recordedArgs, + timeoutMs: options?.timeout, + }); + clock.advance(4); + return successResult(String(recordedArgs.at(-1)), { ...env, PATH: configuredPath }); + }; + + inheritLoginShellEnv({ env, logger, now: clock.now, platform: "darwin", spawnSync }); + + expect(env.PATH).toBe(configuredPath); + expect(calls).toHaveLength(1); + expect(calls[0]?.timeoutMs).toBe(617); + expect(logger.infos[0]?.fields).toMatchObject({ + timeoutMs: 1234, + }); + expect(logger.infos[1]?.fields).toMatchObject({ + timeoutMs: 617, + }); + expect(logger.infos[2]?.fields).toMatchObject({ + durationMs: 4, + timeoutMs: 1234, + }); + }); + + it("uses argv0 for the non-interactive tcsh login retry", () => { + const env = { + ...createEnv(fakeHome), + SHELL: "/bin/tcsh", + }; + const logger = new RecordingLoginShellLogger(); + const clock = createTestClock(); + const calls: RecordedSpawn[] = []; + const nonInteractivePath = "/tcsh/login/bin:/usr/bin:/bin"; + const spawnSync: LoginShellSpawnSync = (shell, args, options) => { + const recordedArgs = Array.isArray(args) ? args.map(String) : []; + calls.push({ + argv0: options?.argv0, + shell: String(shell), + args: recordedArgs, + timeoutMs: options?.timeout, + }); + + if (calls.length === 1) { + clock.advance(8); + return spawnResult({ stdout: "no marker\n" }); + } + + clock.advance(2); + return successResult(String(recordedArgs.at(-1)), { ...env, PATH: nonInteractivePath }); + }; + + inheritLoginShellEnv({ env, logger, now: clock.now, platform: "darwin", spawnSync }); + + expect(env.PATH).toBe(nonInteractivePath); + expect(calls).toHaveLength(2); + expect(shellArgsFromRecordedCall(calls[0])).toEqual(["-ic"]); + expect(calls[0]?.argv0).toBeUndefined(); + expect(shellArgsFromRecordedCall(calls[1])).toEqual(["-c"]); + expect(calls[1]?.argv0).toBe("-tcsh"); + expect(calls[1]?.timeoutMs).toBe(29_992); + expect(logger.warnings[0]?.fields).toMatchObject({ + attemptKind: "interactive", + shellArgs: ["-ic"], + reason: "marker-missing", + timeoutMs: 15_000, + }); + expect(logger.infos[1]?.fields).toMatchObject({ + attemptKind: "non-interactive", + argv0: "-tcsh", + shellArgs: ["-c"], + reason: "success", + timeoutMs: 29_992, + }); + }); +}); + describeIfZsh("login shell env", () => { const homes = new Set(); @@ -77,10 +471,17 @@ describeIfZsh("login shell env", () => { expect(env.PATH?.split(path.delimiter)[0]).toBe(binDir); expect(logger.infos.map((entry) => entry.message)).toEqual([ "[login-shell-env] start", + "[login-shell-env] attempt applied", "[login-shell-env] applied", ]); expect(logger.warnings).toEqual([]); expect(logger.infos[1]?.fields).toMatchObject({ + attemptKind: "interactive", + shellArgs: ["-i", "-l", "-c"], + reason: "success", + }); + expect(logger.infos[2]?.fields).toMatchObject({ + attemptKind: "interactive", beforePath: basePath, afterPath: env.PATH, pathChanged: true, @@ -100,6 +501,7 @@ describeIfZsh("login shell env", () => { expect(env.PASEO_TEST_ZSHRC_LOADED).toBe("1"); expect(logger.infos.map((entry) => entry.message)).toEqual([ "[login-shell-env] start", + "[login-shell-env] attempt applied", "[login-shell-env] applied", ]); expect(logger.warnings).toEqual([]); @@ -116,20 +518,42 @@ describeIfZsh("login shell env", () => { expect(env.PATH).toBe(basePath); expect(logger.infos.map((entry) => entry.message)).toEqual(["[login-shell-env] start"]); - expect(logger.warnings).toHaveLength(1); - expect(logger.warnings[0]?.message).toBe("[login-shell-env] failed; keeping inherited env"); + expect(logger.warnings.map((entry) => entry.message)).toEqual([ + "[login-shell-env] attempt failed; retrying", + "[login-shell-env] attempt failed", + "[login-shell-env] failed; keeping inherited env", + ]); expect(logger.warnings[0]?.fields).toMatchObject({ reason: "non-zero-exit", + attemptKind: "interactive", shell: zsh, shellArgs: ["-i", "-l", "-c"], status: 42, stdoutLength: "premarker\n".length, markerFound: false, + }); + expect(logger.warnings[1]?.fields).toMatchObject({ + reason: "non-zero-exit", + attemptKind: "non-interactive", + shell: zsh, + shellArgs: ["-l", "-c"], + status: 42, + stdoutLength: "premarker\n".length, + markerFound: false, + }); + expect(logger.warnings[2]?.fields).toMatchObject({ + reason: "non-zero-exit", + attemptKind: "non-interactive", + shell: zsh, + shellArgs: ["-l", "-c"], + status: 42, + stdoutLength: "premarker\n".length, + markerFound: false, beforePath: basePath, afterPath: basePath, pathChanged: false, }); - expectNoRawStdout(logger.warnings[0]?.fields ?? {}); + expectNoRawStdout(logger.warnings[2]?.fields ?? {}); }); it("keeps the inherited env when a timed-out shell printed an env marker", async () => { @@ -162,10 +586,14 @@ describeIfZsh("login shell env", () => { expect(env.PATH).toBe(basePath); expect(logger.infos.map((entry) => entry.message)).toEqual(["[login-shell-env] start"]); - expect(logger.warnings).toHaveLength(1); - expect(logger.warnings[0]?.message).toBe("[login-shell-env] failed; keeping inherited env"); + expect(logger.warnings.map((entry) => entry.message)).toEqual([ + "[login-shell-env] attempt failed; retrying", + "[login-shell-env] attempt failed", + "[login-shell-env] failed; keeping inherited env", + ]); expect(logger.warnings[0]?.fields).toMatchObject({ - reason: "spawn-error", + reason: "timeout", + attemptKind: "interactive", shell: zsh, shellArgs: ["-i", "-l", "-c"], status: null, @@ -173,10 +601,32 @@ describeIfZsh("login shell env", () => { stdoutLength: stdout.length, markerFound: true, errorCode: "ETIMEDOUT", + }); + expect(logger.warnings[1]?.fields).toMatchObject({ + reason: "timeout", + attemptKind: "non-interactive", + shell: zsh, + shellArgs: ["-l", "-c"], + status: null, + signal: "SIGTERM", + stdoutLength: stdout.length, + markerFound: true, + errorCode: "ETIMEDOUT", + }); + expect(logger.warnings[2]?.fields).toMatchObject({ + reason: "timeout", + attemptKind: "non-interactive", + shell: zsh, + shellArgs: ["-l", "-c"], + status: null, + signal: "SIGTERM", + stdoutLength: stdout.length, + markerFound: true, + errorCode: "ETIMEDOUT", beforePath: basePath, afterPath: basePath, pathChanged: false, }); - expectNoRawStdout(logger.warnings[0]?.fields ?? {}); + expectNoRawStdout(logger.warnings[2]?.fields ?? {}); }); }); diff --git a/packages/desktop/src/login-shell-env.ts b/packages/desktop/src/login-shell-env.ts index 5d6698e65..a6be7f012 100644 --- a/packages/desktop/src/login-shell-env.ts +++ b/packages/desktop/src/login-shell-env.ts @@ -9,14 +9,17 @@ import { userInfo as defaultUserInfo } from "node:os"; import { basename } from "node:path"; import defaultLog from "electron-log/main"; -const RESOLVE_TIMEOUT_MS = 10_000; +const DEFAULT_RESOLVE_TIMEOUT_MS = 30_000; +const TIMEOUT_ENV_KEY = "PASEO_SHELL_ENV_TIMEOUT_MS"; const STDERR_LOG_LIMIT = 2000; type LoginShellEnvLogger = Pick; +type ShellEnvAttemptKind = "interactive" | "non-interactive"; interface LoginShellEnvDependencies { env?: NodeJS.ProcessEnv; logger?: LoginShellEnvLogger; + now?: () => number; platform?: NodeJS.Platform; spawnSync?: typeof defaultSpawnSync; userInfo?: typeof defaultUserInfo; @@ -37,6 +40,8 @@ function pathEnv(env: NodeJS.ProcessEnv | Record): string | null interface ShellEnvErrorDetails { reason: string; + attemptKind?: ShellEnvAttemptKind; + argv0?: string; shell?: string; shellArgs?: string[]; status?: number | null; @@ -57,19 +62,114 @@ class ShellEnvError extends Error { } } -function throwIfShellFailed( - result: SpawnSyncReturns, - regex: RegExp, - shell: string, - shellArgs: string[], -): void { +interface ShellEnvAttempt { + kind: ShellEnvAttemptKind; + argv0?: string; + shellArgs: string[]; +} + +interface ShellEnvCommand { + command: string; + attempts: ShellEnvAttempt[]; +} + +interface ResolvedShellEnv { + env: Record; + attemptKind: ShellEnvAttemptKind; +} + +interface AttemptTimeoutInput { + totalTimeoutMs: number; + attemptsStartedAt: number; + now: () => number; + attempts: ShellEnvAttempt[]; + index: number; +} + +interface ThrowIfShellFailedInput { + result: SpawnSyncReturns; + regex: RegExp; + shell: string; + attempt: ShellEnvAttempt; +} + +interface ShellEnvForAttemptInput { + deps: Required; + shellEnv: NodeJS.ProcessEnv; + shell: string; + command: string; + regex: RegExp; + attempt: ShellEnvAttempt; + timeoutMs: number; +} + +interface ShellAttemptErrorDetailsInput { + error: unknown; + shell: string; + attempt: ShellEnvAttempt; +} + +interface LogShellAttemptFailureInput { + deps: Required; + error: unknown; + details: ShellEnvErrorDetails; + durationMs: number; + timeoutMs: number; + willRetry: boolean; +} + +interface RestoreElectronEnvInput { + env: Record; + savedRunAsNode: string | undefined; + savedNoAttach: string | undefined; +} + +interface ResolveShellEnvInput { + deps: Required; + timeoutMs: number; +} + +function timeoutMsFromEnv(env: NodeJS.ProcessEnv): number { + const rawTimeoutMs = env[TIMEOUT_ENV_KEY]; + if (!rawTimeoutMs) return DEFAULT_RESOLVE_TIMEOUT_MS; + + const timeoutMs = Number.parseInt(rawTimeoutMs, 10); + return Number.isFinite(timeoutMs) && timeoutMs > 0 ? timeoutMs : DEFAULT_RESOLVE_TIMEOUT_MS; +} + +function timeoutMsForAttempt({ + totalTimeoutMs, + attemptsStartedAt, + now, + attempts, + index, +}: AttemptTimeoutInput): number | null { + if (attempts.length === 1) return totalTimeoutMs; + if (index === 0) return Math.max(1, Math.floor(totalTimeoutMs / 2)); + + const remainingMs = totalTimeoutMs - (now() - attemptsStartedAt); + return remainingMs > 0 ? remainingMs : null; +} + +function errorCode(error: unknown): string | null { + return error instanceof Error ? ((error as NodeJS.ErrnoException).code ?? null) : null; +} + +function shellFailureReason(result: SpawnSyncReturns): string { + if (errorCode(result.error) === "ETIMEDOUT") return "timeout"; + return result.error ? "spawn-error" : "signal"; +} + +function throwIfShellFailed({ result, regex, shell, attempt }: ThrowIfShellFailedInput): void { if (result.error || result.signal) { throw new ShellEnvError( "login shell did not complete", { - reason: result.error ? "spawn-error" : "signal", + reason: shellFailureReason(result), + attemptKind: attempt.kind, + argv0: attempt.argv0, shell, - shellArgs, + shellArgs: attempt.shellArgs, status: result.status, signal: result.signal, stdoutLength: result.stdout?.length ?? 0, @@ -82,8 +182,10 @@ function throwIfShellFailed( if (result.status !== 0 && result.status !== null) { throw new ShellEnvError("login shell exited non-zero", { reason: "non-zero-exit", + attemptKind: attempt.kind, + argv0: attempt.argv0, shell, - shellArgs, + shellArgs: attempt.shellArgs, status: result.status, signal: result.signal, stdoutLength: result.stdout?.length ?? 0, @@ -96,8 +198,10 @@ function throwIfShellFailed( "login shell produced no stdout", { reason: "no-stdout", + attemptKind: attempt.kind, + argv0: attempt.argv0, shell, - shellArgs, + shellArgs: attempt.shellArgs, status: result.status, signal: result.signal, stdoutLength: result.stdout?.length ?? 0, @@ -123,7 +227,171 @@ function getSystemShell( return deps.platform === "darwin" ? "/bin/zsh" : "/bin/bash"; } -function resolveShellEnv(deps: Required): Record { +function shellEnvCommand({ shell, mark }: { shell: string; mark: string }): ShellEnvCommand { + const name = basename(shell); + + if (/^(?:pwsh|powershell)(?:-preview)?$/.test(name)) { + return { + command: `& '${process.execPath}' -p '''${mark}'' + JSON.stringify(process.env) + ''${mark}'''`, + attempts: [{ kind: "non-interactive", shellArgs: ["-Login", "-Command"] }], + }; + } + + if (name === "nu") { + return { + command: `^'${process.execPath}' -p '"${mark}" + JSON.stringify(process.env) + "${mark}"'`, + attempts: [ + { kind: "interactive", shellArgs: ["-i", "-l", "-c"] }, + { kind: "non-interactive", shellArgs: ["-l", "-c"] }, + ], + }; + } + + if (name === "xonsh") { + return { + command: `import os, json; print("${mark}", json.dumps(dict(os.environ)), "${mark}")`, + attempts: [ + { kind: "interactive", shellArgs: ["-i", "-l", "-c"] }, + { kind: "non-interactive", shellArgs: ["-l", "-c"] }, + ], + }; + } + + if (name === "tcsh" || name === "csh") { + return { + command: `'${process.execPath}' -p '"${mark}" + JSON.stringify(process.env) + "${mark}"'`, + attempts: [ + { kind: "interactive", shellArgs: ["-ic"] }, + { kind: "non-interactive", argv0: `-${name}`, shellArgs: ["-c"] }, + ], + }; + } + + return { + command: `'${process.execPath}' -p '"${mark}" + JSON.stringify(process.env) + "${mark}"'`, + attempts: [ + { kind: "interactive", shellArgs: ["-i", "-l", "-c"] }, + { kind: "non-interactive", shellArgs: ["-l", "-c"] }, + ], + }; +} + +function shellEnvForAttempt({ + deps, + shellEnv, + shell, + command, + regex, + attempt, + timeoutMs, +}: ShellEnvForAttemptInput): Record { + const result = deps.spawnSync(shell, [...attempt.shellArgs, command], { + argv0: attempt.argv0, + encoding: "utf8", + timeout: timeoutMs, + windowsHide: true, + env: { + ...shellEnv, + ELECTRON_RUN_AS_NODE: "1", + ELECTRON_NO_ATTACH_CONSOLE: "1", + }, + }); + + throwIfShellFailed({ result, regex, shell, attempt }); + + const match = regex.exec(result.stdout); + if (!match?.[1]) { + throw new ShellEnvError("login shell output did not contain environment marker", { + reason: "marker-missing", + attemptKind: attempt.kind, + argv0: attempt.argv0, + shell, + shellArgs: attempt.shellArgs, + status: result.status, + signal: result.signal, + stdoutLength: result.stdout.length, + markerFound: false, + stderr: result.stderr, + }); + } + + try { + return JSON.parse(match[1]) as Record; + } catch (error) { + throw new ShellEnvError( + "failed to parse login shell environment JSON", + { + reason: "json-parse", + attemptKind: attempt.kind, + argv0: attempt.argv0, + shell, + shellArgs: attempt.shellArgs, + status: result.status, + signal: result.signal, + stdoutLength: result.stdout.length, + markerFound: true, + stderr: result.stderr, + }, + { cause: error }, + ); + } +} + +function shellAttemptErrorDetails({ + error, + shell, + attempt, +}: ShellAttemptErrorDetailsInput): ShellEnvErrorDetails { + return error instanceof ShellEnvError + ? error.details + : { + reason: "throw", + attemptKind: attempt.kind, + argv0: attempt.argv0, + shell, + shellArgs: attempt.shellArgs, + }; +} + +function logShellAttemptFailure({ + deps, + error, + details, + durationMs, + timeoutMs, + willRetry, +}: LogShellAttemptFailureInput): void { + const cause = error instanceof Error ? error.cause : undefined; + deps.logger.warn( + willRetry ? "[login-shell-env] attempt failed; retrying" : "[login-shell-env] attempt failed", + { + ...details, + durationMs, + timeoutMs, + error: error instanceof Error ? error.message : String(error), + errorCode: error instanceof ShellEnvError ? errorCode(cause) : errorCode(error), + stderr: truncateForLog(details.stderr), + }, + ); +} + +function restoreElectronEnv({ env, savedRunAsNode, savedNoAttach }: RestoreElectronEnvInput): void { + if (savedRunAsNode) { + env.ELECTRON_RUN_AS_NODE = savedRunAsNode; + } else { + delete env.ELECTRON_RUN_AS_NODE; + } + + if (savedNoAttach) { + env.ELECTRON_NO_ATTACH_CONSOLE = savedNoAttach; + } else { + delete env.ELECTRON_NO_ATTACH_CONSOLE; + } + + delete env.XDG_RUNTIME_DIR; +} + +function resolveShellEnv({ deps, timeoutMs }: ResolveShellEnvInput): ResolvedShellEnv { if (deps.platform === "win32") { throw new ShellEnvError("login shell env is not resolved on Windows", { reason: "win32" }); } @@ -135,28 +403,7 @@ function resolveShellEnv(deps: Required): Record): Record ({ + attemptKind: attempt.kind, + argv0: attempt.argv0, + shellArgs: attempt.shellArgs, + })), + timeoutMs, beforePath: pathEnv(deps.env), }); - const result = deps.spawnSync(shell, [...shellArgs, command], { - encoding: "utf8", - timeout: RESOLVE_TIMEOUT_MS, - windowsHide: true, - env: { - ...shellEnv, - ELECTRON_RUN_AS_NODE: "1", - ELECTRON_NO_ATTACH_CONSOLE: "1", - }, - }); + let lastError: unknown; + const attemptsStartedAt = deps.now(); - throwIfShellFailed(result, regex, shell, shellArgs); - - const match = regex.exec(result.stdout); - if (!match?.[1]) { - throw new ShellEnvError("login shell output did not contain environment marker", { - reason: "marker-missing", - shell, - shellArgs, - status: result.status, - signal: result.signal, - stdoutLength: result.stdout.length, - markerFound: false, - stderr: result.stderr, + for (const [index, attempt] of attempts.entries()) { + const attemptTimeoutMs = timeoutMsForAttempt({ + totalTimeoutMs: timeoutMs, + attemptsStartedAt, + now: deps.now, + attempts, + index, }); - } + if (attemptTimeoutMs === null) break; - try { - const env = JSON.parse(match[1]) as Record; + const attemptStartedAt = deps.now(); - if (savedRunAsNode) { - env.ELECTRON_RUN_AS_NODE = savedRunAsNode; - } else { - delete env.ELECTRON_RUN_AS_NODE; - } - - if (savedNoAttach) { - env.ELECTRON_NO_ATTACH_CONSOLE = savedNoAttach; - } else { - delete env.ELECTRON_NO_ATTACH_CONSOLE; - } - - delete env.XDG_RUNTIME_DIR; - - return env; - } catch (error) { - throw new ShellEnvError( - "failed to parse login shell environment JSON", - { - reason: "json-parse", + try { + const env = shellEnvForAttempt({ + deps, + shellEnv, shell, - shellArgs, - status: result.status, - signal: result.signal, - stdoutLength: result.stdout.length, - markerFound: true, - stderr: result.stderr, - }, - { cause: error }, - ); + command, + regex, + attempt, + timeoutMs: attemptTimeoutMs, + }); + const durationMs = deps.now() - attemptStartedAt; + restoreElectronEnv({ env, savedRunAsNode, savedNoAttach }); + + deps.logger.info("[login-shell-env] attempt applied", { + attemptKind: attempt.kind, + argv0: attempt.argv0, + shell, + shellArgs: attempt.shellArgs, + reason: "success", + durationMs, + timeoutMs: attemptTimeoutMs, + }); + + return { env, attemptKind: attempt.kind }; + } catch (error) { + const details = shellAttemptErrorDetails({ error, shell, attempt }); + const durationMs = deps.now() - attemptStartedAt; + const willRetry = + index < attempts.length - 1 && + timeoutMsForAttempt({ + totalTimeoutMs: timeoutMs, + attemptsStartedAt, + now: deps.now, + attempts, + index: index + 1, + }) !== null; + lastError = error; + logShellAttemptFailure({ + deps, + error, + details, + durationMs, + timeoutMs: attemptTimeoutMs, + willRetry, + }); + } } + + throw lastError; } /** @@ -245,18 +500,22 @@ export function inheritLoginShellEnv(input: LoginShellEnvDependencies = {}): voi const deps: Required = { env: input.env ?? process.env, logger: input.logger ?? defaultLog, + now: input.now ?? Date.now, platform: input.platform ?? process.platform, spawnSync: input.spawnSync ?? defaultSpawnSync, userInfo: input.userInfo ?? defaultUserInfo, }; const beforePath = pathEnv(deps.env); - const startedAt = Date.now(); + const startedAt = deps.now(); + const timeoutMs = timeoutMsFromEnv(deps.env); try { - const env = resolveShellEnv(deps); + const { env, attemptKind } = resolveShellEnv({ deps, timeoutMs }); Object.assign(deps.env, env); deps.logger.info("[login-shell-env] applied", { - durationMs: Date.now() - startedAt, + attemptKind, + durationMs: deps.now() - startedAt, + timeoutMs, beforePath, afterPath: pathEnv(deps.env), pathChanged: beforePath !== pathEnv(deps.env), @@ -270,8 +529,8 @@ export function inheritLoginShellEnv(input: LoginShellEnvDependencies = {}): voi const cause = error instanceof Error ? error.cause : undefined; deps.logger.warn("[login-shell-env] failed; keeping inherited env", { ...details, - durationMs: Date.now() - startedAt, - timeoutMs: RESOLVE_TIMEOUT_MS, + durationMs: deps.now() - startedAt, + timeoutMs, error: error instanceof Error ? error.message : String(error), errorCode: (cause as NodeJS.ErrnoException | undefined)?.code ?? null, stderr: truncateForLog(details.stderr),