Public: anyone can read this; the crew can change it.

`after the push` means after the push: measure from the push and say the wait #90

Merged opened this

Check · Review · Land · Live done — Landed and live in production.

Merged

torque/forge:torque/80-after-the-push-means-after-the-push-meas → main 1 commit fork

  • Merged. torque/80-after-the-push-means-after-the-push-meas was merged into main as d8f56e4.

Review

Sign in to review this change.
5 files changed +232 −13
docs/APPS.md +8 −1
@@ -83,7 +83,14 @@ around it. None is advisory.
8383 `servingAt` is stamped once, at the swap-in, distinct from `startedAt`
8484 (the deploy's own start) and `finishedAt` (which waits on `test`
8585 beside it) — so how long a change took to reach its preview is a
86 number the forge can read back, not a line buried in the log.
86 number the forge can read back, not a line buried in the log. A page
87 words that number from `createdAt`, the instant the push created the
88 run, because the deploy may have waited on the concurrency gate for a
89 permit first: `servedPhrase` (`web/ui.ts`) says `6.1s after the push ·
90 2.4s queued` and is the only place it is worded. The deploy's own log
91 line stays measured from `startedAt` and says `after the deploy
92 started`; a deploy no push asked for — a redeploy someone pressed, a
93 boot reconcile — is worded the same way and never claims a push.
8794 5. **A private app answers only to someone the forge vouches for.** An app's
8895 `access` is `public` or `private` (defaulting to the repository's
8996 visibility), and it is set apart from the repository's own: the code can
src/apps/runtime.ts +33 −3
@@ -93,7 +93,14 @@ export interface EnvStatus {
9393 readonly since?: string | undefined;
9494 /** The instant this deployment started serving, set once at the swap-in. */
9595 readonly servingAt?: string | undefined;
96 /** The deploy run's own start — the reference `servingAt` is measured from. */
96 /**
97 * The instant the push created this deploy run — what a person means by
98 * "after the push", and the reference `servedPhrase` measures from. Unset
99 * for a deploy no push asked for (a redeploy someone pressed, a boot
100 * reconcile), so the words for those never claim a push that never was.
101 */
102 readonly createdAt?: string | undefined;
103 /** The deploy run's own start — after however long it waited for a permit. */
97104 readonly deployStartedAt?: string | undefined;
98105 readonly error?: string | undefined;
99106 /**
@@ -120,10 +127,20 @@ interface Live {
120127 * unset on the value `bringUp` returns, which does not yet know it.
121128 */
122129 readonly servingAt?: string | undefined;
123 /** The deploy run's own start — the reference `servingAt` is measured from. */
130 /** The instant the push created this deploy run, when a push did. */
131 readonly createdAt?: string | undefined;
132 /** The deploy run's own start — the reference the deploy log measures from. */
124133 readonly deployStartedAt?: string | null | undefined;
125134 }
126135
136 /**
137 * The deploy reasons a ref moving created: for these the run's `createdAt`
138 * is the instant of the push that asked for the deploy, so the wait for a
139 * permit sits inside the number the studio prints. A redeploy someone
140 * pressed, a crash restart, and a boot or enable reconcile are not pushes.
141 */
142 const PUSH_REASONS: readonly string[] = ["push", "opened", "merge"];
143
127144 /** How long between two instants, in seconds to one decimal place: `3.4s`. */
128145 function elapsedSeconds(fromIso: string, toIso: string): string {
129146 const ms = Math.max(0, Date.parse(toIso) - Date.parse(fromIso));
@@ -266,6 +283,7 @@ export class AppsRuntime {
266283 port: state.live.handle.port,
267284 since: state.live.since,
268285 servingAt: state.live.servingAt,
286 createdAt: state.live.createdAt,
269287 ...(state.live.deployStartedAt === null
270288 ? {}
271289 : { deployStartedAt: state.live.deployStartedAt }),
@@ -283,6 +301,7 @@ export class AppsRuntime {
283301 runId: swapped ? state.deploying!.run.id : state.live.runId,
284302 since: state.live.since,
285303 servingAt: state.live.servingAt,
304 createdAt: state.live.createdAt,
286305 ...(state.live.deployStartedAt === null
287306 ? {}
288307 : { deployStartedAt: state.live.deployStartedAt }),
@@ -656,7 +675,18 @@ export class AppsRuntime {
656675 const served = markServing(this.app.db, run.id);
657676 const servingAt = served?.servingAt ?? new Date().toISOString();
658677 const deployStartedAt = claimed.startedAt;
659 const live: Live = { ...outcome.value, servingAt, deployStartedAt };
678 // The run was created the instant the push asked for it; it started when
679 // the gate handed it a permit. Both travel with the deployment: the log
680 // below is measured from the start, the studio's phrase from the push.
681 const createdAt = PUSH_REASONS.includes(run.reason)
682 ? run.createdAt
683 : undefined;
684 const live: Live = {
685 ...outcome.value,
686 servingAt,
687 createdAt,
688 deployStartedAt,
689 };
660690 state.live = live;
661691 state.lastError = undefined;
662692 if (previous !== undefined) {
src/web/ui.ts +33 −8
@@ -51,18 +51,43 @@ export function time(iso: string): Html {
5151 >`;
5252 }
5353
54 /** Seconds to one decimal: `3.4s`. A clock that ran backwards reads `0.0s`. */
55 function seconds(ms: number): string {
56 return `${(Math.max(0, ms) / 1000).toFixed(1)}s`;
57 }
58
59 /** The wait a phrase bothers to name: under this it is noise, not news. */
60 const QUEUED_FLOOR_MS = 1_000;
61
5462 /**
5563 * How long a deployment took to start serving, worded for a person:
56 * `3.4s after the push`. Undefined until it has — never a zero.
64 * `3.4s after the push` — measured from the instant the push created the
65 * deploy run, so however long it waited for a permit is inside the number.
66 * When that wait was a second or more it is named too, because the number
67 * is otherwise a puzzle: `6.1s after the push · 2.4s queued`.
68 *
69 * A deploy no push asked for (a redeploy someone pressed, a boot reconcile)
70 * has no push to measure from: it is measured from its own start and says
71 * so, the same sentence its log makes. Undefined until it serves — never a
72 * zero, and never a negative when two clocks disagree.
5773 */
5874 export function servedPhrase(env: EnvStatus): string | undefined {
59 if (env.servingAt === undefined || env.deployStartedAt === undefined)
60 return undefined;
61 const ms = Math.max(
62 0,
63 Date.parse(env.servingAt) - Date.parse(env.deployStartedAt),
64 );
65 return `${(ms / 1000).toFixed(1)}s after the push`;
75 if (env.servingAt === undefined) return undefined;
76 const servedAt = Date.parse(env.servingAt);
77 const pushedAt = env.createdAt === undefined ? NaN : Date.parse(env.createdAt);
78 const startedAt =
79 env.deployStartedAt === undefined ? NaN : Date.parse(env.deployStartedAt);
80 const pushed = Number.isFinite(pushedAt);
81 const from = pushed ? pushedAt : startedAt;
82 if (!Number.isFinite(servedAt) || !Number.isFinite(from)) return undefined;
83 const phrase = `${seconds(servedAt - from)} ${
84 pushed ? "after the push" : "after the deploy started"
85 }`;
86 if (!pushed || !Number.isFinite(startedAt)) return phrase;
87 const queued = startedAt - pushedAt;
88 return queued >= QUEUED_FLOOR_MS
89 ? `${phrase} · ${seconds(queued)} queued`
90 : phrase;
6691 }
6792
6893 /**
test/apps.test.ts +13
@@ -558,6 +558,14 @@ describe("apps: production, previews, data, gates, crew", () => {
558558 // finished, so `servingAt` is already recorded on the still-open run.
559559 expect(run?.servingAt).not.toBeNull();
560560
561 // The pull's push created this run: the status carries that instant, so
562 // the words a page prints measure from the push and not from the permit
563 // the gate handed out however much later.
564 expect(status?.createdAt).toBe(run!.createdAt);
565 expect(Date.parse(status!.deployStartedAt!)).toBeGreaterThanOrEqual(
566 Date.parse(status!.createdAt!),
567 );
568
561569 // `app.serving` published the same instant, with the tests it started
562570 // beside still going — this is what a preview's look is taken from.
563571 const serving = listEvents(app.db, { repoId: repo.id, limit: 200 }).find(
@@ -851,6 +859,11 @@ describe("apps: production, previews, data, gates, crew", () => {
851859 );
852860 expect(production.state).toBe("ok");
853861 expect((await viaHost(`hello.${DOMAIN}`)).status).toBe(200);
862 // No push asked for this one, so it carries no push instant to claim:
863 // a boot reconcile is worded from the deploy's own start.
864 const booted = runtime.envStatus(record, "production");
865 expect(booted?.createdAt).toBeUndefined();
866 expect(booted?.deployStartedAt).toBeDefined();
854867 const openPreviews = listRuns(app.db, repo.id, { kind: "deploy" }).filter(
855868 (r) => r.reason === "boot" && r.env !== "production",
856869 );
test/studio.test.ts +145 −1
@@ -10,7 +10,7 @@ import { dirname, join } from "node:path";
1010 import { createApp, type App } from "../src/app.ts";
1111 import { enableApp } from "../src/actions/apps.ts";
1212 import { previewEnv, type EnvName } from "../src/apps/data.ts";
13 import { AppsRuntime } from "../src/apps/runtime.ts";
13 import { AppsRuntime, type EnvStatus } from "../src/apps/runtime.ts";
1414 import { getAppByRepo, type AppRecord } from "../src/core/apps.ts";
1515 import { addToCrew, createAgent } from "../src/actions/crew.ts";
1616 import { linkIssue } from "../src/actions/dependencies.ts";
@@ -43,6 +43,7 @@ import type { Decider } from "../src/crew/decide.ts";
4343 import { CHECK_FAILED_LIMIT } from "../src/crew/dispatch.ts";
4444 import { serve, type Servers } from "../src/http/server.ts";
4545 import { pendingLeans, pullWord, runWord, type WordCtx } from "../src/web/pages/studio.ts";
46 import { servedPhrase } from "../src/web/ui.ts";
4647 import { repoDir } from "../src/git/repos.ts";
4748
4849 /** One transparent pixel, dropped where a look would sit. */
@@ -1468,6 +1469,69 @@ describe("the app's live fragment: /:owner/:name/app/state", () => {
14681469 expect(live).toContain(link);
14691470 });
14701471
1472 test("the head measures from the push, not from the permit it waited for: a deploy queued 5s reads 6.0s after the push and names the wait", async () => {
1473 const createdAt = new Date(Date.now() - 20_000).toISOString();
1474 const deployStartedAt = new Date(Date.parse(createdAt) + 5_000).toISOString();
1475 const servingAt = new Date(Date.parse(deployStartedAt) + 1_000).toISOString();
1476 const deployRun = createRun(app.db, {
1477 repoId: repo.id,
1478 kind: "deploy",
1479 env: "production",
1480 commitOid: "cafebabe",
1481 reason: "push",
1482 });
1483 claimRun(app.db, deployRun.id);
1484 finishRun(app.db, deployRun.id, { state: "ok", summary: "deploy" });
1485 putEnv("production", {
1486 live: {
1487 commitOid: "cafebabe",
1488 handle: { port: 4322 },
1489 runId: deployRun.id,
1490 since: servingAt,
1491 servingAt,
1492 createdAt,
1493 deployStartedAt,
1494 },
1495 });
1496
1497 const head = await (await get("/alice/vault/app/state", owner)).text();
1498 expect(head).toContain("live 6.0s after the push · 5.0s queued");
1499 expect(head).not.toContain("1.0s after the push");
1500
1501 // The same deployment with no wait for a permit says only the one
1502 // number, exactly as it always has.
1503 putEnv("production", {
1504 live: {
1505 commitOid: "cafebabe",
1506 handle: { port: 4322 },
1507 runId: deployRun.id,
1508 since: servingAt,
1509 servingAt,
1510 createdAt: deployStartedAt,
1511 deployStartedAt,
1512 },
1513 });
1514 const prompt = await (await get("/alice/vault/app/state", owner)).text();
1515 expect(prompt).toContain("live 1.0s after the push");
1516 expect(prompt).not.toContain("queued");
1517
1518 // A deploy no push asked for — a redeploy someone pressed — carries no
1519 // push instant, and its words never claim one.
1520 putEnv("production", {
1521 live: {
1522 commitOid: "cafebabe",
1523 handle: { port: 4322 },
1524 runId: deployRun.id,
1525 since: servingAt,
1526 servingAt,
1527 deployStartedAt,
1528 },
1529 });
1530 const pressed = await (await get("/alice/vault/app/state", owner)).text();
1531 expect(pressed).toContain("live 1.0s after the deploy started");
1532 expect(pressed).not.toContain("after the push");
1533 });
1534
14711535 test("app.serving reaches the repo's stream with the shape the live client keys on, the instant the swap-in happens — before its run has finished", async () => {
14721536 const deployRun = createRun(app.db, {
14731537 repoId: repo.id,
@@ -1992,3 +2056,83 @@ describe("working: a run's own page in the studio", () => {
19922056 expect(page).not.toContain(">Cancel run<");
19932057 });
19942058 });
2059
2060 /**
2061 * The one function every page words a deployment's speed with. The pages
2062 * above prove it reaches the studio; these prove what it says at the edges,
2063 * where a real deploy is awkward to arrange.
2064 */
2065 describe("servedPhrase", () => {
2066 const env = (extra: Partial<EnvStatus>): EnvStatus => ({
2067 env: "production",
2068 state: "running",
2069 commitOid: "cafebabe",
2070 url: "http://vault.apps.test",
2071 ...extra,
2072 });
2073
2074 test("says nothing at all until the deployment serves", () => {
2075 expect(
2076 servedPhrase(
2077 env({
2078 createdAt: "2026-01-01T00:00:00.000Z",
2079 deployStartedAt: "2026-01-01T00:00:02.000Z",
2080 }),
2081 ),
2082 ).toBeUndefined();
2083 });
2084
2085 test("clocks that disagree clamp to zero rather than printing a negative", () => {
2086 expect(
2087 servedPhrase(
2088 env({
2089 createdAt: "2026-01-01T00:00:00.300Z",
2090 deployStartedAt: "2026-01-01T00:00:00.300Z",
2091 servingAt: "2026-01-01T00:00:00.000Z",
2092 }),
2093 ),
2094 ).toBe("0.0s after the push");
2095 // A start before the push it answers is skew too: no negative wait.
2096 expect(
2097 servedPhrase(
2098 env({
2099 createdAt: "2026-01-01T00:00:05.000Z",
2100 deployStartedAt: "2026-01-01T00:00:00.000Z",
2101 servingAt: "2026-01-01T00:00:06.000Z",
2102 }),
2103 ),
2104 ).toBe("1.0s after the push");
2105 });
2106
2107 test("a wait under a second is noise: the phrase reads as it always has", () => {
2108 expect(
2109 servedPhrase(
2110 env({
2111 createdAt: "2026-01-01T00:00:00.000Z",
2112 deployStartedAt: "2026-01-01T00:00:00.900Z",
2113 servingAt: "2026-01-01T00:00:04.300Z",
2114 }),
2115 ),
2116 ).toBe("4.3s after the push");
2117 });
2118
2119 test("a push with no start recorded is still measured from the push", () => {
2120 expect(
2121 servedPhrase(
2122 env({
2123 createdAt: "2026-01-01T00:00:00.000Z",
2124 servingAt: "2026-01-01T00:00:02.500Z",
2125 }),
2126 ),
2127 ).toBe("2.5s after the push");
2128 });
2129
2130 test("a deployment with neither instant, and an unreadable one, say nothing", () => {
2131 expect(servedPhrase(env({ servingAt: "2026-01-01T00:00:02.500Z" }))).toBeUndefined();
2132 expect(
2133 servedPhrase(
2134 env({ createdAt: "not a time", servingAt: "2026-01-01T00:00:02.500Z" }),
2135 ),
2136 ).toBeUndefined();
2137 });
2138 });

↑↓ navigate ↵ open ⌘↵ its app esc close

Keyboard shortcuts

Docs