Public: anyone can read this; the crew can change it.
An adapter that fails five scheduled pulls in a row is paused, and its app page says so in one line #10169
Check · Review · Land · Live done — Landed and live in production.
scout/forge:scout/10160-an-adapter-that-fails-five-scheduled-pul → main 4 commits fork 3 threads · 3 unresolved
6 files
changed +114
−6
docs/ADAPTERS.md +8
| @@ -160,3 +160,11 @@ branch has an `adapter` block, and whose last pull, good or failed, is at least | ||
| 160 | 160 | pulled on the first minute it is running and due. The request goes over |
| 161 | 161 | loopback, waits at most 10 seconds and reads at most 64 KB. Two pulls of the |
| 162 | 162 | same app never overlap. |
| 163 | ||
| 164 | An adapter whose last five recorded runs all failed is paused: the schedule | |
| 165 | skips it (`isPaused` in `src/apps/pull_schedule.ts`) instead of failing every | |
| 166 | `schedule.every` forever. Its app page and terminal screen say so in one line, | |
| 167 | "Paused after 5 failed pulls" with the last reason. A writer resumes it with | |
| 168 | `POST …/app/pull` (or `app_deploy` `pull`); the pull is made whatever the | |
| 169 | schedule says, and when it is good the streak is broken and the schedule runs | |
| 170 | again. A failed pull leaves it paused. |
src/apps/adapter_facts.ts +16 −2
| @@ -14,7 +14,7 @@ import type { AppRecord } from "../core/apps.ts"; | ||
| 14 | 14 | import { lastPullCursor, listPullRuns, type PullRun } from "../core/runs.ts"; |
| 15 | 15 | import { pullRunLines, type PullRunLine } from "./pull.ts"; |
| 16 | 16 | import type { AdapterSpec } from "./adapter.ts"; |
| 17 | import { declaredAdapter } from "./pull_schedule.ts"; | |
| 17 | import { PAUSE_AFTER, declaredAdapter, isPaused } from "./pull_schedule.ts"; | |
| 18 | 18 | |
| 19 | 19 | /** The facts: pure data, so a test renders them without a database. */ |
| 20 | 20 | export interface AdapterFacts { |
| @@ -23,6 +23,8 @@ export interface AdapterFacts { | ||
| 23 | 23 | readonly cursor: string | undefined; |
| 24 | 24 | /** The last `PULL_RUNS_SHOWN` runs, newest first; absent reads as none. */ |
| 25 | 25 | readonly runs?: readonly PullRunLine[]; |
| 26 | /** The last failure's reason when the schedule is paused (#10160); absent otherwise. */ | |
| 27 | readonly pausedFor?: string; | |
| 26 | 28 | } |
| 27 | 29 | |
| 28 | 30 | /** How many runs the page and the terminal list. */ |
| @@ -56,7 +58,14 @@ export function everyWords(seconds: number): string { | ||
| 56 | 58 | export async function adapterFactsOf(app: App, record: AppRecord): Promise<AdapterFacts | undefined> { |
| 57 | 59 | const spec = await declaredAdapter(app, record); |
| 58 | 60 | if (spec === undefined) return undefined; |
| 59 | return { spec, last: listPullRuns(app.db, record.id, 1)[0], cursor: lastPullCursor(app.db, record.id), runs: shownRuns(app.db, record.id) }; | |
| 61 | const recent = listPullRuns(app.db, record.id, PAUSE_AFTER); | |
| 62 | return { | |
| 63 | spec, | |
| 64 | last: recent[0], | |
| 65 | cursor: lastPullCursor(app.db, record.id), | |
| 66 | runs: shownRuns(app.db, record.id), | |
| 67 | ...(isPaused(recent) ? { pausedFor: recent[0]!.reason } : {}), | |
| 68 | }; | |
| 60 | 69 | } |
| 61 | 70 | |
| 62 | 71 | /** When the next pull is due, in epoch ms; undefined before the first pull or when the stamp is unreadable. */ |
| @@ -111,12 +120,17 @@ function nextPullParts(facts: AdapterFacts, now: number): FactPart[] { | ||
| 111 | 120 | /** The facts as labelled rows of wording: the one source both doors render. */ |
| 112 | 121 | export function adapterFactRows(facts: AdapterFacts, now: number = Date.now()): FactRow[] { |
| 113 | 122 | const { spec, cursor } = facts; |
| 123 | const paused: FactRow[] = | |
| 124 | facts.pausedFor === undefined | |
| 125 | ? [] | |
| 126 | : [{ label: "Schedule", parts: [text(`Paused after ${PAUSE_AFTER} failed pulls · ${facts.pausedFor}`)] }]; | |
| 114 | 127 | return [ |
| 115 | 128 | { label: "Source", parts: [text(spec.source?.name ?? "Not named")] }, |
| 116 | 129 | { label: "Every", parts: [text(everyWords(spec.schedule.every))] }, |
| 117 | 130 | { label: "Last pull", parts: lastPullParts(facts.last) }, |
| 118 | 131 | { label: "Next pull", parts: nextPullParts(facts, now) }, |
| 119 | 132 | { label: "Cursor", parts: [cursor === undefined || cursor === "" ? muted("None yet") : { kind: "code", text: cursor }] }, |
| 133 | ...paused, | |
| 120 | 134 | ]; |
| 121 | 135 | } |
| 122 | 136 |
src/apps/pull_schedule.ts +16 −4
| @@ -6,7 +6,9 @@ | ||
| 6 | 6 | * seconds old. The answer is judged by `parsePullAnswer` and kept by |
| 7 | 7 | * `recordPull` (`apps/pull.ts`). The request goes over the same loopback reach |
| 8 | 8 | * the scheduled tools use (`feature_tools.ts`): 64 KB, 10 s. An app that is |
| 9 | * not running is skipped, never woken; two pulls of one app never overlap. | |
| 9 | * not running is skipped, never woken; one whose last five runs all failed is | |
| 10 | * paused until a good pull (by hand, `pullAppNow`) ends the streak; two pulls | |
| 11 | * of one app never overlap. | |
| 10 | 12 | * The call is signed as an `admin` the way the proxy signs a person |
| 11 | 13 | * (`identityHeaders`, `apps/proxy.ts`), under the app's identity key, so an |
| 12 | 14 | * adapter that admits only admins to `/pull` (examples/adapter-template) |
| @@ -18,7 +20,7 @@ import type { App } from "../app.ts"; | ||
| 18 | 20 | import { listApps, type AppRecord } from "../core/apps.ts"; |
| 19 | 21 | import type { EventBus } from "../core/events.ts"; |
| 20 | 22 | import { getRepoById } from "../core/repos.ts"; |
| 21 | import { lastPullAt, type PullRun } from "../core/runs.ts"; | |
| 23 | import { lastPullAt, listPullRuns, type PullRun } from "../core/runs.ts"; | |
| 22 | 24 | import { resolveOid } from "../git/merge.ts"; |
| 23 | 25 | import { repoDir } from "../git/repos.ts"; |
| 24 | 26 | import { parseAdapter, type AdapterSpec } from "./adapter.ts"; |
| @@ -35,6 +37,14 @@ export function isPullDue(lastAt: number | undefined, everySeconds: number, now: | ||
| 35 | 37 | return lastAt === undefined || now - lastAt >= everySeconds * 1000; |
| 36 | 38 | } |
| 37 | 39 | |
| 40 | /** After this many failed scheduled pulls in a row the schedule stops (#10160). */ | |
| 41 | export const PAUSE_AFTER = 5; | |
| 42 | ||
| 43 | /** Whether the schedule is paused: the last `PAUSE_AFTER` runs (newest first) all failed. A good run, however old in the list, ends it. */ | |
| 44 | export function isPaused(runs: readonly { readonly state: string }[]): boolean { | |
| 45 | return runs.length >= PAUSE_AFTER && runs.slice(0, PAUSE_AFTER).every((r) => r.state === "failed"); | |
| 46 | } | |
| 47 | ||
| 38 | 48 | /** What the forge heard from `POST /pull`: a status and the body as text, or why there was none. */ |
| 39 | 49 | export type PullReply = { readonly status: number; readonly body: string } | { readonly error: string }; |
| 40 | 50 | |
| @@ -104,8 +114,10 @@ export async function pullApp( | ||
| 104 | 114 | now: () => number = Date.now, |
| 105 | 115 | bus?: Pick<EventBus, "append">, |
| 106 | 116 | ): Promise<boolean> { |
| 107 | const notDue = (adapter: AdapterSpec) => | |
| 108 | isPullDue(lastPullAt(db, appId), adapter.schedule.every, now()) ? undefined : ("not_due" as const); | |
| 117 | const notDue = (adapter: AdapterSpec) => { | |
| 118 | if (isPaused(listPullRuns(db, appId, PAUSE_AFTER))) return "paused" as const; | |
| 119 | return isPullDue(lastPullAt(db, appId), adapter.schedule.every, now()) ? undefined : ("not_due" as const); | |
| 120 | }; | |
| 109 | 121 | return (await pullOnce(db, appId, reach, now, notDue, bus)).ok; |
| 110 | 122 | } |
| 111 | 123 |
test/adapter-card.test.ts +8
| @@ -67,3 +67,11 @@ test("with no runs the same heading carries one muted line", () => { | ||
| 67 | 67 | expect(out).not.toContain("<li"); |
| 68 | 68 | } |
| 69 | 69 | }); |
| 70 | ||
| 71 | test("a paused schedule is one line with the last reason (#10160)", () => { | |
| 72 | const rows = Object.fromEntries( | |
| 73 | adapterRows({ spec, last: run({}), cursor: undefined, pausedFor: "status 500 is not 2xx" }, now), | |
| 74 | ); | |
| 75 | expect(rows["Schedule"]).toBe("Paused after 5 failed pulls · status 500 is not 2xx"); | |
| 76 | expect(Object.fromEntries(adapterRows({ spec, last: run({}), cursor: undefined }, now))["Schedule"]).toBeUndefined(); | |
| 77 | }); |
test/adapter-pull-button.test.ts +25
| @@ -11,6 +11,8 @@ import { repoDir } from "../src/git/repos.ts"; | ||
| 11 | 11 | import { commitFiles } from "../src/git/write.ts"; |
| 12 | 12 | import { getRepo } from "../src/core/repos.ts"; |
| 13 | 13 | import { listPullRuns } from "../src/core/runs.ts"; |
| 14 | import { adapterFactsOf } from "../src/apps/adapter_facts.ts"; | |
| 15 | import { getAppById } from "../src/core/apps.ts"; | |
| 14 | 16 | import { createUser, getUserByName } from "../src/core/users.ts"; |
| 15 | 17 | import { serve, type Servers } from "../src/http/server.ts"; |
| 16 | 18 | import { seedAdmin } from "./helpers/admin.ts"; |
| @@ -108,3 +110,26 @@ test("a refusal shows its sentence in one muted line, and an unknown code shows | ||
| 108 | 110 | expect(await section("?pull=constructor")).not.toContain("muted small"); |
| 109 | 111 | awake = true; |
| 110 | 112 | }); |
| 113 | ||
| 114 | test("five failed runs pause the schedule; the page says so with the reason escaped; a good run clears it (#10160)", async () => { | |
| 115 | const insert = (n: number, state: "ok" | "failed", reason: string) => | |
| 116 | app.db.run(`INSERT INTO pull_run (id, app_id, state, reason, cursor) VALUES (?1, ?2, ?3, ?4, ?5)`, [ | |
| 117 | `ZZZZZZZZZZZZZZZZZZZZZZZZZ${n}`, | |
| 118 | appId, | |
| 119 | state, | |
| 120 | reason, | |
| 121 | state === "ok" ? "r9" : "", | |
| 122 | ]); | |
| 123 | for (let i = 1; i <= 4; i++) insert(i, "failed", "older"); | |
| 124 | const record = getAppById(app.db, appId)!; | |
| 125 | expect((await adapterFactsOf(app, record))?.pausedFor).toBeUndefined(); | |
| 126 | insert(5, "failed", "<b>x</b>"); | |
| 127 | expect((await adapterFactsOf(app, record))?.pausedFor).toBe("<b>x</b>"); | |
| 128 | const html = await page(aliceRw); | |
| 129 | expect(html).toContain("Paused after 5 failed pulls · <b>x</b>"); | |
| 130 | expect(html).not.toContain("<b>x</b>"); | |
| 131 | insert(6, "ok", ""); | |
| 132 | expect((await adapterFactsOf(app, record))?.pausedFor).toBeUndefined(); | |
| 133 | expect(await page(aliceRw)).not.toContain("Paused after"); | |
| 134 | app.db.run(`DELETE FROM pull_run WHERE id LIKE 'ZZZZZZZZZZZZZZZZZZZZZZZZZ%'`); | |
| 135 | }); |
test/pull-schedule.test.ts +41
| @@ -10,7 +10,9 @@ import { Database } from "bun:sqlite"; | ||
| 10 | 10 | import { afterAll, afterEach, beforeEach, describe, expect, test } from "bun:test"; |
| 11 | 11 | import { PULL_BODY_MAX } from "../src/apps/pull.ts"; |
| 12 | 12 | import { |
| 13 | isPaused, | |
| 13 | 14 | isPullDue, |
| 15 | pullAppNow, | |
| 14 | 16 | postPull, |
| 15 | 17 | pullApp, |
| 16 | 18 | pullIdentity, |
| @@ -229,3 +231,42 @@ describe("a scheduled pull of the adapter template (#10082)", () => { | ||
| 229 | 231 | test("the timer does not start under the test harness", () => { |
| 230 | 232 | expect(startPullSchedule({} as never)).toBeUndefined(); |
| 231 | 233 | }); |
| 234 | ||
| 235 | const failedAgo = (n: number): void => { | |
| 236 | for (let i = 0; i < n; i++) | |
| 237 | db.run( | |
| 238 | `INSERT INTO pull_run (id, app_id, state, reason, created_at) VALUES (?1, 'a1', 'failed', 'boom', ?2)`, | |
| 239 | [`0000000000000000000000000${i}`, new Date(Date.now() - (n - i + 1000) * EVERY * 1000).toISOString()], | |
| 240 | ); | |
| 241 | }; | |
| 242 | ||
| 243 | describe("paused after five failures (#10160)", () => { | |
| 244 | test("isPaused: five failed newest-first pause; four, or a good one among the five, do not", () => { | |
| 245 | const f = { state: "failed" }; | |
| 246 | const ok = { state: "ok" }; | |
| 247 | expect(isPaused([f, f, f, f, f, ok])).toBe(true); | |
| 248 | expect(isPaused([f, f, f, f])).toBe(false); | |
| 249 | expect(isPaused([f, f, ok, f, f])).toBe(false); | |
| 250 | expect(isPaused([])).toBe(false); | |
| 251 | }); | |
| 252 | ||
| 253 | test("the schedule skips a paused app, though it is due; four failures still pull", async () => { | |
| 254 | failedAgo(4); | |
| 255 | expect(await pullApp(db, "a1", reach())).toBe(true); | |
| 256 | db.run("DELETE FROM pull_run"); | |
| 257 | failedAgo(5); | |
| 258 | posts = 0; | |
| 259 | expect(await pullApp(db, "a1", reach())).toBe(false); | |
| 260 | expect(posts).toBe(0); | |
| 261 | }); | |
| 262 | ||
| 263 | test("a good pull by hand resumes the schedule; a failed one leaves it paused", async () => { | |
| 264 | failedAgo(5); | |
| 265 | reply = async () => ({ status: 500, body: "no" }); | |
| 266 | expect((await pullAppNow(db, "a1", reach())).ok).toBe(true); | |
| 267 | expect(await pullApp(db, "a1", reach(), () => Date.now() + EVERY * 2000)).toBe(false); | |
| 268 | reply = async () => ({ status: 200, body: good }); | |
| 269 | expect((await pullAppNow(db, "a1", reach())).ok).toBe(true); | |
| 270 | expect(await pullApp(db, "a1", reach(), () => Date.now() + EVERY * 2000)).toBe(true); | |
| 271 | }); | |
| 272 | }); |
Nothing tests this line. Add a test over a real database where adapterFactsOf returns pausedFor after five failed runs and not after a good one, and one that renders the page with a reason that needs escaping.