Skip to content
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
99 changes: 97 additions & 2 deletions apps/desktop/src/backend/DesktopBackendManager.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -138,6 +138,7 @@ function makeManagerLayer(input: {
Layer.succeed(DesktopStartupFailurePrompt.DesktopStartupFailurePrompt, {
handle: () => Effect.die("unexpected startup failure prompt"),
notifyDatabaseRecovery: () => Effect.void,
notifyMigrationInProgress: () => Effect.die("unexpected migration notice"),
...input.startupFailurePrompt,
}),
Layer.succeed(DesktopDatabaseRecovery.DesktopDatabaseRecovery, {
Expand Down Expand Up @@ -868,9 +869,14 @@ describe("DesktopBackendManager", () => {
return makeProcess({
// The fatal cause lands on stdout, like the server's Effect
// logger; stderr carries a secondary line. Both must reach
// the crash-report tail.
// the crash-report tail. The migration that ran here already
// reported finishing, so it must not buy this run more time.
stdout: Stream.make(
new TextEncoder().encode("[FATAL] EADDRINUSE: port already bound\n"),
new TextEncoder().encode(
"[00:00:01.100] INFO (#42): Running migration 50_ProjectionTranscriptEventSequence (50 of 51)\n" +
"[00:00:09.244] INFO (#42): Finished migration 50_ProjectionTranscriptEventSequence in 8s 144ms\n" +
"[FATAL] EADDRINUSE: port already bound\n",
),
),
stderr: Stream.make(new TextEncoder().encode("node exited\n")),
exitCode: Deferred.await(closed).pipe(Effect.as(ChildProcessSpawner.ExitCode(143))),
Expand Down Expand Up @@ -910,6 +916,95 @@ describe("DesktopBackendManager", () => {
}),
);

it.effect(
"keeps waiting and shows the migration notice when the backend is mid-migration at the readiness deadline",
() =>
Effect.gen(function* () {
const noticeInfo = yield* Queue.unbounded<{
readonly migrationId: number;
readonly totalMigrations: number;
}>();
const noticeClosed = yield* Deferred.make<void>();
const windowOpened = yield* Deferred.make<void>();
const answersReadiness = yield* Ref.make(false);
const terminations = yield* Ref.make(0);

const spawnerLayer = Layer.succeed(
ChildProcessSpawner.ChildProcessSpawner,
ChildProcessSpawner.make(() =>
Effect.gen(function* () {
const scope = yield* Scope.Scope;
const closed = yield* Deferred.make<void>();
const close = Ref.update(terminations, (count) => count + 1).pipe(
Effect.andThen(Deferred.succeed(closed, void 0)),
Effect.asVoid,
);
yield* Scope.addFinalizer(scope, close);
return makeProcess({
stdout: Stream.make(
new TextEncoder().encode(
"[00:00:01.000] INFO (#42): Running all migrations...\n",
),
new TextEncoder().encode(
"[00:00:01.100] INFO (#42): Running migration 50_ProjectionTranscriptEventSequence (50 of 51)\n",
),
),
exitCode: Deferred.await(closed).pipe(Effect.as(ChildProcessSpawner.ExitCode(0))),
kill: () => close,
});
}),
),
);

const managerLayer = makeManagerLayer({
spawnerLayer,
httpClientLayer: httpClientLayer((request) =>
Effect.flatMap(Ref.get(answersReadiness), (ready) =>
ready ? Effect.succeed(responseForRequest(request, 200)) : Effect.never,
),
),
startupFailurePrompt: {
notifyMigrationInProgress: (info) =>
Queue.offer(noticeInfo, info).pipe(
Effect.andThen(
Effect.never.pipe(
Effect.onInterrupt(() =>
Deferred.succeed(noticeClosed, void 0).pipe(Effect.asVoid),
),
),
),
),
},
desktopWindow: {
handleBackendReady: Deferred.succeed(windowOpened, void 0).pipe(Effect.asVoid),
},
});

yield* Effect.gen(function* () {
const manager = yield* DesktopBackendManager.DesktopBackendManager;
yield* manager.start;

// The 60s budget elapses while migration 50 of 51 is still running.
// The backend is busy, not hung, so it must survive the deadline.
yield* TestClock.adjust(Duration.minutes(1));
assert.deepEqual(yield* Queue.take(noticeInfo), {
migrationId: 50,
totalMigrations: 51,
});
assert.equal(yield* Ref.get(terminations), 0);

// Once the migration finishes the backend answers, and the notice
// closes itself instead of outliving the wait.
yield* Ref.set(answersReadiness, true);
yield* TestClock.adjust(Duration.seconds(2));
yield* Deferred.await(windowOpened);
yield* Deferred.await(noticeClosed);
assert.equal(yield* Ref.get(terminations), 0);
assert.isTrue((yield* manager.snapshot).ready);
}).pipe(Effect.provide(Layer.merge(TestClock.layer(), managerLayer)));
}),
);

it.effect("keeps restarting without a prompt once the backend has been ready", () =>
Effect.gen(function* () {
const starts = yield* Queue.unbounded<number>();
Expand Down
128 changes: 112 additions & 16 deletions apps/desktop/src/backend/DesktopBackendManager.ts
Original file line number Diff line number Diff line change
Expand Up @@ -23,6 +23,8 @@ import { hideWindowsConsole } from "@threadlines/shared/childProcess";
import {
DESKTOP_LAUNCH_ID_HEADER,
DesktopBackendBootstrap,
MIGRATION_FINISHED_LOG_PREFIX,
MIGRATION_RUNNING_LOG_PREFIX,
type DesktopBackendBootstrap as DesktopBackendBootstrapValue,
} from "@threadlines/contracts";

Expand Down Expand Up @@ -104,17 +106,61 @@ class BackendProcessSpawnError extends Data.TaggedError("BackendProcessSpawnErro

type BackendProcessError = BackendProcessBootstrapEncodeError | BackendProcessSpawnError;

/**
* What to do when the readiness deadline passes: give up on this run, or drop
* the deadline and keep probing until the backend answers or the process dies.
*/
export type BackendReadinessTimeoutDecision = "give-up" | "keep-waiting";

interface RunBackendProcessOptions extends DesktopBackendStartConfig {
readonly readinessTimeout?: Duration.Duration;
readonly onStarted?: (pid: number) => Effect.Effect<void>;
readonly onReady?: () => Effect.Effect<void>;
readonly onReadinessFailure?: (error: BackendTimeoutError) => Effect.Effect<void>;
readonly onReadinessTimeout?: (
error: BackendTimeoutError,
) => Effect.Effect<BackendReadinessTimeoutDecision>;
readonly onOutput?: (
streamName: BackendProcessOutputStream,
chunk: Uint8Array,
) => Effect.Effect<void>;
}

export interface BackendMigrationInProgress {
readonly id: number;
readonly name: string;
readonly total: number;
}

const MIGRATION_RUNNING_PATTERN = new RegExp(
`${MIGRATION_RUNNING_LOG_PREFIX}(\\d+)_(\\S+) \\((?:\\d+) of (\\d+)\\)`,
);

/**
* Reads the backend's captured output for a migration that started and has not
* reported finishing. The SQLite driver is synchronous, so nothing else is
* logged while a long statement runs: the last unfinished "Running migration"
* line is the whole story. Lines carry the server's pretty-logger prefix, so
* the match is anywhere in the line.
*/
export function findMigrationInProgress(
outputTail: string,
): Option.Option<BackendMigrationInProgress> {
const lines = DesktopStartupFailurePrompt.stripAnsiEscapes(outputTail).split(/\r?\n/);
for (let index = lines.length - 1; index >= 0; index -= 1) {
const match = lines[index]?.match(MIGRATION_RUNNING_PATTERN);
const id = match?.[1];
const name = match?.[2];
const total = match?.[3];
if (id === undefined || name === undefined || total === undefined) {
continue;
}
const finishedMarker = `${MIGRATION_FINISHED_LOG_PREFIX}${id}_${name}`;
const finished = lines.slice(index + 1).some((line) => line.includes(finishedMarker));
return finished ? Option.none() : Option.some({ id: Number(id), name, total: Number(total) });
}
return Option.none();
}

export interface DesktopBackendSnapshot {
readonly desiredRunning: boolean;
readonly ready: boolean;
Expand All @@ -135,8 +181,11 @@ export class DesktopBackendManager extends Context.Service<
DesktopBackendManagerShape
>()("threadlines/desktop/BackendManager") {}

const { logWarning: logBackendManagerWarning, logError: logBackendManagerError } =
DesktopObservability.makeComponentLogger("desktop-backend-manager");
const {
logInfo: logBackendManagerInfo,
logWarning: logBackendManagerWarning,
logError: logBackendManagerError,
} = DesktopObservability.makeComponentLogger("desktop-backend-manager");

interface ActiveBackendRun {
readonly id: number;
Expand Down Expand Up @@ -328,13 +377,22 @@ const runBackendProcess = Effect.fn("runBackendProcess")(function* (
yield* drainBackendOutput("stderr", handle.stderr, onOutput).pipe(Effect.forkScoped),
);
}
yield* waitForHttpReady(
options.httpBaseUrl,
options.readinessTimeout ?? DEFAULT_BACKEND_READINESS_TIMEOUT,
options.bootstrap.desktopLaunchId,
).pipe(
Effect.tap(() => options.onReady?.() ?? Effect.void),
Effect.catch((error) => options.onReadinessFailure?.(error) ?? Effect.void),
const awaitReady = (timeout: Duration.Duration) =>
waitForHttpReady(options.httpBaseUrl, timeout, options.bootstrap.desktopLaunchId).pipe(
Effect.tap(() => options.onReady?.() ?? Effect.void),
);
yield* awaitReady(options.readinessTimeout ?? DEFAULT_BACKEND_READINESS_TIMEOUT).pipe(
Effect.catch((error) =>
(options.onReadinessTimeout?.(error) ?? Effect.succeed("give-up" as const)).pipe(
// "keep-waiting" drops the deadline rather than the probe: if the
// process dies meanwhile, the exit path below ends the run anyway.
Effect.flatMap((decision) =>
decision === "keep-waiting"
? awaitReady(Duration.infinity).pipe(Effect.ignore)
: Effect.void,
),
),
),
Effect.forkScoped,
);

Expand Down Expand Up @@ -500,6 +558,20 @@ const makeDesktopBackendManager = Effect.fn("makeDesktopBackendManager")(functio
const stdoutDecoder = new TextDecoder();
const stderrDecoder = new TextDecoder();
const readinessTimeoutRef = yield* Ref.make(Option.none<BackendTimeoutError>());
// The "still migrating" dialog belongs to this run: readiness and the
// run ending both close it.
const migrationNoticeRef = yield* Ref.make(Option.none<Fiber.Fiber<void, never>>());
const closeMigrationNotice = Ref.getAndSet(
migrationNoticeRef,
Option.none<Fiber.Fiber<void, never>>(),
).pipe(
Effect.flatMap(
Option.match({
onNone: () => Effect.void,
onSome: (fiber) => Fiber.interrupt(fiber).pipe(Effect.asVoid),
}),
),
);
const runIdOption = yield* Ref.modify(state, (latest) =>
latest.intentGeneration === startIntentGeneration && latest.desiredRunning
? ([
Expand Down Expand Up @@ -528,6 +600,7 @@ const makeDesktopBackendManager = Effect.fn("makeDesktopBackendManager")(functio
exitCode: Option.Option<number>,
flushOutput: Effect.Effect<void>,
) {
yield* closeMigrationNotice;
const restartAfterRecovery = yield* mutex.withPermits(1)(
Effect.gen(function* () {
const { isCurrentRun, nextState, pid } = yield* Ref.modify(
Expand Down Expand Up @@ -735,6 +808,7 @@ const makeDesktopBackendManager = Effect.fn("makeDesktopBackendManager")(functio
return;
}

yield* closeMigrationNotice;
yield* Ref.set(desktopState.backendReady, true);
yield* desktopWindow.handleBackendReady.pipe(
Effect.catch((error) =>
Expand All @@ -754,24 +828,46 @@ const makeDesktopBackendManager = Effect.fn("makeDesktopBackendManager")(functio
);
}
}),
onReadinessFailure: (error) =>
// Three ways the deadline can pass, and only one of them is a
// failure. Once a window exists, an unresponsive restart is visible
// and recoverable, so keep probing quietly. Before the first window
// a migration still running is healthy work that a kill would only
// make restart from zero, so keep probing and say so. Anything else
// is a process that is alive but unresponsive and would sit
// invisible forever: mark the run and kill it so finalizeRun
// surfaces the failure instead of scheduling a restart.
onReadinessTimeout: (error) =>
Effect.gen(function* () {
yield* logBackendManagerWarning("backend readiness check failed during bootstrap", {
error: error.message,
});
const latest = yield* Ref.get(state);
if (latest.everReady) {
return;
return "keep-waiting" as const;
}
const migration = findMigrationInProgress(yield* Ref.get(outputTailRef));
if (Option.isSome(migration)) {
yield* logBackendManagerInfo("backend still migrating at readiness deadline", {
migrationId: migration.value.id,
migrationName: migration.value.name,
totalMigrations: migration.value.total,
});
const noticeFiber = yield* Effect.forkIn(
startupFailurePrompt.notifyMigrationInProgress({
migrationId: migration.value.id,
totalMigrations: migration.value.total,
}),
parentScope,
);
yield* Ref.set(migrationNoticeRef, Option.some(noticeFiber));
return "keep-waiting" as const;
}
// Before the first readiness there is no window: a process that
// is alive but unresponsive would sit invisible forever. Mark
// the run and kill it so finalizeRun surfaces the failure
// instead of scheduling a restart.
yield* Ref.set(readinessTimeoutRef, Option.some(error));
const run = Option.getOrUndefined(latest.active);
if (run?.id === runId) {
yield* Effect.forkIn(closeRun(run), parentScope);
}
return "give-up" as const;
}),
onOutput: (streamName, chunk) =>
backendOutputLog.writeOutputChunk(streamName, chunk).pipe(
Expand Down
5 changes: 4 additions & 1 deletion apps/desktop/src/electron/ElectronDialog.ts
Original file line number Diff line number Diff line change
Expand Up @@ -74,7 +74,10 @@ const make = ElectronDialog.of({
});
return result.response === CONFIRM_BUTTON_INDEX;
}),
showMessageBox: (options) => Effect.promise(() => Electron.dialog.showMessageBox(options)),
// Interrupting the fiber aborts the signal, which closes the box as if the
// user had cancelled it, so a dialog never outlives the work that showed it.
showMessageBox: (options) =>
Effect.promise((signal) => Electron.dialog.showMessageBox({ ...options, signal })),
showErrorBox: (title, content) =>
Effect.sync(() => {
Electron.dialog.showErrorBox(title, content);
Expand Down
Loading
Loading