diff --git a/.changeset/fn-7688-login-shell-profile-latency.md b/.changeset/fn-7688-login-shell-profile-latency.md new file mode 100644 index 0000000000..10151c54a2 --- /dev/null +++ b/.changeset/fn-7688-login-shell-profile-latency.md @@ -0,0 +1,7 @@ +--- +"@runfusion/fusion": patch +--- + +summary: Add a one-time server log hint pointing to shell-profile-hygiene docs when a login shell is slow to prompt. +category: performance +dev: FN-7688 investigated whether `--login` in `TerminalService.detectShell()`/`createSession()` is a meaningful first-prompt latency contributor. Finding: negligible on lean profiles, additive (~800ms+) when `.zprofile`/`.bash_profile` eagerly sources something slow (e.g. version manager init). `--login` is preserved unconditionally per FN-7686; added `SLOW_LOGIN_PROFILE_HINT_MS` (2000ms) threshold and a one-time, non-blocking `console.info` hint in `createSession()`'s PTY `onData` handler — never alters spawn args, timeouts, or the `retry-without-login` fallback. See `docs/solutions/developer-experience/login-shell-profile-latency.md`. diff --git a/docs/dashboard-guide.md b/docs/dashboard-guide.md index 259511d428..00607d3288 100644 --- a/docs/dashboard-guide.md +++ b/docs/dashboard-guide.md @@ -659,6 +659,23 @@ Features: ![Interactive terminal](./screenshots/terminal.png) +### Slow first prompt / shell profile hygiene + +Fusion's embedded terminal spawns your shell as a **login shell** (`bash --login` / `zsh --login`) so `.bash_profile`/`.zprofile` (and, for interactive zsh, `.zlogin`) are sourced exactly as they would be in a real terminal. This is deliberate: dropping the login flag would silently break PATH entries, secrets, and tool init that many profiles rely on, so Fusion always tries `--login` first (falling back only if that specific spawn attempt fails, never as a latency optimization). + +If the terminal view appears almost instantly but stays blank for several seconds before the first prompt/output shows up, this is very rarely `--login` itself — measurements show the flag typically costs only single-digit milliseconds on a lean profile. The far more common cause is your own `.zprofile`/`.bash_profile` (or `.zshrc`/`.bashrc`, which a login shell also sources) eagerly running something slow, most often a version manager init script (`nvm.sh`, `rbenv init`, `pyenv init`, `direnv hook`, etc.). Because a **login** shell sources `.zprofile`/`.zlogin` in addition to `.zshrc` (a non-login shell skips them), anything slow specifically in `.zprofile`/`.bash_profile`/`.zlogin` is fully additive latency that only a login shell pays. + +To trim a slow first prompt: + +1. Move slow, one-time setup (build tool version managers, background daemons, etc.) out of `.zprofile`/`.bash_profile` and into `.zshrc`/`.bashrc`, or gate it behind an interactive-only check if it should not run for every login shell. +2. Prefer lazy-loading over eager-sourcing for version managers — most (nvm, pyenv, rbenv) document a lazy-init pattern that defers the expensive part until the tool is first invoked. +3. Time your own profile to confirm the source of the delay: `time zsh -i -c exit` (interactive, non-login) vs. `time zsh -li -c exit` (interactive, login) isolates whether `.zprofile`/`.zlogin` specifically is the slow part. +4. If Fusion's server log shows a one-time `login shell took ms to produce first output` hint for a session, it is pointing at this same profile-hygiene question — it is informational only and never blocks or retries the session. + +See `docs/solutions/developer-experience/login-shell-profile-latency.md` for the underlying measurement and the decision to keep `--login` unconditionally. + +## Git Manager + ## Git Manager Git Manager centralizes repo operations in the dashboard. On desktop/tablet it is available as an embedded right-dock panel and can expand into a resizable modal; on mobile it opens from the compact More surfaces. diff --git a/docs/solutions/developer-experience/login-shell-profile-latency.md b/docs/solutions/developer-experience/login-shell-profile-latency.md new file mode 100644 index 0000000000..18a290f47c --- /dev/null +++ b/docs/solutions/developer-experience/login-shell-profile-latency.md @@ -0,0 +1,79 @@ +--- +title: "Login-shell --login first-prompt latency: measurement and decision" +date: 2026-07-08 +category: developer-experience +module: packages/dashboard/src/terminal-service.ts +problem_type: performance_investigation +component: embedded_terminal +applies_when: "Investigating why the embedded terminal's first prompt/output is slow to appear, specifically whether the `--login` shell flag in detectShell()/createSession() is the cause." +symptoms: + - "Terminal view renders immediately but shows no output for multiple seconds" + - "Suspicion that bash/zsh --login profile sourcing is the bottleneck" +root_cause: user_profile_content_not_the_login_flag +resolution_type: documented_finding_plus_additive_diagnostic +severity: low +related_components: + - packages/dashboard/src/terminal-service.ts + - packages/dashboard/src/__tests__/terminal-service.test.ts +tags: [terminal, login-shell, shell-profile, latency, pty, fn-7686, fn-7688] +--- + +# Login-shell `--login` first-prompt latency: measurement and decision + +## Problem + +FN-7686 (slow initial terminal load) flagged `detectShell()`'s use of `--login` for bash/zsh as a +*possible but unconfirmed, environment-dependent* contributor to first-prompt latency, and deferred +root-causing it. FN-7688 investigated this in isolation. + +## Investigation + +An ad hoc timed PTY harness (same `@homebridge/node-pty-prebuilt-multiarch` binding the dashboard +bundles) measured wall-clock time from `pty.spawn()` to first readable output byte, for +`bash`/`zsh` with and without `--login`, on (a) a typical/lean real developer profile and (b) a +synthetic heavy profile (`ZDOTDIR` pointed at a temp dir whose `.zprofile`/`.zshrc` each `sleep 0.8`). + +Raw numbers and method are recorded in the FN-7688 task's `repro` document; summary: + +- **Typical/lean profile:** `--login` vs. non-login delta is single-digit milliseconds for both + bash and zsh — noise-level, not perceptible. +- **Heavy profile (simulated slow version-manager init):** `--login` costs an additional + ~815-820ms over non-login, because a login *interactive* zsh sources `.zshenv` → `.zprofile` → + `.zshrc` → `.zlogin`, while a non-login interactive zsh sources only `.zshenv` → `.zshrc`. Any + slow command placed in `.zprofile`/`.zlogin` (not `.zshrc`) is entirely additive cost that only + exists because of `--login`. + +## Root cause + +`--login` itself is not a meaningful latency contributor on a typical/lean shell profile. It **is** +a meaningful, user-environment-dependent contributor when the user's own `.zprofile`/`.bash_profile` +eagerly sources something slow (most commonly a version manager init script: nvm/rbenv/pyenv/direnv). +The mechanism is structural — a login shell sources strictly more profile files than a non-login +shell — not a defect in `detectShell()`/`createSession()`. + +## Decision + +`--login` is preserved unconditionally (per FN-7686's hard constraint): dropping it would silently +break `.zprofile`-managed PATH/env/secrets for any user relying on login-shell semantics. That +tradeoff is correct — the fix belongs in shell-profile hygiene, not in Fusion's spawn logic. + +**Delivered mitigation (additive only, no spawn-path change):** + +1. Operator-facing troubleshooting guidance in `docs/dashboard-guide.md` → "Slow first prompt / + shell profile hygiene", explaining the login-vs-non-login profile-sourcing difference and + concrete steps to trim/lazy-load slow `.zprofile`/`.bash_profile` content. +2. A one-time, non-blocking, server-log-only diagnostic in `terminal-service.ts`: if a login-shell + session's first PTY output takes ≥ `SLOW_LOGIN_PROFILE_HINT_MS` (2000ms) to appear, a + `console.info` hint is logged once per session, pointing at the docs section above. This never + alters spawn args, timeouts, the readiness contract (`READY_QUIET_WINDOW_MS`/`READY_TIMEOUT_MS`), + or the `retry-without-login` fallback — it is purely informational and additive. + +## Verification + +- `detectShell()` still returns `["--login"]` for bash/zsh, `[]` for sh/powershell/pwsh/cmd + (asserted in `packages/dashboard/src/__tests__/terminal-service.test.ts`, + describe block "FN-7688: --login preservation and slow-login-profile hint"). +- `createSession()` still spawns `--login` as the primary attempt with the `retry-without-login` + fallback registered. +- The slow-profile hint fires exactly once, only for login-shell sessions, only when first output + is at/above the threshold, and never for non-login shells (sh) or fast sessions. diff --git a/packages/dashboard/src/__tests__/terminal-service.test.ts b/packages/dashboard/src/__tests__/terminal-service.test.ts index 7b51aa792e..519f417190 100644 --- a/packages/dashboard/src/__tests__/terminal-service.test.ts +++ b/packages/dashboard/src/__tests__/terminal-service.test.ts @@ -4,6 +4,7 @@ import * as nodePty from "node-pty"; import { READY_QUIET_WINDOW_MS, READY_TIMEOUT_MS, + SLOW_LOGIN_PROFILE_HINT_MS, TerminalService, STALE_SESSION_THRESHOLD_MS, WINDOWS_TERMINAL_EMBEDDED_STARTUP_ERROR, @@ -930,4 +931,124 @@ describe("TerminalService", () => { vi.useRealTimers(); }); }); + + // FN-7688: login-shell `--login` profile-execution latency investigation. `--login` must be + // preserved exactly (dropping it would silently break .zprofile/.bash_profile-managed env/PATH + // for users relying on login-shell semantics) — these tests lock in that invariant, and assert + // the additive slow-profile hint never alters spawn args, the readiness contract, or the + // retry-without-login fallback. + describe("FN-7688: --login preservation and slow-login-profile hint", () => { + it("detectShell() returns [\"--login\"] for bash", () => { + process.env.SHELL = "/bin/bash"; + vi.mocked(fs.existsSync).mockImplementation((candidate) => candidate === "/bin/bash"); + expect(service.detectShell()).toEqual({ shell: "/bin/bash", args: ["--login"] }); + }); + + it('detectShell() returns ["--login"] for zsh', () => { + process.env.SHELL = "/bin/zsh"; + vi.mocked(fs.existsSync).mockImplementation((candidate) => candidate === "/bin/zsh"); + expect(service.detectShell()).toEqual({ shell: "/bin/zsh", args: ["--login"] }); + }); + + it("detectShell() returns [] for sh", () => { + process.env.SHELL = "/bin/sh"; + vi.mocked(fs.existsSync).mockImplementation((candidate) => candidate === "/bin/sh"); + expect(service.detectShell()).toEqual({ shell: "/bin/sh", args: [] }); + }); + + it("detectShell() returns [] for powershell/pwsh/cmd on Windows", () => { + __setTerminalPlatformForTests("win32"); + delete process.env.SHELL; + vi.mocked(fs.existsSync).mockImplementation((candidate) => + String(candidate).toLowerCase().includes("powershell"), + ); + const winService = new TerminalService(projectRoot, 10); + expect(winService.detectShell().args).toEqual([]); + winService.cleanup(); + }); + + it("createSession spawns --login as the primary attempt and keeps the retry-without-login fallback registered", async () => { + process.env.SHELL = "/bin/bash"; + vi.mocked(fs.existsSync).mockImplementation((candidate) => candidate === "/bin/bash"); + + const result = await service.createSession(); + + expect(result.success).toBe(true); + // Primary spawn attempt must still use --login — FN-7688 does not drop or bypass it. + expect(nodePty.spawn).toHaveBeenCalledWith( + "/bin/bash", + ["--login"], + expect.objectContaining({ cwd: projectRoot }), + ); + // Only the primary attempt is actually invoked when it succeeds (mockPtyProcess never + // throws), so the retry-without-login fallback attempt is not spawned — but it must still + // be reachable: this is asserted by the spawn call above using the winning primary attempt, + // and by the pty_spawn_failed path test elsewhere in this file exercising fallback attempts. + expect(nodePty.spawn).toHaveBeenCalledTimes(1); + }); + + it("logs a one-time, non-blocking slow-login-profile hint when first output is slow, without altering spawn args or the readiness contract", async () => { + vi.useFakeTimers(); + const infoSpy = vi.spyOn(console, "info").mockImplementation(() => undefined); + process.env.SHELL = "/bin/bash"; + vi.mocked(fs.existsSync).mockImplementation((candidate) => candidate === "/bin/bash"); + + const result = await service.createSession(); + expect(result.success).toBe(true); + + // --login is still the primary spawn arg even though a slow-profile hint may follow. + expect(nodePty.spawn).toHaveBeenCalledWith( + "/bin/bash", + ["--login"], + expect.objectContaining({ cwd: projectRoot }), + ); + + vi.advanceTimersByTime(SLOW_LOGIN_PROFILE_HINT_MS + 50); + mockPtyProcess._onDataCallback?.("prompt$ "); + + const hintCalls = infoSpy.mock.calls.filter((call) => String(call[0]).includes("login shell took")); + expect(hintCalls.length).toBe(1); + + // One-time: a second output burst must not re-log the hint. + infoSpy.mockClear(); + mockPtyProcess._onDataCallback?.("more output\n"); + const secondHintCalls = infoSpy.mock.calls.filter((call) => String(call[0]).includes("login shell took")); + expect(secondHintCalls.length).toBe(0); + + vi.useRealTimers(); + }); + + it("does not log the slow-login-profile hint when first output is fast", async () => { + const infoSpy = vi.spyOn(console, "info").mockImplementation(() => undefined); + process.env.SHELL = "/bin/bash"; + vi.mocked(fs.existsSync).mockImplementation((candidate) => candidate === "/bin/bash"); + + const result = await service.createSession(); + expect(result.success).toBe(true); + + mockPtyProcess._onDataCallback?.("prompt$ "); + + const hintCalls = infoSpy.mock.calls.filter((call) => String(call[0]).includes("login shell took")); + expect(hintCalls.length).toBe(0); + }); + + it("never logs the slow-login-profile hint for a non-login shell (sh)", async () => { + vi.useFakeTimers(); + const infoSpy = vi.spyOn(console, "info").mockImplementation(() => undefined); + process.env.SHELL = "/bin/sh"; + vi.mocked(fs.existsSync).mockImplementation((candidate) => candidate === "/bin/sh"); + + const result = await service.createSession(); + expect(result.success).toBe(true); + expect(nodePty.spawn).toHaveBeenCalledWith("/bin/sh", [], expect.objectContaining({ cwd: projectRoot })); + + vi.advanceTimersByTime(SLOW_LOGIN_PROFILE_HINT_MS + 50); + mockPtyProcess._onDataCallback?.("$ "); + + const hintCalls = infoSpy.mock.calls.filter((call) => String(call[0]).includes("login shell took")); + expect(hintCalls.length).toBe(0); + + vi.useRealTimers(); + }); + }); }); diff --git a/packages/dashboard/src/terminal-service.ts b/packages/dashboard/src/terminal-service.ts index 60aaddeb96..992e1cb468 100644 --- a/packages/dashboard/src/terminal-service.ts +++ b/packages/dashboard/src/terminal-service.ts @@ -41,6 +41,16 @@ Use a short quiet window to avoid writing into an actively streaming prompt/bann export const READY_QUIET_WINDOW_MS = 150; export const READY_TIMEOUT_MS = 5_000; +/* +FNXC:Terminal 2026-07-08-11:20: +FN-7688: threshold for the one-time, non-blocking "slow shell profile" server-log hint. +Measured typical --login overhead is single-digit ms; a first-output delay at or beyond this +threshold is a signal the user's own .zprofile/.bash_profile (not the --login flag) is slow to +source (e.g. an eagerly-loaded version manager). This never blocks session creation or alters +the readiness contract — it only decides whether to log a doc pointer. +*/ +export const SLOW_LOGIN_PROFILE_HINT_MS = 2_000; + // Stale session threshold: sessions inactive for more than 5 minutes are eligible for eviction export const STALE_SESSION_THRESHOLD_MS = 300_000; // 5 minutes @@ -117,6 +127,20 @@ export interface TerminalSession { readyQuietTimeout: NodeJS.Timeout | null; /** Internal flush callback set by createSession; used by resize debounce */ _flushOutput: (() => void) | null; + /* + FNXC:Terminal 2026-07-08-11:20: + FN-7688 investigated whether login-shell `--login` profile execution (sourcing + .zprofile/.bash_profile) is a meaningful first-prompt latency contributor. Measurement + found the flag itself costs low single-digit ms on a typical/lean profile, but is fully + additive latency (confirmed ~800ms+ in a synthetic heavy-profile repro) when the user's + own .zprofile/.bash_profile eagerly sources something slow (e.g. a version manager init + script). `--login` is intentionally preserved per FN-7686 (dropping it would silently + break login-shell-managed env/PATH/secrets) — spawnStartedAt/loginProfileHintLogged exist + only to emit a one-time, non-blocking, server-log-only hint pointing operators at shell- + profile-hygiene docs; they never alter spawn args, timeouts, or the readiness contract. + */ + spawnStartedAt: number; + loginProfileHintLogged: boolean; } export interface TerminalOptions { @@ -572,14 +596,23 @@ export class TerminalService extends EventEmitter { addSpawnAttempt(allowedShell, fallbackArgs, "allowed-fallback"); } + // FNXC:Terminal 2026-07-08-11:20: captured just before the first spawn attempt so the + // FN-7688 slow-login-profile hint measures wall-clock from "we start trying to spawn a + // shell" to first PTY output, not from unrelated createSession setup work above. + const spawnStartedAt = Date.now(); let ptyProcess: IPty | undefined; let lastSpawnError: unknown; + // FNXC:Terminal 2026-07-08-11:20: tracks whether the spawn attempt that actually succeeded + // used --login, so the FN-7688 slow-profile hint only fires for login-shell sessions (it + // would be misleading to attribute a slow non-login shell's first output to profile cost). + let succeededWithLoginArgs = false; for (const attempt of spawnAttempts) { try { console.info( `[createSession] Spawning terminal via ${attempt.reason}: ${attempt.shell} ${attempt.args.join(" ")} in ${cwd}`, ); ptyProcess = pty.spawn(attempt.shell, attempt.args, ptyOptions); + succeededWithLoginArgs = attempt.args.includes("--login"); break; } catch (spawnError) { lastSpawnError = spawnError; @@ -623,6 +656,8 @@ export class TerminalService extends EventEmitter { readyTimeout: null, readyQuietTimeout: null, _flushOutput: null, + spawnStartedAt, + loginProfileHintLogged: false, }; session.readyTimeout = setTimeout(() => { @@ -676,8 +711,30 @@ export class TerminalService extends EventEmitter { // Forward data events with throttling ptyProcess.onData((data: string) => { + const wasFirstOutput = !session.firstOutputSeen; this.observeReadinessOutput(session); + /* + FNXC:Terminal 2026-07-08-11:20: + FN-7688 finding: --login itself costs low single-digit ms on a typical/lean shell + profile, but sourcing .zprofile/.bash_profile is fully additive latency when the + user's own profile is slow (e.g. eagerly-sourced version manager init). This hint is + one-time, non-blocking (server log only, never surfaced as a UI toast/error), and + never changes spawn args, timeouts, or the readiness contract — it only points + operators at shell-profile-hygiene docs when the signal warrants it. + */ + if (wasFirstOutput && succeededWithLoginArgs && !session.loginProfileHintLogged) { + const firstOutputMs = Date.now() - session.spawnStartedAt; + if (firstOutputMs >= SLOW_LOGIN_PROFILE_HINT_MS) { + session.loginProfileHintLogged = true; + console.info( + `[createSession] Session ${session.id}: login shell took ${firstOutputMs}ms to produce first output. ` + + `If this is consistently slow, your .zprofile/.bash_profile may be eagerly sourcing something slow ` + + `(e.g. a version manager init script). See docs/dashboard-guide.md "Slow first prompt / shell profile hygiene".`, + ); + } + } + // Always append to scrollback buffer so no output is lost session.scrollbackBuffer += data; if (session.scrollbackBuffer.length > MAX_SCROLLBACK_SIZE) {