Make login shell environment failures visible

Log the desktop login-shell env start, applied, and failed outcomes while keeping stdout redacted to marker and length diagnostics.
2026-06-20 16:59:09 +07:00
parent 4354ad3e27
commit b8bf2345fd
2 changed files with 371 additions and 24 deletions
@@ -0,0 +1,182 @@
+import type { SpawnSyncReturns } from "node:child_process";
+import { existsSync } from "node:fs";
+import { mkdtemp, mkdir, rm, writeFile } from "node:fs/promises";
+import os from "node:os";
+import path from "node:path";
+import { afterEach, describe, expect, it } from "vitest";
+
+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";
+type LoginShellEnvInput = NonNullable<Parameters<typeof inheritLoginShellEnv>[0]>;
+type LoginShellSpawnSync = NonNullable<LoginShellEnvInput["spawnSync"]>;
+
+interface RecordedLog {
+  message: string;
+  fields: Record<string, unknown>;
+}
+
+class RecordingLoginShellLogger {
+  readonly infos: RecordedLog[] = [];
+  readonly warnings: RecordedLog[] = [];
+
+  info(message: string, fields: Record<string, unknown>): void {
+    this.infos.push({ message, fields });
+  }
+
+  warn(message: string, fields: Record<string, unknown>): void {
+    this.warnings.push({ message, fields });
+  }
+}
+
+function createEnv(home: string): NodeJS.ProcessEnv {
+  return {
+    HOME: home,
+    USER: "paseo-test",
+    LOGNAME: "paseo-test",
+    SHELL: zsh,
+    PATH: basePath,
+  };
+}
+
+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}`);
+  return match[1];
+}
+
+function expectNoRawStdout(fields: Record<string, unknown>): void {
+  expect(fields).not.toHaveProperty("stdout");
+}
+
+async function createShellHome(): Promise<string> {
+  return await mkdtemp(path.join(os.tmpdir(), "paseo-login-shell-env-"));
+}
+
+describeIfZsh("login shell env", () => {
+  const homes = new Set<string>();
+
+  afterEach(async () => {
+    await Promise.all([...homes].map((home) => rm(home, { recursive: true, force: true })));
+    homes.clear();
+  });
+
+  it("applies PATH from the user's login shell", async () => {
+    const home = await createShellHome();
+    homes.add(home);
+    const binDir = path.join(home, "tools");
+    await mkdir(binDir);
+    await writeFile(path.join(home, ".zprofile"), 'export PATH="$HOME/tools:$PATH"\n');
+    const env = createEnv(home);
+    const logger = new RecordingLoginShellLogger();
+
+    inheritLoginShellEnv({ env, logger });
+
+    expect(env.PATH?.split(path.delimiter)[0]).toBe(binDir);
+    expect(logger.infos.map((entry) => entry.message)).toEqual([
+      "[login-shell-env] start",
+      "[login-shell-env] applied",
+    ]);
+    expect(logger.warnings).toEqual([]);
+    expect(logger.infos[1]?.fields).toMatchObject({
+      beforePath: basePath,
+      afterPath: env.PATH,
+      pathChanged: true,
+      shell: zsh,
+    });
+  });
+
+  it("loads the user's zshrc while resolving the login shell env", async () => {
+    const home = await createShellHome();
+    homes.add(home);
+    await writeFile(path.join(home, ".zshrc"), "export PASEO_TEST_ZSHRC_LOADED=1\n");
+    const env = createEnv(home);
+    const logger = new RecordingLoginShellLogger();
+
+    inheritLoginShellEnv({ env, logger });
+
+    expect(env.PASEO_TEST_ZSHRC_LOADED).toBe("1");
+    expect(logger.infos.map((entry) => entry.message)).toEqual([
+      "[login-shell-env] start",
+      "[login-shell-env] applied",
+    ]);
+    expect(logger.warnings).toEqual([]);
+  });
+
+  it("keeps the inherited env and logs stdout diagnostics when shell startup fails", async () => {
+    const home = await createShellHome();
+    homes.add(home);
+    await writeFile(path.join(home, ".zshenv"), "print -r -- premarker\nexit 42\n");
+    const env = createEnv(home);
+    const logger = new RecordingLoginShellLogger();
+
+    inheritLoginShellEnv({ env, logger });
+
+    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[0]?.fields).toMatchObject({
+      reason: "non-zero-exit",
+      shell: zsh,
+      shellArgs: ["-i", "-l", "-c"],
+      status: 42,
+      stdoutLength: "premarker\n".length,
+      markerFound: false,
+      beforePath: basePath,
+      afterPath: basePath,
+      pathChanged: false,
+    });
+    expectNoRawStdout(logger.warnings[0]?.fields ?? {});
+  });
+
+  it("keeps the inherited env when a timed-out shell printed an env marker", async () => {
+    const home = await createShellHome();
+    homes.add(home);
+    const env = createEnv(home);
+    const logger = new RecordingLoginShellLogger();
+    const timedOutPath = path.join(home, "timed-out");
+    let stdout = "";
+    const timeoutError = Object.assign(new Error("spawnSync ETIMEDOUT"), {
+      code: "ETIMEDOUT",
+    });
+    const spawnSync: LoginShellSpawnSync = (_shell, args) => {
+      const shellCommand = String(Array.isArray(args) ? args.at(-1) : "");
+      const marker = markerFromShellCommand(shellCommand);
+      stdout = `${marker}${JSON.stringify({ ...env, PATH: timedOutPath })}${marker}`;
+
+      return {
+        pid: 0,
+        output: [stdout, stdout, ""],
+        stdout,
+        stderr: "",
+        status: null,
+        signal: "SIGTERM",
+        error: timeoutError,
+      } satisfies SpawnSyncReturns<string>;
+    };
+
+    inheritLoginShellEnv({ env, logger, spawnSync });
+
+    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[0]?.fields).toMatchObject({
+      reason: "spawn-error",
+      shell: zsh,
+      shellArgs: ["-i", "-l", "-c"],
+      status: null,
+      signal: "SIGTERM",
+      stdoutLength: stdout.length,
+      markerFound: true,
+      errorCode: "ETIMEDOUT",
+      beforePath: basePath,
+      afterPath: basePath,
+      pathChanged: false,
+    });
+    expectNoRawStdout(logger.warnings[0]?.fields ?? {});
+  });
+});
@@ -2,35 +2,139 @@
 // https://github.com/microsoft/vscode/blob/main/src/vs/platform/shell/node/shellEnv.ts
 // Licensed under the MIT License.

-import { spawnSync } from "node:child_process";
+import type { SpawnSyncReturns } from "node:child_process";
+import { spawnSync as defaultSpawnSync } from "node:child_process";
 import { randomUUID } from "node:crypto";
-import { userInfo } from "node:os";
+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 STDERR_LOG_LIMIT = 2000;

-function getSystemShell(): string {
-  const shell = process.env.SHELL;
+type LoginShellEnvLogger = Pick<typeof defaultLog, "info" | "warn">;
+
+interface LoginShellEnvDependencies {
+  env?: NodeJS.ProcessEnv;
+  logger?: LoginShellEnvLogger;
+  platform?: NodeJS.Platform;
+  spawnSync?: typeof defaultSpawnSync;
+  userInfo?: typeof defaultUserInfo;
+}
+
+function truncateForLog(value: string | undefined): string | undefined {
+  if (!value) return undefined;
+  const trimmed = value.trim();
+  if (!trimmed) return undefined;
+  return trimmed.length > STDERR_LOG_LIMIT
+    ? `${trimmed.slice(0, STDERR_LOG_LIMIT)}...(truncated)`
+    : trimmed;
+}
+
+function pathEnv(env: NodeJS.ProcessEnv | Record<string, string>): string | null {
+  return env.PATH ?? env.Path ?? null;
+}
+
+interface ShellEnvErrorDetails {
+  reason: string;
+  shell?: string;
+  shellArgs?: string[];
+  status?: number | null;
+  signal?: NodeJS.Signals | null;
+  stdoutLength?: number;
+  markerFound?: boolean;
+  stderr?: string;
+}
+
+class ShellEnvError extends Error {
+  constructor(
+    message: string,
+    readonly details: ShellEnvErrorDetails,
+    options?: { cause?: unknown },
+  ) {
+    super(message, options);
+    this.name = "ShellEnvError";
+  }
+}
+
+function throwIfShellFailed(
+  result: SpawnSyncReturns<string>,
+  regex: RegExp,
+  shell: string,
+  shellArgs: string[],
+): void {
+  if (result.error || result.signal) {
+    throw new ShellEnvError(
+      "login shell did not complete",
+      {
+        reason: result.error ? "spawn-error" : "signal",
+        shell,
+        shellArgs,
+        status: result.status,
+        signal: result.signal,
+        stdoutLength: result.stdout?.length ?? 0,
+        markerFound: regex.test(result.stdout ?? ""),
+        stderr: result.stderr,
+      },
+      { cause: result.error },
+    );
+  }
+  if (result.status !== 0 && result.status !== null) {
+    throw new ShellEnvError("login shell exited non-zero", {
+      reason: "non-zero-exit",
+      shell,
+      shellArgs,
+      status: result.status,
+      signal: result.signal,
+      stdoutLength: result.stdout?.length ?? 0,
+      markerFound: regex.test(result.stdout ?? ""),
+      stderr: result.stderr,
+    });
+  }
+  if (!result.stdout) {
+    throw new ShellEnvError(
+      "login shell produced no stdout",
+      {
+        reason: "no-stdout",
+        shell,
+        shellArgs,
+        status: result.status,
+        signal: result.signal,
+        stdoutLength: result.stdout?.length ?? 0,
+        markerFound: false,
+        stderr: result.stderr,
+      },
+      { cause: result.error },
+    );
+  }
+}
+
+function getSystemShell(
+  deps: Required<Pick<LoginShellEnvDependencies, "env" | "platform" | "userInfo">>,
+): string {
+  const shell = deps.env.SHELL;
  if (shell) return shell;

  try {
-    const info = userInfo();
+    const info = deps.userInfo();
    if (info.shell && info.shell !== "/bin/false") return info.shell;
  } catch {}

-  return process.platform === "darwin" ? "/bin/zsh" : "/bin/bash";
+  return deps.platform === "darwin" ? "/bin/zsh" : "/bin/bash";
 }

-function resolveShellEnv(): Record<string, string> | undefined {
-  if (process.platform === "win32") return undefined;
+function resolveShellEnv(deps: Required<LoginShellEnvDependencies>): Record<string, string> {
+  if (deps.platform === "win32") {
+    throw new ShellEnvError("login shell env is not resolved on Windows", { reason: "win32" });
+  }

-  const savedRunAsNode = process.env.ELECTRON_RUN_AS_NODE;
-  const savedNoAttach = process.env.ELECTRON_NO_ATTACH_CONSOLE;
+  const savedRunAsNode = deps.env.ELECTRON_RUN_AS_NODE;
+  const savedNoAttach = deps.env.ELECTRON_NO_ATTACH_CONSOLE;

  const mark = randomUUID().replace(/-/g, "").slice(0, 12);
  const regex = new RegExp(mark + "({.*})" + mark);

-  const shell = getSystemShell();
+  const shell = getSystemShell(deps);
  const name = basename(shell);

  let command: string;
@@ -54,12 +158,19 @@ function resolveShellEnv(): Record<string, string> | undefined {
    }
  }

-  const shellEnv = { ...process.env };
+  const shellEnv = { ...deps.env };
  delete shellEnv.PASEO_NODE_ENV;
  delete shellEnv.PASEO_DESKTOP_MANAGED;
  delete shellEnv.PASEO_SUPERVISED;

-  const result = spawnSync(shell, [...shellArgs, command], {
+  deps.logger.info("[login-shell-env] start", {
+    shell,
+    shellArgs,
+    timeoutMs: RESOLVE_TIMEOUT_MS,
+    beforePath: pathEnv(deps.env),
+  });
+
+  const result = deps.spawnSync(shell, [...shellArgs, command], {
    encoding: "utf8",
    timeout: RESOLVE_TIMEOUT_MS,
    windowsHide: true,
@@ -70,11 +181,21 @@ function resolveShellEnv(): Record<string, string> | undefined {
    },
  });

-  if (result.status !== 0 && result.status !== null) return undefined;
-  if (!result.stdout) return undefined;
+  throwIfShellFailed(result, regex, shell, shellArgs);

  const match = regex.exec(result.stdout);
-  if (!match?.[1]) return undefined;
+  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,
+    });
+  }

  try {
    const env = JSON.parse(match[1]) as Record<string, string>;
@@ -94,8 +215,21 @@ function resolveShellEnv(): Record<string, string> | undefined {
    delete env.XDG_RUNTIME_DIR;

    return env;
-  } catch {
-    return undefined;
+  } catch (error) {
+    throw new ShellEnvError(
+      "failed to parse login shell environment JSON",
+      {
+        reason: "json-parse",
+        shell,
+        shellArgs,
+        status: result.status,
+        signal: result.signal,
+        stdoutLength: result.stdout.length,
+        markerFound: true,
+        stderr: result.stderr,
+      },
+      { cause: error },
+    );
  }
 }

@@ -107,13 +241,44 @@ function resolveShellEnv(): Record<string, string> | undefined {
 *
 * Approach borrowed from VS Code (src/vs/platform/shell/node/shellEnv.ts).
 */
-export function inheritLoginShellEnv(): void {
+export function inheritLoginShellEnv(input: LoginShellEnvDependencies = {}): void {
+  const deps: Required<LoginShellEnvDependencies> = {
+    env: input.env ?? process.env,
+    logger: input.logger ?? defaultLog,
+    platform: input.platform ?? process.platform,
+    spawnSync: input.spawnSync ?? defaultSpawnSync,
+    userInfo: input.userInfo ?? defaultUserInfo,
+  };
+  const beforePath = pathEnv(deps.env);
+  const startedAt = Date.now();
+
  try {
-    const env = resolveShellEnv();
-    if (env) {
-      Object.assign(process.env, env);
-    }
-  } catch {
+    const env = resolveShellEnv(deps);
+    Object.assign(deps.env, env);
+    deps.logger.info("[login-shell-env] applied", {
+      durationMs: Date.now() - startedAt,
+      beforePath,
+      afterPath: pathEnv(deps.env),
+      pathChanged: beforePath !== pathEnv(deps.env),
+      shell: deps.env.SHELL ?? null,
+    });
+  } catch (error) {
+    const details: ShellEnvErrorDetails =
+      error instanceof ShellEnvError
+        ? error.details
+        : { reason: "throw", shell: deps.env.SHELL ?? undefined };
+    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,
+      error: error instanceof Error ? error.message : String(error),
+      errorCode: (cause as NodeJS.ErrnoException | undefined)?.code ?? null,
+      stderr: truncateForLog(details.stderr),
+      beforePath,
+      afterPath: pathEnv(deps.env),
+      pathChanged: beforePath !== pathEnv(deps.env),
+    });
    // Keep inherited environment if shell lookup fails.
  }
 }