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
5 changes: 5 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -5,6 +5,11 @@ This file records what changes **in the product** – process and session state

## [Unreleased]

### Fixed
- `/api/health` reports the AI service as `starting` instead of `failed` when it does not answer in time –
on the showcase usually the cold start of the scaled-to-zero container; after 30 s without an answer it
reads `failed` again, so a real outage is not hidden (#81).

## [0.1.0] – 2026-09-27

First release: the pilot scope – intake of e-mail and PDF/Excel/Word, AI extraction with sources and
Expand Down
3 changes: 2 additions & 1 deletion docs/technical/api.md
Original file line number Diff line number Diff line change
Expand Up @@ -9,9 +9,10 @@
|---|---|
| 200 | `{"status":"ok","checks":{"database":"ok","storage":"ok"},"dependencies":{"aiService":"ok"},"backlog":{"request-process":0,"request-export":0}}` |
| 503 | `{"status":"degraded","checks":{"<name>":"failed", …}}` – names only, never hosts, users or error text |
| 200 | `dependencies.aiService`: `ok`, `failed` (answered with an error / refused) or `starting` (no answer within the probe's 2 s – e.g. a cold start, #81; still no answer after 30 s → `failed`, #88); informational, never changes the status |
| 503 | `{"status":"degraded","checks":{"config":"failed"}}` – invalid configuration (the server log names the variables) |

- Each check has a 3 s time limit; `cache-control: no-store`.
- Each check has a 3 s time limit (the AI service probe aborts itself after 2 s); `cache-control: no-store`.
- Cost per call: one `select 1` and one S3 `HeadBucket`; the informational parts (AI-service ping, two
backlog counts on `pgboss.job`) are cached for 10 s, so they run at most once per window. The backlog
is summed over all companies (no tenant data, but it shows overall activity to an unauthenticated
Expand Down
4 changes: 3 additions & 1 deletion docs/technical/deployment-vercel.md
Original file line number Diff line number Diff line change
Expand Up @@ -141,7 +141,9 @@ step is idempotent: repeat it whenever visitors have decided the samples, and it

## 8. Smoke check

1. `GET /api/health` → 200, `database` and `storage` `ok`, `aiService` `ok`.
1. `GET /api/health` → 200, `database` and `storage` `ok`, `aiService` `ok`. Right after a pause the first
call may read `aiService` `starting` (the container's cold start, ~6 s) – repeat after 10 s. If it keeps
timing out for more than 30 s it reads `failed`: then check the AI project and `AI_SERVICE_URL` (#81, #88).
2. Drain route: without header → 401; with the secret → 200 JSON.
3. The banner „Demo – nur synthetische Daten" is visible on the login page.
4. Sign in as the seeded admin, upload a synthetic `.eml` (like the one in `tests/e2e/review-smoke.spec.ts`)
Expand Down
9 changes: 6 additions & 3 deletions docs/technical/operations.md
Original file line number Diff line number Diff line change
Expand Up @@ -95,9 +95,12 @@ never its message) and `logger` for records of a library (docling, httpx, uvicor
log line contains document content or personal data.
- Correlation: the request id. The worker sends it to the AI service as `X-Request-Id`. Follow one request
with `docker compose logs web worker ai | grep <requestId>`.
- `/api/health` also reports `dependencies.aiService` (reachable or not) and `backlog` (waiting jobs per
queue). Both are informational and never turn the status into 503 – the AI service is an optional
compose profile.
- `/api/health` also reports `dependencies.aiService` and `backlog` (waiting jobs per queue). Both are
informational and never turn the status into 503 – the AI service is an optional compose profile.
`aiService` is `ok` (answered), `failed` (answered with an error, refused the connection, or no answer for
more than 30 s) or `starting` (no answer within the probe's 2 s – on the showcase usually the cold start of
the scaled-to-zero container, which the probe itself triggers; once it has started, the next call reads `ok`.
A failed or timed-out probe is not cached, #81/#88).

## Deploy step

Expand Down
6 changes: 4 additions & 2 deletions src/app/api/health/route.ts
Original file line number Diff line number Diff line change
Expand Up @@ -3,13 +3,15 @@ import { pingDatabase } from "@/db";
import { countWaitingJobs } from "@/db/job-queue-client";
import { pingAiService } from "@/features/extraction";
import { QUEUES } from "@/features/jobs";
import { cachedFor, logEvent, runHealthChecks } from "@/features/observability";
import { cachedFor, logEvent, runHealthChecks, withStartupGrace } from "@/features/observability";

export const dynamic = "force-dynamic";

const CHECK_TIMEOUT_MS = 3_000;
// Informational parts are cached (public endpoint): at most one AI ping and two counts per 10 s.
const INFO_TTL_MS = 10_000;
// Longer than a cold start of the showcase AI container (~6 s): beyond it, no answer means failed (#88).
const AI_STARTUP_GRACE_MS = 30_000;
let informational:
| { aiService: () => Promise<void>; process: () => Promise<number>; exportQueue: () => Promise<number> }
| undefined;
Expand All @@ -21,7 +23,7 @@ export async function GET(): Promise<Response> {
try {
const { config, database, storage } = getRuntime();
informational ??= {
aiService: cachedFor(INFO_TTL_MS, () => pingAiService(config.aiService.baseUrl)),
aiService: cachedFor(INFO_TTL_MS, withStartupGrace(() => pingAiService(config.aiService.baseUrl), AI_STARTUP_GRACE_MS)),
process: cachedFor(INFO_TTL_MS, () => countWaitingJobs(database.pool, QUEUES.processRequest)),
exportQueue: cachedFor(INFO_TTL_MS, () => countWaitingJobs(database.pool, QUEUES.exportRequest)),
};
Expand Down
62 changes: 61 additions & 1 deletion src/features/observability/health.test.ts
Original file line number Diff line number Diff line change
@@ -1,5 +1,5 @@
import { describe, expect, it } from "vitest";
import { cachedFor, runHealthChecks } from "./health";
import { cachedFor, runHealthChecks, withStartupGrace } from "./health";

const ok = async () => {};
const failing = async () => {
Expand Down Expand Up @@ -50,6 +50,66 @@ describe("runHealthChecks", () => {
});
});

// #81: a dependency that does not answer in time is usually a scaled-to-zero container waking up
// (the probe itself wakes it) – "starting", not "failed". An answered error stays "failed".
it("reports a dependency without an answer in time as starting, not failed", async () => {
const result = await runHealthChecks({ database: ok }, { timeoutMs: 20, dependencies: { aiService: hanging } });

expect(result.httpStatus).toBe(200);
expect(result.report.dependencies).toEqual({ aiService: "starting" });
});

it("also counts the probe's own timeout (AbortSignal.timeout) as starting", async () => {
const aborted = async () => {
throw new DOMException("The operation was aborted due to timeout", "TimeoutError");
};

const result = await runHealthChecks({ database: ok }, { timeoutMs: 100, dependencies: { aiService: aborted } });

expect(result.report.dependencies).toEqual({ aiService: "starting" });
});

it("keeps a check (database, storage) that times out as failed with 503", async () => {
const result = await runHealthChecks({ database: hanging }, { timeoutMs: 20, dependencies: { aiService: hanging } });

expect(result.httpStatus).toBe(503);
expect(result.report).toMatchObject({ status: "degraded", checks: { database: "failed" }, dependencies: { aiService: "starting" } });
});

// #88 review: a dependency that keeps timing out is not starting any more – a cold start takes ~6 s.
it("reports a dependency that keeps timing out beyond the grace period as failed, and starting again after an answer", async () => {
let clock = 0;
let answering = false;
const probe = withStartupGrace(
async () => {
if (!answering) throw new DOMException("The operation was aborted due to timeout", "TimeoutError");
},
30_000,
() => clock,
);
const state = async () => (await runHealthChecks({ database: ok }, { timeoutMs: 100, dependencies: { aiService: probe } })).report.dependencies?.aiService;

expect(await state()).toBe("starting");
clock = 29_999;
expect(await state()).toBe("starting");
clock = 30_001;
expect(await state()).toBe("failed");

answering = true;
expect(await state()).toBe("ok");
answering = false;
clock = 40_000;
expect(await state()).toBe("starting"); // a new cold start gets a new grace period
});

it("does not delay a real error: a refused connection is failed at once", async () => {
const probe = withStartupGrace(failing, 30_000, () => 0);

const result = await runHealthChecks({ database: ok }, { timeoutMs: 100, dependencies: { aiService: probe } });

expect(result.report.dependencies).toEqual({ aiService: "failed" });
});

it("times out a hanging gauge as unknown (null) and never leaks error text", async () => {
const result = await runHealthChecks({ database: ok }, { timeoutMs: 20, backlog: { "request-process": () => new Promise<number>(() => {}) } });

Expand Down
63 changes: 51 additions & 12 deletions src/features/observability/health.ts
Original file line number Diff line number Diff line change
@@ -1,11 +1,16 @@
export type HealthCheck = () => Promise<void>;
export type CheckResult = "ok" | "failed";
/**
* `starting` (#81): no answer within the time limit – for a scaled-to-zero container usually its cold
* start, which the probe itself triggers; the next probe normally reads `ok`. An answered error is `failed`.
*/
export type DependencyResult = CheckResult | "starting";

export interface HealthReport {
status: "ok" | "degraded";
checks: Record<string, CheckResult>;
/** Informational (#28): reachable or not – does not change the HTTP status (e.g. the optional AI profile). */
dependencies?: Record<string, CheckResult>;
/** Informational (#28, #81): ok, failed or starting – does not change the HTTP status (e.g. the optional AI profile). */
dependencies?: Record<string, DependencyResult>;
/** Informational (#28): jobs waiting per queue; null when unknown. */
backlog?: Record<string, number | null>;
}
Expand All @@ -15,17 +20,24 @@ export interface HealthResult {
report: HealthReport;
}

// A check fails by throwing or by exceeding the time limit. Error details stay out of the
// report on purpose: /api/health is reachable without login and must not leak hosts or users.
// A required check fails by throwing or by exceeding the time limit; an informational dependency that
// does not answer in time is `starting` (#81). Error details stay out of the report on purpose:
// /api/health is reachable without login and must not leak hosts or users.
export async function runHealthChecks(
checks: Record<string, HealthCheck>,
options: { timeoutMs: number; dependencies?: Record<string, HealthCheck>; backlog?: Record<string, () => Promise<number>> },
): Promise<HealthResult> {
const settleAll = (group: Record<string, HealthCheck>) =>
Promise.all(Object.entries(group).map(async ([name, check]) => [name, await settle(check, options.timeoutMs)] as const));
// A required check that does not answer in time has failed; an informational dependency is starting.
const settleAll = <R extends string>(group: Record<string, HealthCheck>, onTimeout: R) =>
Promise.all(
Object.entries(group).map(async ([name, check]) => {
const outcome = await settle(check, options.timeoutMs);
return [name, outcome === "timeout" ? onTimeout : outcome] as const;
}),
);
const [entries, dependencies, backlog] = await Promise.all([
settleAll(checks),
options.dependencies ? settleAll(options.dependencies) : undefined,
settleAll(checks, "failed" as const),
options.dependencies ? settleAll(options.dependencies, "starting" as const) : undefined,
options.backlog
? Promise.all(
Object.entries(options.backlog).map(async ([name, gauge]) => {
Expand All @@ -45,16 +57,43 @@ export async function runHealthChecks(
return { httpStatus: healthy ? 200 : 503, report };
}

async function settle(check: HealthCheck, timeoutMs: number): Promise<CheckResult> {
const TIMED_OUT = Symbol("timed out");

/**
* A dependency that keeps timing out is not starting any more (#88 review): a cold start takes about
* 6 s, so timeouts for longer than `graceMs` read as failed – a wrong address, a dropped connection or a
* hanging service would otherwise show `starting` for ever. An answer (or a real error) ends the period.
*/
export function withStartupGrace(check: HealthCheck, graceMs: number, now: () => number = Date.now): HealthCheck {
let timingOutSince: number | undefined;
return async () => {
try {
await check();
timingOutSince = undefined;
} catch (error) {
if (!isTimeout(error)) {
timingOutSince = undefined;
throw error;
}
timingOutSince ??= now();
if (now() - timingOutSince > graceMs) throw new Error("no answer beyond the startup grace period");
throw error;
}
};
}
// Our own limit, or the probe's AbortSignal.timeout (a DOMException named TimeoutError).
const isTimeout = (error: unknown) => error === TIMED_OUT || (error instanceof Error && error.name === "TimeoutError");

async function settle(check: HealthCheck, timeoutMs: number): Promise<CheckResult | "timeout"> {
let timer: ReturnType<typeof setTimeout> | undefined;
const timeout = new Promise<never>((_, reject) => {
timer = setTimeout(() => reject(new Error("timeout")), timeoutMs);
timer = setTimeout(() => reject(TIMED_OUT), timeoutMs);
});
try {
await Promise.race([check(), timeout]);
return "ok";
} catch {
return "failed";
} catch (error) {
return isTimeout(error) ? "timeout" : "failed";
} finally {
clearTimeout(timer);
}
Expand Down
2 changes: 1 addition & 1 deletion src/features/observability/index.ts
Original file line number Diff line number Diff line change
@@ -1,3 +1,3 @@
// Public API of the `observability` module: health aggregation, structured log lines (IDs only).
export { cachedFor, runHealthChecks, type HealthCheck, type HealthReport, type HealthResult } from "./health";
export { cachedFor, runHealthChecks, withStartupGrace, type CheckResult, type DependencyResult, type HealthCheck, type HealthReport, type HealthResult } from "./health";
export { captureLogs, logEvent, type LogDetail, type LogIds, type LogLevel } from "./log";
18 changes: 18 additions & 0 deletions tests/integration/health.test.ts
Original file line number Diff line number Diff line change
Expand Up @@ -30,6 +30,24 @@ describe("GET /api/health", () => {
});
});

// #81/#88: the real undici abort of pingAiService (AbortSignal.timeout) reads as starting, not failed.
it("reports an AI service that does not answer in time as starting", async () => {
const server = createServer(() => {
// accepts the connection, never answers – like a container still starting
});
await new Promise<void>((resolve) => server.listen(0, "127.0.0.1", resolve));
try {
vi.stubEnv("AI_SERVICE_URL", `http://127.0.0.1:${(server.address() as AddressInfo).port}`);
const { status, body } = await callHealth();

expect(status).toBe(200);
expect(body.dependencies).toEqual({ aiService: "starting" });
} finally {
server.closeAllConnections();
await new Promise((resolve) => server.close(resolve));
}
});

it("reports the AI service as reachable when its /healthz answers", async () => {
const server = createServer((request, response) => void response.writeHead(request.url === "/healthz" ? 200 : 404).end('{"status":"ok"}'));
await new Promise<void>((resolve) => server.listen(0, "127.0.0.1", resolve));
Expand Down
Loading