Restart read-only jobs whose container the platform stops without warning (#215)
* Restart read-only jobs whose container the platform stops without warning
- CI / Typecheck and bundlesuccess
- CI / Unit tests (1/2)success
- CI / Unit tests (2/2)success
- Deploy / Deploy to Cloudflaresuccess
- Deploy / Main's current tipsuccess
4 files changed+62−12
Files (4)
modifiedapps/diffinery/docs/actions/runners.md+1−1View file
| @@ -165,7 +165,7 @@ | ||
| 165 | 165 | | Matrix size | 256 jobs per matrix | The job fails with "A matrix may produce at most 256 jobs." | |
| 166 | 166 | | Log line length | 16,384 characters | Longer lines are cut and end with `…` | |
| 167 | 167 | | Log size | 16 MiB of text per job | The log ends with "The log is cut off here: a job's log is limited to 16 MiB of text." Later lines are dropped; the job keeps running. | |
| 168 | -| Platform updates | A deploy is set up not to replace the container of a running job, so running jobs normally finish on the version they started with. The platform doesn't guarantee it, though. If it replaces a container anyway, its stop signal reaches the running step too. Diffinery then starts the job again from the beginning on a new runner, up to twice, if no step but `actions/checkout` had started or if the job can only read: it uses no secrets (other than `GITHUB_TOKEN`), no deployment environment, and its token can't write. What the stopped attempt uploaded (artifacts, caches) is dropped first, as a re-run would. A job that could change something outside the run fails instead once another step has started, because running that step twice could repeat what it did (a deploy, a publish). Re-run it from the run page | The log shows "This runner is being replaced by a new version" and, on the step, "The platform stopped this step's processes while replacing the runner with a new version." A restarted job's log starts over with "Diffinery started the job again from the beginning on a new runner (restart N of 2)". A failed one says "The platform replaced this job's runner with a new version while step … ran" (or, after the third replacement, "… 3 times") | | |
| 168 | +| Platform updates | A deploy is set up not to replace the container of a running job, so running jobs normally finish on the version they started with. The platform doesn't guarantee it, though. If it replaces a container anyway, its stop signal reaches the running step too. The same goes when the platform stops or loses a job's container without warning (it ends with no exit code, for example when its host fails). Diffinery then starts the job again from the beginning on a new runner, up to twice, if no step but `actions/checkout` had started or if the job can only read: it uses no secrets (other than `GITHUB_TOKEN`), no deployment environment, and its token can't write. What the stopped attempt uploaded (artifacts, caches) is dropped first, as a re-run would. A job that could change something outside the run fails instead once another step has started, because running that step twice could repeat what it did (a deploy, a publish). Re-run it from the run page | The log shows "This runner is being replaced by a new version" and, on the step, "The platform stopped this step's processes while replacing the runner with a new version." A restarted job's log starts over with "Diffinery started the job again from the beginning on a new runner (restart N of 2)". A failed one says "The platform replaced this job's runner with a new version while step … ran" or "The platform stopped this job's container while step … ran" (or, after the third replacement, "… 3 times") | | |
| 169 | 169 | |
| 170 | 170 | If the container stops unexpectedly (for example it runs out of memory), the job fails with `The runner stopped unexpectedly (exit code N).` A container that stops before its runner fetched the job is replaced instead, since no step ran. |
| 171 | 171 |
modifiedapps/diffinery/src/repo/actions.ts+12−7View file
| @@ -1644,7 +1644,7 @@ | ||
| 1644 | 1644 | await this.completeJob(jobId, { conclusion: "failure", outputs: {}, failure: { message: `The job exceeded its timeout of ${j.timeout_minutes} minutes.` } }, "timed_out"); |
| 1645 | 1645 | } |
| 1646 | 1646 | |
| 1647 | - async containerStopped(jobId: string, exitCode: number | null, container?: string): Promise<void> { | |
| 1647 | + async containerStopped(jobId: string, exitCode: number | null, container?: string, requested = false): Promise<void> { | |
| 1648 | 1648 | const j = this.sql.exec<JobRow>("SELECT * FROM jobs WHERE id = ?", jobId).toArray()[0]; |
| 1649 | 1649 | if (!j || j.status === "completed") return; |
| 1650 | 1650 | // A container the job no longer runs in (it was replaced, and the job restarted in another). |
| @@ -1658,6 +1658,10 @@ | ||
| 1658 | 1658 | // Stopped without reporting while a newer runner image is deployed than the one it ran on: a rollout replaced it. |
| 1659 | 1659 | const ran = j.runner_info ? (JSON.parse(j.runner_info) as JobRunnerInfo).image : undefined; |
| 1660 | 1660 | if (!j.labels && ran && this.env.RUNNER_IMAGE && ran !== this.env.RUNNER_IMAGE) return this.runnerReplaced(j); |
| 1661 | + // Stopped without an exit code (the library reports none, or 0) and not by Diffinery (a cancel, a | |
| 1662 | + // timeout): the platform stopped or lost the container, for example its host. The same as a | |
| 1663 | + // replacement. A runner that exits by itself reports its job first, and one that crashes exits non-zero. | |
| 1664 | + if (!j.labels && !exitCode && !requested) return this.runnerReplaced(j, "stopped"); | |
| 1661 | 1665 | await this.completeJob(jobId, { conclusion: "failure", outputs: {}, failure: { message: exitCode ? `The runner stopped unexpectedly (exit code ${exitCode}).` : "The runner's container stopped before the job finished, without an exit code (the platform restarted or replaced it)." } }); |
| 1662 | 1666 | } |
| 1663 | 1667 | |
| @@ -2194,13 +2198,14 @@ | ||
| 2194 | 2198 | |
| 2195 | 2199 | /** |
| 2196 | 2200 | * The platform replaced a hosted job's runner while the job ran (a deploy's container rollout, or |
| 2197 | - * the platform moving the container). Its stop signal reaches the running step too, so the job | |
| 2198 | - * can't finish there. It starts again from the beginning on a new runner, as if it had just been | |
| 2201 | + * the platform moving the container), or stopped its container without warning (`how` "stopped", | |
| 2202 | + * see containerStopped). Its stop signal reaches the running step too, so the job can't finish there. It starts again from the beginning on a new runner, as if it had just been | |
| 2199 | 2203 | * queued, up to MAX_RUNNER_RESTARTS times, when running its steps again can't repeat anything |
| 2200 | 2204 | * outside the run: no step but checkout had started, or the job could only read (see `readOnly`). |
| 2201 | 2205 | * Otherwise, or past the limit, the job fails and says why. |
| 2202 | 2206 | */ |
| 2203 | - private async runnerReplaced(job: JobRow): Promise<void> { | |
| 2207 | + private async runnerReplaced(job: JobRow, how: "replaced" | "stopped" = "replaced"): Promise<void> { | |
| 2208 | + const what = how === "replaced" ? "The platform replaced this job's runner with a new version" : "The platform stopped this job's container"; | |
| 2204 | 2209 | const run = this.runRow(job.run_id); |
| 2205 | 2210 | const steps = JSON.parse(job.steps) as Array<StepReport & { index: number }>; |
| 2206 | 2211 | let exp: Expanded | null = null; |
| @@ -2219,7 +2224,7 @@ | ||
| 2219 | 2224 | const why = !repeatable |
| 2220 | 2225 | ? `while step "${stopped!.name}" ran. Diffinery doesn't start a job again by itself once its steps have run if it could change something outside the run (it uses secrets, a deployment environment, or a token that can write), since running them twice could repeat what they did` |
| 2221 | 2226 | : `${stopped ? "after its steps had started" : "before the job's steps ran"}, ${MAX_RUNNER_RESTARTS + 1} times`; |
| 2222 | - await this.completeJob(job.id, { conclusion: "failure", outputs: {}, failure: { message: `The platform replaced this job's runner with a new version ${why}. Re-run the job.` } }); | |
| 2227 | + await this.completeJob(job.id, { conclusion: "failure", outputs: {}, failure: { message: `${what} ${why}. Re-run the job.` } }); | |
| 2223 | 2228 | return; |
| 2224 | 2229 | } |
| 2225 | 2230 | const t = now(); |
| @@ -2230,7 +2235,7 @@ | ||
| 2230 | 2235 | ); |
| 2231 | 2236 | // The log starts over, with a line that says why (its seq keeps counting up, for live readers). |
| 2232 | 2237 | const when = stopped ? `while step "${stopped.name}" ran. The job can only read (no secrets, deployment environment or token that can write), so` : "before the job's steps ran."; |
| 2233 | - const text = `##[warning]The platform replaced this job's runner with a new version ${when} Diffinery started the job again from the beginning on a new runner (restart ${restarts} of ${MAX_RUNNER_RESTARTS}).`; | |
| 2238 | + const text = `##[warning]${what} ${when} Diffinery started the job again from the beginning on a new runner (restart ${restarts} of ${MAX_RUNNER_RESTARTS}).`; | |
| 2234 | 2239 | const seq = (this.sql.exec<{ n: number | null }>("SELECT max(seq) AS n FROM logs WHERE job_id = ?", job.id).one().n ?? -1) + 1; |
| 2235 | 2240 | this.sql.exec("DELETE FROM logs WHERE job_id = ?", job.id); |
| 2236 | 2241 | this.sql.exec("INSERT INTO logs (job_id, seq, t, step, text) VALUES (?, ?, ?, -1, ?)", job.id, seq, t, text); |
| @@ -2246,7 +2251,7 @@ | ||
| 2246 | 2251 | await instance.sendEvent({ type: `job-${job.id}`, payload: { retryInSeconds: 10 } }); |
| 2247 | 2252 | } catch (e) { |
| 2248 | 2253 | console.error("could not ask the run's workflow to start the job again", e); |
| 2249 | - await this.completeJob(job.id, { conclusion: "failure", outputs: {}, failure: { message: "The platform replaced this job's runner with a new version, and Diffinery could not start the job again. Re-run the job." } }); | |
| 2254 | + await this.completeJob(job.id, { conclusion: "failure", outputs: {}, failure: { message: `${what}, and Diffinery could not start the job again. Re-run the job.` } }); | |
| 2250 | 2255 | } |
| 2251 | 2256 | } |
| 2252 | 2257 |
modifiedapps/diffinery/src/runner/containers.ts+8−2View file
| @@ -37,6 +37,9 @@ | ||
| 37 | 37 | } |
| 38 | 38 | } |
| 39 | 39 | |
| 40 | +/** The job a runner container runs; stopRequested once Diffinery asked it to stop (stopJob). */ | |
| 41 | +type RunnerJob = { repoId: string; jobId: string; container?: string; stopRequested?: boolean }; | |
| 42 | + | |
| 40 | 43 | /** How long a job's container may take to come up, and how often it is checked meanwhile. */ |
| 41 | 44 | const START_WAIT_MS = 180_000; |
| 42 | 45 | const START_POLL_MS = 500; |
| @@ -73,16 +76,19 @@ | ||
| 73 | 76 | } |
| 74 | 77 | |
| 75 | 78 | async stopJob(): Promise<void> { |
| 79 | + // Noted first, so onStop can tell Diffinery's own stop (a cancel, a timeout) from the platform's. | |
| 80 | + const job = await this.ctx.storage.get<RunnerJob>("job"); | |
| 81 | + if (job) await this.ctx.storage.put("job", { ...job, stopRequested: true }); | |
| 76 | 82 | // SIGINT cancels the job at once. The agent reads SIGTERM as a platform rollout and |
| 77 | 83 | // keeps the job running for up to 14 minutes, which a cancelled job must not do. |
| 78 | 84 | if (this.ctx.container?.running) await this.stop("SIGINT"); |
| 79 | 85 | } |
| 80 | 86 | |
| 81 | 87 | override async onStop(params: StopParams): Promise<void> { |
| 82 | - const job = await this.ctx.storage.get<{ repoId: string; jobId: string; container?: string }>("job"); | |
| 88 | + const job = await this.ctx.storage.get<RunnerJob>("job"); | |
| 83 | 89 | if (!job) return; |
| 84 | 90 | const repo = this.env.REPO.get(this.env.REPO.idFromName(job.repoId)); |
| 85 | - await repo.containerStopped(job.jobId, params.exitCode ?? null, job.container); | |
| 91 | + await repo.containerStopped(job.jobId, params.exitCode ?? null, job.container, !!job.stopRequested); | |
| 86 | 92 | await this.ctx.storage.delete("job"); |
| 87 | 93 | } |
| 88 | 94 |
modifiedapps/diffinery/test/unit/actions-runtime.test.ts+41−2View file
| @@ -771,8 +771,8 @@ | ||
| 771 | 771 | expect(job("j1")).toMatchObject({ status: "queued", conclusion: null, placement_tries: 3 }); |
| 772 | 772 | await launch("j2"); |
| 773 | 773 | sql.exec("UPDATE jobs SET status = 'in_progress' WHERE id = 'j2'"); |
| 774 | - await actions.containerStopped("j2", null); | |
| 775 | - expect(job("j2")).toMatchObject({ status: "completed", conclusion: "failure" }); | |
| 774 | + await actions.containerStopped("j2", 1); | |
| 775 | + expect(job("j2")).toMatchObject({ status: "completed", conclusion: "failure", placement_tries: 0 }); | |
| 776 | 776 | |
| 777 | 777 | // A container sidecar restarting under the start counts the same way; an error that won't go away fails the job. |
| 778 | 778 | full = true; |
| @@ -1040,6 +1040,45 @@ | ||
| 1040 | 1040 | running("j4", "diffinery-runner:new", []); |
| 1041 | 1041 | await actions.containerStopped("j4", 137, "job-j4"); |
| 1042 | 1042 | expect(job("j4")).toMatchObject({ status: "completed", conclusion: "failure", restarts: 0 }); |
| 1043 | + expect(JSON.parse(job("j4")!.failure as string).message).toBe("The runner stopped unexpectedly (exit code 137)."); | |
| 1044 | + | |
| 1045 | + // A container on the deployed image that the platform stops or loses mid-job (no exit code, not | |
| 1046 | + // stopped by Diffinery) counts as a replacement too: a job that can only read starts again... | |
| 1047 | + sql.exec("INSERT INTO jobs (id, run_id, job_key, name, status) VALUES ('s1', 'run1', 'r1', 's1', 'queued'), ('s2', 'run1', 'k3', 's2', 'queued')"); | |
| 1048 | + await launch("s1"); | |
| 1049 | + running("s1", "diffinery-runner:new", [0, 1], install); | |
| 1050 | + await actions.containerStopped("s1", 0, "job-s1"); | |
| 1051 | + expect(job("s1")).toMatchObject({ status: "queued", conclusion: null, restarts: 1 }); | |
| 1052 | + expect(swept.at(-1)).toEqual(["s1", true]); | |
| 1053 | + expect(logs("s1")).toEqual([{ seq: 2, step: -1, text: expect.stringMatching(/^##\[warning\]The platform stopped this job's container while step "Run pnpm install" ran\. The job can only read .* \(restart 1 of 2\)\.$/) }]); | |
| 1054 | + // ...a late stop of that container changes nothing, and the restarts stop at MAX_RUNNER_RESTARTS. | |
| 1055 | + await actions.containerStopped("s1", null, "job-s1"); | |
| 1056 | + expect(job("s1")).toMatchObject({ status: "queued", restarts: 1 }); | |
| 1057 | + for (let i = 1; i <= MAX_RUNNER_RESTARTS; i++) { | |
| 1058 | + await actions.relaunchJob("s1"); | |
| 1059 | + running("s1", "diffinery-runner:new", [0, 1], install); | |
| 1060 | + await actions.containerStopped("s1", null, started.at(-1)!.container); | |
| 1061 | + } | |
| 1062 | + expect(job("s1")).toMatchObject({ status: "completed", conclusion: "failure", restarts: MAX_RUNNER_RESTARTS }); | |
| 1063 | + expect(JSON.parse(job("s1")!.failure as string).message).toBe("The platform stopped this job's container after its steps had started, 3 times. Re-run the job."); | |
| 1064 | + // One that could change something outside the run fails, naming the step. | |
| 1065 | + await launch("s2"); | |
| 1066 | + running("s2", "diffinery-runner:new", [0, 1]); | |
| 1067 | + await actions.containerStopped("s2", 0, "job-s2"); | |
| 1068 | + expect(job("s2")).toMatchObject({ status: "completed", conclusion: "failure", restarts: 0 }); | |
| 1069 | + expect(JSON.parse(job("s2")!.failure as string).message).toMatch(/^The platform stopped this job's container while step "Deploy" ran\. Diffinery doesn't start a job again by itself/); | |
| 1070 | + // Diffinery's own stop (a cancel, a timeout, fail-fast) never starts a job again, and a runner that crashes isn't retried. | |
| 1071 | + // (Each added after the one before failed, so fail-fast doesn't cancel it.) | |
| 1072 | + sql.exec("INSERT INTO jobs (id, run_id, job_key, name, status) VALUES ('s3', 'run1', 'r1', 's3', 'queued')"); | |
| 1073 | + await launch("s3"); | |
| 1074 | + running("s3", "diffinery-runner:new", [0, 1], install); | |
| 1075 | + await actions.containerStopped("s3", 0, "job-s3", true); | |
| 1076 | + expect(job("s3")).toMatchObject({ status: "completed", conclusion: "failure", restarts: 0 }); | |
| 1077 | + sql.exec("INSERT INTO jobs (id, run_id, job_key, name, status) VALUES ('s4', 'run1', 'r1', 's4', 'queued')"); | |
| 1078 | + await launch("s4"); | |
| 1079 | + running("s4", "diffinery-runner:new", [0, 1], install); | |
| 1080 | + await actions.containerStopped("s4", 1, "job-s4"); | |
| 1081 | + expect(job("s4")).toMatchObject({ status: "completed", conclusion: "failure", restarts: 0 }); | |
| 1043 | 1082 | }); |
| 1044 | 1083 | }); |
| 1045 | 1084 |