From 19b9e987d91e92807fe680477689b53a40348967 Mon Sep 17 00:00:00 2001 From: "@mrubens" <2600+mrubens@users.noreply.github.com> Date: Thu, 3 Sep 2026 16:40:39 +0000 Subject: [PATCH 1/3] fix(worker): wait for preview readiness after startup --- .../__tests__/environment-commands.test.ts | 189 ++++++++++++++++++ .../setup/workspace/environment-commands.ts | 109 ++++++++++ 2 files changed, 298 insertions(+) create mode 100644 apps/worker/src/commands/setup/workspace/__tests__/environment-commands.test.ts diff --git a/apps/worker/src/commands/setup/workspace/__tests__/environment-commands.test.ts b/apps/worker/src/commands/setup/workspace/__tests__/environment-commands.test.ts new file mode 100644 index 000000000..d1c814055 --- /dev/null +++ b/apps/worker/src/commands/setup/workspace/__tests__/environment-commands.test.ts @@ -0,0 +1,189 @@ +import type { NamedPort } from '@roomote/types'; +import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest'; + +import type { EnvironmentWorkspace } from '../../../../workspace'; +import type { StartupLogger } from '../../../../logging'; +import { resolveLoopback } from '../../../../services/auth-proxy'; +import type { EnvironmentSetupStatusWriter } from '../setup-status'; +import { + executeOrganizationEnvironmentRepositoryCommands, + waitForPreviewPorts, +} from '../environment-commands'; + +const { executeEnvironmentCommandsMock } = vi.hoisted(() => ({ + executeEnvironmentCommandsMock: vi.fn(), +})); + +vi.mock('../../../../services/auth-proxy', () => ({ + resolveLoopback: vi.fn().mockResolvedValue('127.0.0.1'), +})); + +vi.mock('../shared', () => ({ + createWorkspaceManager: () => ({ + workspaceManager: { + executeEnvironmentRepositoryCommands: executeEnvironmentCommandsMock, + }, + }), +})); + +describe('waitForPreviewPorts', () => { + beforeEach(() => { + vi.mocked(resolveLoopback).mockResolvedValue('127.0.0.1'); + }); + + afterEach(() => { + vi.useRealTimers(); + vi.restoreAllMocks(); + }); + + it('warms configured initial routes and accepts non-server-error responses as ready', async () => { + const fetchSpy = vi.spyOn(globalThis, 'fetch').mockResolvedValue( + new Response(null, { + status: 404, + }), + ); + const ports: NamedPort[] = [ + { name: 'web', port: 3000, initial_path: '/auth/dev-login' }, + { name: 'docs', port: 3333 }, + ]; + + await expect(waitForPreviewPorts(ports)).resolves.toEqual([]); + expect(fetchSpy).toHaveBeenCalledTimes(2); + expect(fetchSpy).toHaveBeenCalledWith( + 'http://127.0.0.1:3000/auth/dev-login', + expect.objectContaining({ redirect: 'manual' }), + ); + expect(fetchSpy).toHaveBeenCalledWith( + 'http://127.0.0.1:3333/', + expect.objectContaining({ redirect: 'manual' }), + ); + }); + + it('reports a readiness warning when a configured preview never responds', async () => { + vi.useFakeTimers(); + vi.spyOn(globalThis, 'fetch').mockRejectedValue( + new Error('connect ECONNREFUSED'), + ); + + const readiness = waitForPreviewPorts([{ name: 'web', port: 3000 }]); + await vi.advanceTimersByTimeAsync(60_000); + + await expect(readiness).resolves.toEqual([ + { + message: + 'Preview "web" at http://127.0.0.1:3000/ did not become ready within 60 seconds after its detached startup command launched.', + }, + ]); + }); + + it('retries while a preview returns a server error', async () => { + vi.useFakeTimers(); + const fetchSpy = vi + .spyOn(globalThis, 'fetch') + .mockResolvedValueOnce(new Response(null, { status: 503 })) + .mockResolvedValueOnce(new Response(null, { status: 200 })); + + const readiness = waitForPreviewPorts([{ name: 'web', port: 3000 }]); + await vi.advanceTimersByTimeAsync(1_000); + + await expect(readiness).resolves.toEqual([]); + expect(fetchSpy).toHaveBeenCalledTimes(2); + }); + + it('formats IPv6 loopback URLs correctly', async () => { + vi.mocked(resolveLoopback).mockResolvedValue('[::1]'); + const fetchSpy = vi + .spyOn(globalThis, 'fetch') + .mockResolvedValue(new Response(null, { status: 302 })); + + await expect( + waitForPreviewPorts([{ name: 'web', port: 3000 }]), + ).resolves.toEqual([]); + expect(fetchSpy).toHaveBeenCalledWith( + 'http://[::1]:3000/', + expect.objectContaining({ redirect: 'manual' }), + ); + }); +}); + +describe('executeOrganizationEnvironmentRepositoryCommands', () => { + afterEach(() => { + vi.useRealTimers(); + vi.restoreAllMocks(); + executeEnvironmentCommandsMock.mockReset(); + }); + + it('finalizes timed-out detached previews with a readiness warning', async () => { + vi.useFakeTimers(); + vi.spyOn(globalThis, 'fetch').mockRejectedValue( + new Error('connect ECONNREFUSED'), + ); + executeEnvironmentCommandsMock.mockImplementation( + async (...args: unknown[]) => { + const options = args[3] as { + onCommandResult?: (event: { + repository: string; + result: { + command: { + name: string; + run: string; + timeout: number; + continue_on_error: boolean; + detached: boolean; + }; + success: boolean; + duration: number; + }; + }) => void; + }; + options.onCommandResult?.({ + repository: 'owner/repo', + result: { + command: { + name: 'Start app', + run: 'pnpm dev', + timeout: 600, + continue_on_error: false, + detached: true, + }, + success: true, + duration: 2_000, + }, + }); + }, + ); + const setupStatusWriter = { + markCommandResult: vi.fn(), + finalize: vi.fn(), + } as unknown as EnvironmentSetupStatusWriter; + const logger = { + userLog: { log: vi.fn(), warn: vi.fn() }, + debug: { warn: vi.fn() }, + } as unknown as StartupLogger; + const environment = { + environmentConfig: { + repositories: [{ repository: 'owner/repo', commands: [] }], + ports: [{ name: 'web', port: 3000 }], + }, + } as unknown as EnvironmentWorkspace; + + const execution = executeOrganizationEnvironmentRepositoryCommands(logger, { + environment, + envVars: {}, + preparedWorkspace: { + workspacePath: '/tmp', + environment: { repoPaths: { 'owner/repo': '/tmp' } }, + }, + setupStatusWriter, + }); + await vi.advanceTimersByTimeAsync(60_000); + const expectedWarning = + 'Preview "web" at http://127.0.0.1:3000/ did not become ready within 60 seconds after its detached startup command launched.'; + + await expect(execution).resolves.toEqual([{ message: expectedWarning }]); + expect(setupStatusWriter.finalize).toHaveBeenCalledWith({ + warnings: [expectedWarning], + }); + expect(logger.userLog.warn).toHaveBeenCalledWith(expectedWarning); + }); +}); diff --git a/apps/worker/src/commands/setup/workspace/environment-commands.ts b/apps/worker/src/commands/setup/workspace/environment-commands.ts index 0068b63f6..681d2b847 100644 --- a/apps/worker/src/commands/setup/workspace/environment-commands.ts +++ b/apps/worker/src/commands/setup/workspace/environment-commands.ts @@ -1,6 +1,9 @@ +import type { NamedPort } from '@roomote/types'; + import type { EnvironmentWorkspace } from '../../../workspace'; import { ExecutionError } from '../../../command-executor'; import type { StartupLogger } from '../../../logging'; +import { resolveLoopback } from '../../../services/auth-proxy'; import type { PhaseRecorder } from '../logging'; import type { EnvironmentSetupWarning, PrepareWorkspaceResult } from './types'; import type { EnvironmentSetupStatusWriter } from './setup-status'; @@ -18,6 +21,92 @@ interface SetupOrganizationEnvironmentOptions { recordPhase?: PhaseRecorder; } +const PREVIEW_READINESS_TIMEOUT_MS = 60_000; +const PREVIEW_READINESS_POLL_INTERVAL_MS = 1_000; +const PREVIEW_READINESS_PROBE_TIMEOUT_MS = 5_000; + +function previewUrl(port: NamedPort, host = '127.0.0.1'): string { + return new URL( + port.initial_path ?? '/', + `http://${host}:${port.port}`, + ).toString(); +} + +async function probePreview( + port: NamedPort, + deadline: number, +): Promise { + const loopbackTimeoutMs = deadline - Date.now(); + if (loopbackTimeoutMs <= 0) { + return false; + } + + let loopbackTimeout: ReturnType | undefined; + + try { + const host = await Promise.race([ + resolveLoopback(port.port), + new Promise((_, reject) => { + loopbackTimeout = setTimeout( + () => reject(new Error('Loopback resolution timed out')), + loopbackTimeoutMs, + ); + }), + ]); + const remainingMs = deadline - Date.now(); + if (remainingMs <= 0) { + return false; + } + + const url = previewUrl(port, host); + const response = await fetch(url, { + redirect: 'manual', + signal: AbortSignal.timeout( + Math.min(PREVIEW_READINESS_PROBE_TIMEOUT_MS, remainingMs), + ), + }); + await response.body?.cancel().catch(() => {}); + return response.status < 500; + } catch { + return false; + } finally { + clearTimeout(loopbackTimeout); + } +} + +export async function waitForPreviewPorts( + ports: NamedPort[], +): Promise { + return ( + await Promise.all( + ports.map(async (port) => { + const url = previewUrl(port); + const deadline = Date.now() + PREVIEW_READINESS_TIMEOUT_MS; + + while (Date.now() < deadline) { + if (await probePreview(port, deadline)) { + return undefined; + } + + const remainingMs = deadline - Date.now(); + if (remainingMs > 0) { + await new Promise((resolve) => + setTimeout( + resolve, + Math.min(PREVIEW_READINESS_POLL_INTERVAL_MS, remainingMs), + ), + ); + } + } + + return { + message: `Preview "${port.name}" at ${url} did not become ready within ${PREVIEW_READINESS_TIMEOUT_MS / 1_000} seconds after its detached startup command launched.`, + }; + }), + ) + ).filter((warning) => warning !== undefined); +} + function getEnvironmentRepoPaths( preparedWorkspace?: PrepareWorkspaceResult, ): Record | undefined { @@ -76,6 +165,7 @@ export async function executeOrganizationEnvironmentRepositoryCommands( ): Promise { const repoPaths = getEnvironmentRepoPaths(preparedWorkspace); const warnings: EnvironmentSetupWarning[] = []; + let startedDetachedCommand = false; if (!repoPaths) { // Nothing to execute, but the status file must still reach a terminal @@ -99,6 +189,10 @@ export async function executeOrganizationEnvironmentRepositoryCommands( onCommandResult: ({ repository, result }) => { setupStatusWriter?.markCommandResult(repository, result); + if (result.success && result.command.detached) { + startedDetachedCommand = true; + } + if (recordPhase) { const endedAtMs = Date.now(); @@ -135,6 +229,21 @@ export async function executeOrganizationEnvironmentRepositoryCommands( }, }, ); + + if (startedDetachedCommand) { + if ((environment.environmentConfig.ports?.length ?? 0) > 0) { + logger.userLog.log('Waiting for configured previews to become ready'); + } + + const previewWarnings = await waitForPreviewPorts( + environment.environmentConfig.ports ?? [], + ); + warnings.push(...previewWarnings); + + for (const warning of previewWarnings) { + logger.userLog.warn(warning.message); + } + } } catch (error) { setupStatusWriter?.finalize({ warnings: warnings.map((warning) => warning.message), From e492b1725cce2718be7ec20869587c68178f29a5 Mon Sep 17 00:00:00 2001 From: "@mrubens" <2600+mrubens@users.noreply.github.com> Date: Thu, 3 Sep 2026 17:00:31 +0000 Subject: [PATCH 2/3] fix: address preview readiness review feedback --- .../__tests__/environment-commands.test.ts | 20 +++++++++++++++++++ .../setup/workspace/environment-commands.ts | 12 +++++++---- packages/db/vitest.config.ts | 2 ++ 3 files changed, 30 insertions(+), 4 deletions(-) diff --git a/apps/worker/src/commands/setup/workspace/__tests__/environment-commands.test.ts b/apps/worker/src/commands/setup/workspace/__tests__/environment-commands.test.ts index d1c814055..88a63a7ef 100644 --- a/apps/worker/src/commands/setup/workspace/__tests__/environment-commands.test.ts +++ b/apps/worker/src/commands/setup/workspace/__tests__/environment-commands.test.ts @@ -104,6 +104,26 @@ describe('waitForPreviewPorts', () => { expect.objectContaining({ redirect: 'manual' }), ); }); + + it('keeps network-path initial routes on the loopback authority', async () => { + const fetchSpy = vi + .spyOn(globalThis, 'fetch') + .mockResolvedValue(new Response(null, { status: 200 })); + + await expect( + waitForPreviewPorts([ + { + name: 'web', + port: 3000, + initial_path: '//example.com/path?view=preview#section', + }, + ]), + ).resolves.toEqual([]); + expect(fetchSpy).toHaveBeenCalledWith( + 'http://127.0.0.1:3000//example.com/path?view=preview#section', + expect.objectContaining({ redirect: 'manual' }), + ); + }); }); describe('executeOrganizationEnvironmentRepositoryCommands', () => { diff --git a/apps/worker/src/commands/setup/workspace/environment-commands.ts b/apps/worker/src/commands/setup/workspace/environment-commands.ts index 681d2b847..d6962f731 100644 --- a/apps/worker/src/commands/setup/workspace/environment-commands.ts +++ b/apps/worker/src/commands/setup/workspace/environment-commands.ts @@ -26,10 +26,14 @@ const PREVIEW_READINESS_POLL_INTERVAL_MS = 1_000; const PREVIEW_READINESS_PROBE_TIMEOUT_MS = 5_000; function previewUrl(port: NamedPort, host = '127.0.0.1'): string { - return new URL( - port.initial_path ?? '/', - `http://${host}:${port.port}`, - ).toString(); + const url = new URL(`http://${host}:${port.port}`); + const initialPath = port.initial_path ?? '/'; + const suffixIndex = initialPath.search(/[?#]/); + + url.pathname = + suffixIndex === -1 ? initialPath : initialPath.slice(0, suffixIndex); + + return `${url.origin}${url.pathname}${suffixIndex === -1 ? '' : initialPath.slice(suffixIndex)}`; } async function probePreview( diff --git a/packages/db/vitest.config.ts b/packages/db/vitest.config.ts index fe4a1a5e7..242ed90d2 100644 --- a/packages/db/vitest.config.ts +++ b/packages/db/vitest.config.ts @@ -6,6 +6,8 @@ export default defineConfig({ watch: false, environment: 'node', globalSetup: './vitest.setup.server.ts', + // Integration files share one database and may delete each other's fixtures. + fileParallelism: false, reporters: ['dot'], }, }); From d838e9161319555e8bdda287cc4295a52175792c Mon Sep 17 00:00:00 2001 From: "@mrubens" <2600+mrubens@users.noreply.github.com> Date: Thu, 3 Sep 2026 17:26:52 +0000 Subject: [PATCH 3/3] fix(worker): align preview readiness with task limits --- .../__tests__/environment-commands.test.ts | 89 +++++++++++++++---- .../setup/workspace/environment-commands.ts | 78 +++++++++++++--- 2 files changed, 138 insertions(+), 29 deletions(-) diff --git a/apps/worker/src/commands/setup/workspace/__tests__/environment-commands.test.ts b/apps/worker/src/commands/setup/workspace/__tests__/environment-commands.test.ts index 88a63a7ef..c33f13eee 100644 --- a/apps/worker/src/commands/setup/workspace/__tests__/environment-commands.test.ts +++ b/apps/worker/src/commands/setup/workspace/__tests__/environment-commands.test.ts @@ -1,4 +1,4 @@ -import type { NamedPort } from '@roomote/types'; +import { TASK_TIMEOUT_MS, type NamedPort } from '@roomote/types'; import { afterEach, beforeEach, describe, expect, it, vi } from 'vitest'; import type { EnvironmentWorkspace } from '../../../../workspace'; @@ -7,6 +7,7 @@ import { resolveLoopback } from '../../../../services/auth-proxy'; import type { EnvironmentSetupStatusWriter } from '../setup-status'; import { executeOrganizationEnvironmentRepositoryCommands, + getPreviewReadinessTimeoutMs, waitForPreviewPorts, } from '../environment-commands'; @@ -47,7 +48,9 @@ describe('waitForPreviewPorts', () => { { name: 'docs', port: 3333 }, ]; - await expect(waitForPreviewPorts(ports)).resolves.toEqual([]); + await expect( + waitForPreviewPorts(ports, { timeoutMs: 60_000 }), + ).resolves.toEqual([]); expect(fetchSpy).toHaveBeenCalledTimes(2); expect(fetchSpy).toHaveBeenCalledWith( 'http://127.0.0.1:3000/auth/dev-login', @@ -65,13 +68,15 @@ describe('waitForPreviewPorts', () => { new Error('connect ECONNREFUSED'), ); - const readiness = waitForPreviewPorts([{ name: 'web', port: 3000 }]); + const readiness = waitForPreviewPorts([{ name: 'web', port: 3000 }], { + timeoutMs: 60_000, + }); await vi.advanceTimersByTimeAsync(60_000); await expect(readiness).resolves.toEqual([ { message: - 'Preview "web" at http://127.0.0.1:3000/ did not become ready within 60 seconds after its detached startup command launched.', + 'Preview "web" at http://127.0.0.1:3000/ did not become ready within 60 seconds after its detached startup command launched. Last probe: connect ECONNREFUSED. Inspect the detached command logs listed in .roomote/setup-status.json.', }, ]); }); @@ -83,13 +88,34 @@ describe('waitForPreviewPorts', () => { .mockResolvedValueOnce(new Response(null, { status: 503 })) .mockResolvedValueOnce(new Response(null, { status: 200 })); - const readiness = waitForPreviewPorts([{ name: 'web', port: 3000 }]); + const readiness = waitForPreviewPorts([{ name: 'web', port: 3000 }], { + timeoutMs: 60_000, + }); await vi.advanceTimersByTimeAsync(1_000); await expect(readiness).resolves.toEqual([]); expect(fetchSpy).toHaveBeenCalledTimes(2); }); + it('allows a preview to become ready after the old one-minute cutoff', async () => { + vi.useFakeTimers(); + const readyAt = Date.now() + 90_000; + vi.spyOn(globalThis, 'fetch').mockImplementation(async () => { + if (Date.now() < readyAt) { + throw new Error('connect ECONNREFUSED'); + } + + return new Response(null, { status: 200 }); + }); + + const readiness = waitForPreviewPorts([{ name: 'web', port: 3000 }], { + timeoutMs: 10 * 60_000, + }); + await vi.advanceTimersByTimeAsync(90_000); + + await expect(readiness).resolves.toEqual([]); + }); + it('formats IPv6 loopback URLs correctly', async () => { vi.mocked(resolveLoopback).mockResolvedValue('[::1]'); const fetchSpy = vi @@ -97,7 +123,9 @@ describe('waitForPreviewPorts', () => { .mockResolvedValue(new Response(null, { status: 302 })); await expect( - waitForPreviewPorts([{ name: 'web', port: 3000 }]), + waitForPreviewPorts([{ name: 'web', port: 3000 }], { + timeoutMs: 60_000, + }), ).resolves.toEqual([]); expect(fetchSpy).toHaveBeenCalledWith( 'http://[::1]:3000/', @@ -111,19 +139,50 @@ describe('waitForPreviewPorts', () => { .mockResolvedValue(new Response(null, { status: 200 })); await expect( - waitForPreviewPorts([ - { - name: 'web', - port: 3000, - initial_path: '//example.com/path?view=preview#section', - }, - ]), + waitForPreviewPorts( + [ + { + name: 'web', + port: 3000, + initial_path: '//example.com/path?view=preview#section', + }, + ], + { timeoutMs: 60_000 }, + ), ).resolves.toEqual([]); expect(fetchSpy).toHaveBeenCalledWith( 'http://127.0.0.1:3000//example.com/path?view=preview#section', expect.objectContaining({ redirect: 'manual' }), ); }); + + it('reports diagnostics while a slow preview remains unavailable', async () => { + vi.useFakeTimers(); + vi.spyOn(globalThis, 'fetch').mockRejectedValue( + new Error('connect ECONNREFUSED'), + ); + const onProgress = vi.fn(); + + const readiness = waitForPreviewPorts([{ name: 'web', port: 3000 }], { + timeoutMs: 61_000, + onProgress, + }); + await vi.advanceTimersByTimeAsync(61_000); + await readiness; + + expect(onProgress).toHaveBeenCalledWith({ + port: { name: 'web', port: 3000 }, + elapsedMs: 60_000, + diagnostic: 'connect ECONNREFUSED', + }); + }); +}); + +describe('getPreviewReadinessTimeoutMs', () => { + it('uses the command timeout up to the task lifecycle limit', () => { + expect(getPreviewReadinessTimeoutMs(600)).toBe(10 * 60_000); + expect(getPreviewReadinessTimeoutMs(2 * 60 * 60)).toBe(TASK_TIMEOUT_MS); + }); }); describe('executeOrganizationEnvironmentRepositoryCommands', () => { @@ -196,9 +255,9 @@ describe('executeOrganizationEnvironmentRepositoryCommands', () => { }, setupStatusWriter, }); - await vi.advanceTimersByTimeAsync(60_000); + await vi.advanceTimersByTimeAsync(10 * 60_000); const expectedWarning = - 'Preview "web" at http://127.0.0.1:3000/ did not become ready within 60 seconds after its detached startup command launched.'; + 'Preview "web" at http://127.0.0.1:3000/ did not become ready within 600 seconds after its detached startup command launched. Last probe: connect ECONNREFUSED. Inspect the detached command logs listed in .roomote/setup-status.json.'; await expect(execution).resolves.toEqual([{ message: expectedWarning }]); expect(setupStatusWriter.finalize).toHaveBeenCalledWith({ diff --git a/apps/worker/src/commands/setup/workspace/environment-commands.ts b/apps/worker/src/commands/setup/workspace/environment-commands.ts index d6962f731..7d3a618ba 100644 --- a/apps/worker/src/commands/setup/workspace/environment-commands.ts +++ b/apps/worker/src/commands/setup/workspace/environment-commands.ts @@ -1,4 +1,4 @@ -import type { NamedPort } from '@roomote/types'; +import { TASK_TIMEOUT_MS, type NamedPort } from '@roomote/types'; import type { EnvironmentWorkspace } from '../../../workspace'; import { ExecutionError } from '../../../command-executor'; @@ -21,9 +21,24 @@ interface SetupOrganizationEnvironmentOptions { recordPhase?: PhaseRecorder; } -const PREVIEW_READINESS_TIMEOUT_MS = 60_000; const PREVIEW_READINESS_POLL_INTERVAL_MS = 1_000; const PREVIEW_READINESS_PROBE_TIMEOUT_MS = 5_000; +const PREVIEW_READINESS_PROGRESS_INTERVAL_MS = 60_000; + +interface PreviewProbeResult { + ready: boolean; + diagnostic: string; +} + +interface PreviewReadinessProgress { + port: NamedPort; + elapsedMs: number; + diagnostic: string; +} + +export function getPreviewReadinessTimeoutMs(timeoutSeconds: number): number { + return Math.min(timeoutSeconds * 1_000, TASK_TIMEOUT_MS); +} function previewUrl(port: NamedPort, host = '127.0.0.1'): string { const url = new URL(`http://${host}:${port.port}`); @@ -39,10 +54,10 @@ function previewUrl(port: NamedPort, host = '127.0.0.1'): string { async function probePreview( port: NamedPort, deadline: number, -): Promise { +): Promise { const loopbackTimeoutMs = deadline - Date.now(); if (loopbackTimeoutMs <= 0) { - return false; + return { ready: false, diagnostic: 'readiness deadline elapsed' }; } let loopbackTimeout: ReturnType | undefined; @@ -59,7 +74,7 @@ async function probePreview( ]); const remainingMs = deadline - Date.now(); if (remainingMs <= 0) { - return false; + return { ready: false, diagnostic: 'readiness deadline elapsed' }; } const url = previewUrl(port, host); @@ -70,9 +85,15 @@ async function probePreview( ), }); await response.body?.cancel().catch(() => {}); - return response.status < 500; - } catch { - return false; + return { + ready: response.status < 500, + diagnostic: `HTTP ${response.status}`, + }; + } catch (error) { + return { + ready: false, + diagnostic: error instanceof Error ? error.message : String(error), + }; } finally { clearTimeout(loopbackTimeout); } @@ -80,17 +101,35 @@ async function probePreview( export async function waitForPreviewPorts( ports: NamedPort[], + options: { + timeoutMs: number; + onProgress?: (progress: PreviewReadinessProgress) => void; + }, ): Promise { return ( await Promise.all( ports.map(async (port) => { const url = previewUrl(port); - const deadline = Date.now() + PREVIEW_READINESS_TIMEOUT_MS; + const startedAt = Date.now(); + const deadline = startedAt + options.timeoutMs; + let nextProgressAt = startedAt + PREVIEW_READINESS_PROGRESS_INTERVAL_MS; + let lastDiagnostic = 'not yet probed'; while (Date.now() < deadline) { - if (await probePreview(port, deadline)) { + const result = await probePreview(port, deadline); + if (result.ready) { return undefined; } + lastDiagnostic = result.diagnostic; + + if (options.onProgress && Date.now() >= nextProgressAt) { + options.onProgress({ + port, + elapsedMs: Date.now() - startedAt, + diagnostic: lastDiagnostic, + }); + nextProgressAt += PREVIEW_READINESS_PROGRESS_INTERVAL_MS; + } const remainingMs = deadline - Date.now(); if (remainingMs > 0) { @@ -104,7 +143,7 @@ export async function waitForPreviewPorts( } return { - message: `Preview "${port.name}" at ${url} did not become ready within ${PREVIEW_READINESS_TIMEOUT_MS / 1_000} seconds after its detached startup command launched.`, + message: `Preview "${port.name}" at ${url} did not become ready within ${options.timeoutMs / 1_000} seconds after its detached startup command launched. Last probe: ${lastDiagnostic}. Inspect the detached command logs listed in .roomote/setup-status.json.`, }; }), ) @@ -169,7 +208,7 @@ export async function executeOrganizationEnvironmentRepositoryCommands( ): Promise { const repoPaths = getEnvironmentRepoPaths(preparedWorkspace); const warnings: EnvironmentSetupWarning[] = []; - let startedDetachedCommand = false; + let previewReadinessTimeoutMs = 0; if (!repoPaths) { // Nothing to execute, but the status file must still reach a terminal @@ -194,7 +233,10 @@ export async function executeOrganizationEnvironmentRepositoryCommands( setupStatusWriter?.markCommandResult(repository, result); if (result.success && result.command.detached) { - startedDetachedCommand = true; + previewReadinessTimeoutMs = Math.max( + previewReadinessTimeoutMs, + getPreviewReadinessTimeoutMs(result.command.timeout), + ); } if (recordPhase) { @@ -234,13 +276,21 @@ export async function executeOrganizationEnvironmentRepositoryCommands( }, ); - if (startedDetachedCommand) { + if (previewReadinessTimeoutMs > 0) { if ((environment.environmentConfig.ports?.length ?? 0) > 0) { logger.userLog.log('Waiting for configured previews to become ready'); } const previewWarnings = await waitForPreviewPorts( environment.environmentConfig.ports ?? [], + { + timeoutMs: previewReadinessTimeoutMs, + onProgress: ({ port, elapsedMs, diagnostic }) => { + logger.userLog.log( + `Preview "${port.name}" is still starting after ${Math.round(elapsedMs / 1_000)} seconds. Last probe: ${diagnostic}.`, + ); + }, + }, ); warnings.push(...previewWarnings);