Skip to content

Commit

A running job's log is live, as on GitHub. A step's output reaches its run's page within about two seconds: the runner sends what is printed every second, and the page asks every second while a step runs, every three while none does; an answer that fails (a 429, a 5xx, the network) is asked again after a wait that doubles to half a minute, or as long as Retry-After says, where before one such answer stopped the log for good and the step said "No output yet." until the page was reloaded, and a signed-out viewer's run page, refreshing beside its log, ran into the 30-a-minute limit within a minute; the live log now counts as a page, and only log downloads as costly. A hidden tab stops asking and catches up when shown, and the page says when it is reconnecting. The running step opens by itself, its timer counts, its log follows the newest line while its end is on screen and offers Jump to latest once the viewer scrolls up, a step that has printed nothing for a while says "Running · no output for 2m 10s", and the job's header names the step it is on. Colour that tools print (bold, dim, italic, underline, the 16 colours as theme tokens for light and dark, 256 colours and 24-bit colour, text and background) is drawn as printed, other escape codes are dropped and links keep their text, and search reads the plain text and keeps the colours around what it marks. Every line is stamped with the time it was printed, as GitHub's raw logs are, so log.txt and the run's zip have a time at the start of each line, and a clock button beside Search logs shows the times, remembered by the browser. Set up job now gives the runner's version and name, the operating system, the runner image, the machine's architecture, CPUs and memory, the token's permissions under G1T_TOKEN Permissions, the secret source and the actions it downloads; each run step opens with GitHub's folded Run group, the script in cyan, the shell's whole path and the step's env, each uses step with its with inputs (an action's defaults among them) and env; cache and artifact transfers say how far they have got every five seconds; and a last Complete job step sets the job's outputs and stops what the steps left running, found by RUNNER_TRACKING_ID as GitHub's runner finds it. Two batches of a job's log written at once can no longer reach for the same seq and lose one. The Actions guide and the rate limits page say so.

Claude-Session:
https://claude.ai/code/session_01PnwTRSNaC7vEHTAuBzjhrn
Claudeagent and Claudeagentcommitted Parent41c296aBrowse files
20 files+1607−1290/20 viewed
+49−1
11421142 fold, errors and warnings are marked, and secrets are replaced with
11431143 `***`. The page keeps itself up to date while the run goes on.
11441144
1145−The start of each job's log lists what its [token](#the-jobs-token) may do.
1145+### Live logs
1146+
1147+While a job runs, its log reaches the page within about two seconds of
1148+being printed: the runner sends what a step prints every second, and the
1149+page asks for more every second while a step is running.
1150+
1151+- The running step opens by itself, and its timer counts up. Its log
1152+ follows the newest line while the end of it is on screen. Scroll up and
1153+ it stays where you are, with **Jump to latest** to go back to the end.
1154+- A step that prints nothing for a while says so under its last line:
1155+ **Running · no output for 2m 10s**, or **no output yet** before its
1156+ first line. The job's header names the step it is on.
1157+- Colour that tools print is shown as they print it: bold, dim, italic,
1158+ underline, the 16 terminal colours, 256 colours and 24-bit colour, for
1159+ text and background, in both the light and the dark theme. Tools built
1160+ on chalk or supports-color colour their output because the job has
1161+ `GITHUB_ACTIONS=true`, as on GitHub; others need asking, such as
1162+ `CARGO_TERM_COLOR: always` in the step's `env` for cargo. Other escape codes (moving the cursor, clearing a
1163+ line) are left out, and a link keeps its text. Search reads the text
1164+ without the colour codes.
1165+- Every line is stamped with the time it was printed, as GitHub stamps
1166+ it (`2026-10-12T09:41:07.1234567Z`). The clock button beside **Search
1167+ logs** shows or hides the times; your browser remembers which.
1168+- A download (the job's `log.txt` and the run's zip) has the time at the
1169+ start of every line, as GitHub's downloaded logs do.
1170+- If the page cannot reach g1t for a moment, it says **Reconnecting to the
1171+ log** and tries again, waiting longer each time up to half a minute.
1172+ A tab you are not looking at stops asking, and catches up when you come
1173+ back to it.
1174+
1175+A cache restore, an artifact upload or download, and other transfers say
1176+how far they have got every few seconds
1177+(`Received 46137344 of 523190823 (8.8%), 43.9 MBs/sec`).
1178+
1179+A [self-hosted runner](/guides/self-hosted-runners/) stamps its lines and
1180+writes these headers once it has updated itself to a release that does;
1181+until then its logs show without times.
1182+
1183+### What a job's log says
1184+
1185+Each job's log reads as GitHub's does:
1186+
1187+| Step | What it shows |
1188+| --- | --- |
1189+| **Set up job** | The runner's version and name; the operating system; the runner image (`ImageOS` and `ImageVersion` when the machine's image sets them, and the software g1t's machines have); the machine (hosted or self-hosted, its architecture, CPUs and memory); what the job's [token](#the-jobs-token) may do, under **G1T_TOKEN Permissions**; the secret source; each action the job uses as it is downloaded, with the commit it resolved to (`Download action repository 'actions/setup-node@v4' (SHA:…)`); and the job's matrix. |
1190+| A `run:` step | A folded group, `Run` and the script's first line, holding the whole script, the shell it ran in (`shell: /usr/bin/bash -e {0}`) and its variables under `env:`, secrets masked. Then what it printed. |
1191+| A `uses:` step | A folded group, `Run owner/repo@ref`, holding its inputs under `with:` (an action's defaults among them) and its variables under `env:`. |
1192+| **Post** steps and **Stop containers** | An action's `post`, saving the cache, then the job's containers stopped, as on GitHub. |
1193+| **Complete job** | The job's outputs as they are set (`Set output 'version'`), and **Cleaning up orphan processes**: anything the steps started and left running is stopped (`Terminate orphan process: pid (1234) (node)`). The runner finds those processes by `RUNNER_TRACKING_ID`, as GitHub's does, so a process that unsets it is not found. Only on Linux. |
11461194
11471195 ### The run's summary
11481196
+4−1
2222 | Pages on g1t.sh, signed in | Session | 1,200 |
2323 | Pages on g1t.sh, [with a token](/guides/authentication/#use-a-token-on-the-website) | Token | 1,000 |
2424 | Pages on g1t.sh, signed out | Client IP address | 600 |
25−| Archive downloads, workflow run pages, logs and search, signed out | Client IP address | 30 |
25+| Archive downloads, workflow run pages, log downloads and search, signed out | Client IP address | 30 |
2626 | [Raw files](/guides/git/#raw-files) on g1tusercontent.com | Client IP address, together with pages signed out | 600 |
2727 | Container and package registries | See [storage and pull limits](/guides/containers/#storage-and-pull-limits) | |
2828
3232 request from one IP address, signed in or not, also counts toward 3,000 a
3333 minute.
3434
35+A running job's live log, which its run's page asks for about once a
36+second, counts as a page, not as a log download.
37+
3538 Agents' sandboxes and workflow jobs report to g1t with their own
3639 credentials. Those reports are not rate limited.
3740
+61−0
11471147 @apply my-0.5 border-l-2 border-line-strong pl-3 text-muted;
11481148 }
11491149
1150+/*
1151+ * Colour in a job's log (lib/ansi.ts): the 16 terminal colours, for text
1152+ * (`ansi-fg-N`) and its background (`ansi-bg-N`), each a pair that reads
1153+ * on the log's background in the light theme and the dark one, as
1154+ * GitHub's log viewer draws them. `inverse` with no colour named swaps
1155+ * the text's and the background's.
1156+ */
1157+:root {
1158+ --ansi-0: light-dark(#24292f, #6e7681);
1159+ --ansi-1: light-dark(#cf222e, #ff7b72);
1160+ --ansi-2: light-dark(#116329, #3fb950);
1161+ --ansi-3: light-dark(#7d4e00, #d29922);
1162+ --ansi-4: light-dark(#0969da, #58a6ff);
1163+ --ansi-5: light-dark(#8250df, #bc8cff);
1164+ --ansi-6: light-dark(#1b7c83, #39c5cf);
1165+ --ansi-7: light-dark(#6e7781, #b1bac4);
1166+ --ansi-8: light-dark(#57606a, #8b949e);
1167+ --ansi-9: light-dark(#a40e26, #ffa198);
1168+ --ansi-10: light-dark(#1a7f37, #56d364);
1169+ --ansi-11: light-dark(#633c01, #e3b341);
1170+ --ansi-12: light-dark(#218bff, #79c0ff);
1171+ --ansi-13: light-dark(#a475f9, #d2a8ff);
1172+ --ansi-14: light-dark(#3192aa, #56d4dd);
1173+ --ansi-15: light-dark(#8c959f, #ffffff);
1174+}
1175+@layer components {
1176+ .ansi-fg-0 { color: var(--ansi-0); }
1177+ .ansi-fg-1 { color: var(--ansi-1); }
1178+ .ansi-fg-2 { color: var(--ansi-2); }
1179+ .ansi-fg-3 { color: var(--ansi-3); }
1180+ .ansi-fg-4 { color: var(--ansi-4); }
1181+ .ansi-fg-5 { color: var(--ansi-5); }
1182+ .ansi-fg-6 { color: var(--ansi-6); }
1183+ .ansi-fg-7 { color: var(--ansi-7); }
1184+ .ansi-fg-8 { color: var(--ansi-8); }
1185+ .ansi-fg-9 { color: var(--ansi-9); }
1186+ .ansi-fg-10 { color: var(--ansi-10); }
1187+ .ansi-fg-11 { color: var(--ansi-11); }
1188+ .ansi-fg-12 { color: var(--ansi-12); }
1189+ .ansi-fg-13 { color: var(--ansi-13); }
1190+ .ansi-fg-14 { color: var(--ansi-14); }
1191+ .ansi-fg-15 { color: var(--ansi-15); }
1192+ .ansi-bg-0 { background-color: var(--ansi-0); }
1193+ .ansi-bg-1 { background-color: var(--ansi-1); }
1194+ .ansi-bg-2 { background-color: var(--ansi-2); }
1195+ .ansi-bg-3 { background-color: var(--ansi-3); }
1196+ .ansi-bg-4 { background-color: var(--ansi-4); }
1197+ .ansi-bg-5 { background-color: var(--ansi-5); }
1198+ .ansi-bg-6 { background-color: var(--ansi-6); }
1199+ .ansi-bg-7 { background-color: var(--ansi-7); }
1200+ .ansi-bg-8 { background-color: var(--ansi-8); }
1201+ .ansi-bg-9 { background-color: var(--ansi-9); }
1202+ .ansi-bg-10 { background-color: var(--ansi-10); }
1203+ .ansi-bg-11 { background-color: var(--ansi-11); }
1204+ .ansi-bg-12 { background-color: var(--ansi-12); }
1205+ .ansi-bg-13 { background-color: var(--ansi-13); }
1206+ .ansi-bg-14 { background-color: var(--ansi-14); }
1207+ .ansi-bg-15 { background-color: var(--ansi-15); }
1208+ .ansi-fg-inverse { color: var(--color-bg); }
1209+ .ansi-bg-inverse { background-color: var(--color-fg); }
1210+}
+148−34
44 * its errors and warnings marked.
55 */
66 import { AlertTriangle, Ban, Check, ChevronRight, CircleDashed, CircleSlash, Clock, Hourglass, Info, Loader2, ShieldAlert, X } from "lucide-react";
7−import { useEffect, useMemo, useRef, useState } from "react";
7+import { Fragment, memo, useEffect, useMemo, useRef, useState } from "react";
88 import { Link } from "react-router";
99
1010 import type { CommitStatus, Conclusion, LogChunk, WorkflowNote } from "@g1t/contracts";
1111
1212 import { Card } from "./ui/card";
1313 import { Hint } from "./ui/hint";
14−import { type Line, blocks, highlight, searchLog } from "../lib/log-lines";
14+import { markSpans, parseAnsi, spanLook } from "../lib/ansi";
15+import { type Line, blocks, searchLog } from "../lib/log-lines";
16+import { type PollAnswer, nextPoll, retryAfterMs } from "../lib/log-poll";
1517
1618 /**
1719 * Where a run, job or step stands. `of` says which: a run's `pending` waits
113115 command: "text-muted",
114116 };
115117
116−function LogLine({ line, number, query = "" }: { line: Line; number: number; query?: string }) {
117− const text = line.text.replace(/^(Error|Warning|Notice): /, "");
118+/** A line's time as the log shows it beside the line: GitHub's, to the millisecond. */
119+function shownTime(at: string): string {
120+ return at.replace(/(\.\d{3})\d*Z$/, "$1Z");
121+}
122+
123+/** A line's text, coloured as the tool that printed it coloured it, and with a search's matches marked. */
124+function LineText({ text, ansi, query }: { text: string; ansi?: string; query: string }) {
125+ const spans = useMemo(() => (ansi ? parseAnsi(ansi) : [{ text, style: {} }]), [text, ansi]);
126+ const pieces = useMemo(() => markSpans(spans, query), [spans, query]);
118127 return (
128+ <>
129+ {pieces.map((piece, index) => {
130+ const look = spanLook(piece.style);
131+ const drawn = look.className || look.style ? (
132+ <span className={look.className} style={look.style}>
133+ {piece.text}
134+ </span>
135+ ) : (
136+ piece.text
137+ );
138+ return piece.match ? (
139+ <mark key={index} className="rounded-sm bg-accent/30 text-fg">
140+ {drawn}
141+ </mark>
142+ ) : (
143+ <Fragment key={index}>{drawn}</Fragment>
144+ );
145+ })}
146+ </>
147+ );
148+}
149+
150+/** One line of a step's log: its number, its time when asked for, and its text. Drawn again only when it changes. */
151+type LogLineProps = { line: Line; number: number; query?: string; timestamps?: boolean };
152+
153+const LogLine = memo(function LogLine({ line, number, query = "", timestamps = false }: LogLineProps) {
154+ const label = /^(Error|Warning|Notice): /;
155+ const text = line.text.replace(label, "");
156+ const ansi = line.ansi?.replace(label, "");
157+ return (
119158 <div className={`flex gap-4 px-4 hover:bg-raised/40 ${line.kind === "error" ? "bg-danger/5" : ""}`}>
120159 <span className="w-8 shrink-0 select-none text-right text-faint/70">{number}</span>
160+ {timestamps && (
161+ <time dateTime={line.at} className="w-[24ch] shrink-0 select-none text-faint/70 tabular-nums">
162+ {line.at ? shownTime(line.at) : ""}
163+ </time>
164+ )}
121165 <span className={`min-w-0 whitespace-pre-wrap break-all ${LINE_STYLE[line.kind]}`}>
122166 {line.kind === "error" && <span className="font-semibold">Error: </span>}
123167 {line.kind === "warning" && <span className="font-semibold">Warning: </span>}
124− {query
125− ? highlight(text, query).map((piece, index) =>
126− piece.match ? (
127− <mark key={index} className="rounded-sm bg-accent/30 text-fg">
128− {piece.text}
129− </mark>
130− ) : (
131− piece.text
132− ),
133− )
134− : text}
168+ <LineText text={text} ansi={ansi} query={query} />
135169 </span>
136170 </div>
137171 );
172+}, sameLine);
173+
174+/** Whether a line would draw the same: a log read again as it grows makes new objects of the lines it had. */
175+function sameLine(a: LogLineProps, b: LogLineProps): boolean {
176+ return (
177+ a.number === b.number &&
178+ a.query === b.query &&
179+ a.timestamps === b.timestamps &&
180+ a.line.kind === b.line.kind &&
181+ a.line.text === b.line.text &&
182+ a.line.ansi === b.line.ansi &&
183+ a.line.at === b.line.at
184+ );
138185 }
139186
140187 /**
141188 * A step's log. With `query`, only the lines holding it (any case), groups
142− * opened, each match marked.
189+ * opened, each match marked. With `timestamps`, each line's time beside it.
143190 */
144−export function LogText({ text, query = "" }: { text: string; query?: string }) {
191+export function LogText({ text, query = "", timestamps = false }: { text: string; query?: string; timestamps?: boolean }) {
145192 const parsed = useMemo(() => blocks(text), [text]);
146193 const found = useMemo(() => searchLog(text, query), [text, query]);
147194 if (!text.trim()) return <p className="px-4 py-2 text-xs text-faint">No output.</p>;
149196 return (
150197 <div className="py-1 font-mono text-xs leading-5">
151198 {found.map(({ line, number }) => (
152− <LogLine key={number} line={line} number={number} query={query} />
199+ <LogLine key={number} line={line} number={number} query={query} timestamps={timestamps} />
153200 ))}
154201 </div>
155202 );
158205 <div className="py-1 font-mono text-xs leading-5">
159206 {parsed.map((block, index) =>
160207 block.kind === "line" ? (
161− <LogLine key={index} line={block.line} number={block.number} />
208+ <LogLine key={index} line={block.line} number={block.number} timestamps={timestamps} />
162209 ) : (
163210 <details key={index} className="group/log">
164211 <summary className="flex cursor-pointer list-none items-center gap-1.5 px-4 text-fg/85 hover:bg-raised/40">
165212 <span className="w-8 shrink-0" />
213+ {timestamps && (
214+ <time dateTime={block.at} className="ml-2.5 w-[24ch] shrink-0 select-none text-faint/70 tabular-nums">
215+ {block.at ? shownTime(block.at) : ""}
216+ </time>
217+ )}
166218 <ChevronRight size={12} className="shrink-0 text-faint transition-transform group-open/log:rotate-90" />
167219 {block.title}
168220 </summary>
169221 {block.lines.map(({ line, number }) => (
170− <LogLine key={number} line={line} number={number} />
222+ <LogLine key={number} line={line} number={number} timestamps={timestamps} />
171223 ))}
172224 </details>
173225 ),
176228 );
177229 }
178230
231+/** A job's log as the page has it: each step's text (0 is the job's setup), when each last grew, and whether asking for more is failing. */
232+export type JobLog = {
233+ byStep: Map<number, string>;
234+ /** When a chunk of each step's last arrived, by this browser's clock. */
235+ grewAt: Map<number, number>;
236+ /** The last ask failed, and the page is waiting to ask again. */
237+ retrying: boolean;
238+};
239+
179240 /**
180− * A job's log, fetched as it grows, split by step: `render` gets each
181− * step's text (0 is the job's setup).
241+ * A job's log, fetched as it grows (lib/log-poll.ts says how often), split
242+ * by step. A failed fetch is tried again, waiting longer each time; while
243+ * the tab is hidden it waits, and asks at once when it is shown again.
244+ * `running` is whether one of the job's steps is running now.
182245 */
183−export function useJobLog(url: string, live: boolean): Map<number, string> {
246+export function useJobLog(url: string, live: boolean, running: boolean): JobLog {
184247 const [chunks, setChunks] = useState<LogChunk[]>([]);
248+ const [grewAt, setGrewAt] = useState<Map<number, number>>(new Map());
249+ const [retrying, setRetrying] = useState(false);
185250 const after = useRef(0);
251+ const runningNow = useRef(running);
252+ runningNow.current = running;
186253 useEffect(() => {
187254 after.current = 0;
188255 setChunks([]);
256+ setGrewAt(new Map());
189257 }, [url]);
190258 useEffect(() => {
191259 let stopped = false;
260+ let busy = false;
261+ let failures = 0;
192262 let timer: ReturnType<typeof setTimeout> | undefined;
263+ const schedule = (delayMs: number | null) => {
264+ if (timer) clearTimeout(timer);
265+ timer = undefined;
266+ if (stopped || delayMs === null) return;
267+ timer = setTimeout(load, delayMs);
268+ };
193269 const load = async () => {
270+ timer = undefined;
271+ if (stopped || busy) return;
272+ // Hidden, a live log waits; it asks again when the tab is shown.
273+ if (live && typeof document !== "undefined" && document.visibilityState === "hidden") return;
274+ busy = true;
275+ let answer: PollAnswer;
194276 try {
195− // Pages of up to 500 chunks, until there is no more for now.
196− for (;;) {
197− const response = await fetch(`${url}?after=${after.current}`);
198− if (!response.ok) break;
277+ const response = await fetch(`${url}?after=${after.current}`, { cache: "no-store" });
278+ if (!response.ok) {
279+ answer = { ok: false, status: response.status, retryAfterMs: retryAfterMs(response.headers.get("retry-after")) };
280+ } else {
199281 const page = (await response.json()) as { chunks: LogChunk[]; done: boolean };
200282 if (stopped) return;
201283 if (page.chunks.length > 0) {
202− after.current = page.chunks[page.chunks.length - 1].seq;
284+ after.current = page.chunks[page.chunks.length - 1]!.seq;
285+ const now = Date.now();
203286 setChunks((known) => [...known, ...page.chunks]);
287+ setGrewAt((known) => {
288+ const next = new Map(known);
289+ for (const chunk of page.chunks) next.set(chunk.step, now);
290+ return next;
291+ });
204292 }
205− if (page.chunks.length < 500) {
206− if (!page.done && live) timer = setTimeout(load, 2000);
207− break;
208− }
293+ answer = { ok: true, done: page.done, full: page.chunks.length >= LOG_PAGE };
209294 }
210295 } catch {
211− if (!stopped && live) timer = setTimeout(load, 4000);
296+ answer = { ok: false };
297+ } finally {
298+ busy = false;
212299 }
300+ if (stopped) return;
301+ const next = nextPoll(answer, { failures, live, running: runningNow.current });
302+ failures = next.failures;
303+ setRetrying(!answer.ok && next.delayMs !== null);
304+ schedule(next.delayMs);
213305 };
306+ const shown = () => {
307+ if (document.visibilityState === "visible" && !timer && !busy && live) load();
308+ else if (document.visibilityState === "visible" && timer && live) schedule(0);
309+ };
214310 load();
311+ document.addEventListener("visibilitychange", shown);
215312 return () => {
216313 stopped = true;
217314 if (timer) clearTimeout(timer);
315+ document.removeEventListener("visibilitychange", shown);
218316 };
219317 }, [url, live]);
220− return useMemo(() => {
318+ const byStep = useMemo(() => {
221319 const byStep = new Map<number, string>();
222320 for (const chunk of chunks) byStep.set(chunk.step, (byStep.get(chunk.step) ?? "") + chunk.text);
223321 return byStep;
224322 }, [chunks]);
323+ return { byStep, grewAt, retrying };
324+}
325+
326+/** The most chunks one answer of the log carries (services/actions, `logs`). */
327+const LOG_PAGE = 500;
328+
329+/** Now, as a number, again every `everyMs` while `on`: for times that count up as you watch. */
330+export function useNow(on: boolean, everyMs = 1000): number {
331+ const [now, setNow] = useState(() => Date.now());
332+ useEffect(() => {
333+ if (!on) return;
334+ setNow(Date.now());
335+ const timer = setInterval(() => setNow(Date.now()), everyMs);
336+ return () => clearInterval(timer);
337+ }, [on, everyMs]);
338+ return now;
225339 }
226340
227341 const NOTE_ICON = {
+94−0
1+import assert from "node:assert/strict";
2+import { test } from "node:test";
3+
4+import { markSpans, paletteRgb, parseAnsi, spanLook, stripAnsi } from "./ansi.ts";
5+
6+const E = "\u001b";
7+
8+test("plain text is one unstyled span", () => {
9+ assert.deepEqual(parseAnsi("cargo build"), [{ text: "cargo build", style: {} }]);
10+ assert.deepEqual(parseAnsi(""), []);
11+});
12+
13+test("SGR codes style the text after them until a reset", () => {
14+ assert.deepEqual(parseAnsi(`${E}[1m${E}[32mCompiling${E}[0m g1t v0.2.0`), [
15+ { text: "Compiling", style: { bold: true, fg: { palette: 2 } } },
16+ { text: " g1t v0.2.0", style: {} },
17+ ]);
18+ // Several in one sequence, an empty one resetting, and the switches off.
19+ assert.deepEqual(parseAnsi(`${E}[2;3;4;9mx${E}[22;23my${E}[24;29mz${E}[mw`), [
20+ { text: "x", style: { dim: true, italic: true, underline: true, strike: true } },
21+ { text: "y", style: { underline: true, strike: true } },
22+ // The same look, one span.
23+ { text: "zw", style: {} },
24+ ]);
25+ // Bright colours, backgrounds, and the defaults back.
26+ assert.deepEqual(parseAnsi(`${E}[91;104mhot${E}[39mbg${E}[49mnone`), [
27+ { text: "hot", style: { fg: { palette: 9 }, bg: { palette: 12 } } },
28+ { text: "bg", style: { bg: { palette: 12 } } },
29+ { text: "none", style: {} },
30+ ]);
31+ assert.deepEqual(parseAnsi(`${E}[7minverse${E}[27m`), [{ text: "inverse", style: { inverse: true } }]);
32+});
33+
34+test("256 colours and 24-bit colours, in both of their forms", () => {
35+ assert.deepEqual(parseAnsi(`${E}[38;5;208morange${E}[48;5;3mon`), [
36+ { text: "orange", style: { fg: { palette: 208 } } },
37+ { text: "on", style: { fg: { palette: 208 }, bg: { palette: 3 } } },
38+ ]);
39+ assert.deepEqual(parseAnsi(`${E}[38;2;255;100;0mrgb${E}[0m`), [{ text: "rgb", style: { fg: { rgb: [255, 100, 0] } } }]);
40+ assert.deepEqual(parseAnsi(`${E}[38:2::10:20:30mitu${E}[48:5:17mbg`), [
41+ { text: "itu", style: { fg: { rgb: [10, 20, 30] } } },
42+ { text: "bg", style: { fg: { rgb: [10, 20, 30] }, bg: { palette: 17 } } },
43+ ]);
44+ // A colour out of range is left alone, and what follows still reads.
45+ assert.deepEqual(parseAnsi(`${E}[38;5;999;1mx`), [{ text: "x", style: { bold: true } }]);
46+ assert.deepEqual(paletteRgb(16), [0, 0, 0]);
47+ assert.deepEqual(paletteRgb(196), [255, 0, 0]);
48+ assert.deepEqual(paletteRgb(232), [8, 8, 8]);
49+ assert.deepEqual(paletteRgb(255), [238, 238, 238]);
50+});
51+
52+test("every other escape is dropped, and a link keeps its text", () => {
53+ // Moving the cursor and clearing the line, as progress bars do.
54+ assert.equal(stripAnsi(`${E}[2K${E}[1G Downloading${E}[?25l done${E}[?25h`), " Downloading done");
55+ // An OSC 8 hyperlink, closed with BEL and with ESC \.
56+ assert.equal(stripAnsi(`see ${E}]8;;https://g1t.sh${E}\\the docs${E}]8;;${E}\\ now`), "see the docs now");
57+ assert.equal(stripAnsi(`${E}]0;title\u0007after`), "after");
58+ // A character set, a two-character escape, a bell and a backspace.
59+ assert.equal(stripAnsi(`${E}(Bplain${E}7 kept\u0007\u0008`), "plain kept");
60+ // A tab stays; a sequence cut off at the end of the line goes.
61+ assert.equal(stripAnsi(`a\tb${E}[3`), "a\tb");
62+ assert.equal(stripAnsi(`end${E}`), "end");
63+ assert.equal(stripAnsi("no escapes"), "no escapes");
64+});
65+
66+test("the 16 colours are theme classes; the rest are inline colours", () => {
67+ assert.deepEqual(spanLook({ bold: true, fg: { palette: 1 }, bg: { palette: 15 } }), { className: "ansi-fg-1 ansi-bg-15 font-bold", style: undefined });
68+ assert.deepEqual(spanLook({ fg: { palette: 196 }, bg: { rgb: [1, 2, 3] } }), {
69+ className: "",
70+ style: { color: "rgb(255, 0, 0)", backgroundColor: "rgb(1, 2, 3)" },
71+ });
72+ assert.deepEqual(spanLook({ inverse: true, fg: { palette: 4 } }), { className: "ansi-fg-inverse ansi-bg-4", style: undefined });
73+ assert.equal(spanLook({ dim: true, italic: true, underline: true }).className, "opacity-70 italic underline");
74+ assert.equal(spanLook({}).className, "");
75+});
76+
77+test("a search marks its matches across spans, colours kept", () => {
78+ const spans = parseAnsi(`${E}[32mtest${E}[0m result: ok. Test`);
79+ assert.deepEqual(markSpans(spans, "T R"), [
80+ { text: "tes", style: { fg: { palette: 2 } }, match: false },
81+ { text: "t", style: { fg: { palette: 2 } }, match: true },
82+ { text: " r", style: {}, match: true },
83+ { text: "esult: ok. Test", style: {}, match: false },
84+ ]);
85+ assert.deepEqual(
86+ markSpans(spans, "test").map((span) => [span.text, span.match]),
87+ [
88+ ["test", true],
89+ [" result: ok. ", false],
90+ ["Test", true],
91+ ],
92+ );
93+ assert.deepEqual(markSpans(spans, " "), spans.map((span) => ({ ...span, match: false })));
94+});
+267−0
1+/**
2+ * Colour in a job's log, as a terminal draws it. Tools colour their output
3+ * when they see `GITHUB_ACTIONS=true` (chalk, cargo, pytest and the like),
4+ * with SGR escape codes: bold, dim, italic, underline, the 16 colours, the
5+ * 256-colour palette and 24-bit colour, for text and its background. Those
6+ * are read into styled spans; every other escape sequence (moving the
7+ * cursor, clearing the line, setting the window's title) is dropped, and a
8+ * hyperlink (OSC 8) keeps its text. The 16 colours are theme tokens
9+ * (`ansi-fg-N` and `ansi-bg-N` in app.css), so they read in light and dark.
10+ */
11+
12+/** A colour: one of the 256 of the palette, or red, green and blue. */
13+export type AnsiColor = { palette: number } | { rgb: [number, number, number] };
14+
15+export type AnsiStyle = {
16+ bold?: boolean;
17+ dim?: boolean;
18+ italic?: boolean;
19+ underline?: boolean;
20+ strike?: boolean;
21+ inverse?: boolean;
22+ fg?: AnsiColor;
23+ bg?: AnsiColor;
24+};
25+
26+export type AnsiSpan = { text: string; style: AnsiStyle };
27+
28+const ESC = "\u001b";
29+
30+/** Whether `text` holds an escape sequence or another control character worth reading out. */
31+export function hasEscapes(text: string): boolean {
32+ // eslint-disable-next-line no-control-regex
33+ return /[\u0000-\u0008\u000b-\u001f\u007f\u009b]/.test(text);
34+}
35+
36+/** `text` without its escape sequences: what a search reads and a copy takes. */
37+export function stripAnsi(text: string): string {
38+ if (!hasEscapes(text)) return text;
39+ return parseAnsi(text)
40+ .map((span) => span.text)
41+ .join("");
42+}
43+
44+/**
45+ * A parameter in ITU's colon form as its `;` form: `38:5:n`, `38:2::r:g:b`
46+ * (the empty one names the colour space), and `4:3`, a curly underline,
47+ * as an underline.
48+ */
49+function colonForm(part: string): string[] {
50+ if (!part.includes(":")) return [part];
51+ const pieces = part.split(":");
52+ if ((pieces[0] === "38" || pieces[0] === "48") && pieces[1] === "2" && pieces.length >= 6) return [pieces[0], "2", ...pieces.slice(3, 6)];
53+ if (pieces[0] === "4") return [pieces[1] === "0" ? "24" : "4"];
54+ return pieces;
55+}
56+
57+/** Reads one SGR sequence's parameters into `style`, in place. */
58+function applySgr(style: AnsiStyle, params: string): void {
59+ const codes = (params === "" ? "0" : params)
60+ .split(";")
61+ .flatMap(colonForm)
62+ .map((part) => (part === "" ? 0 : Number(part)));
63+ for (let i = 0; i < codes.length; i++) {
64+ const code = codes[i]!;
65+ if (!Number.isFinite(code)) continue;
66+ if (code === 0) {
67+ for (const key of Object.keys(style) as (keyof AnsiStyle)[]) delete style[key];
68+ } else if (code === 1) style.bold = true;
69+ else if (code === 2) style.dim = true;
70+ else if (code === 3) style.italic = true;
71+ else if (code === 4 || code === 21) style.underline = true;
72+ else if (code === 7) style.inverse = true;
73+ else if (code === 9) style.strike = true;
74+ else if (code === 22) {
75+ delete style.bold;
76+ delete style.dim;
77+ } else if (code === 23) delete style.italic;
78+ else if (code === 24) delete style.underline;
79+ else if (code === 27) delete style.inverse;
80+ else if (code === 29) delete style.strike;
81+ else if (code >= 30 && code <= 37) style.fg = { palette: code - 30 };
82+ else if (code === 39) delete style.fg;
83+ else if (code >= 40 && code <= 47) style.bg = { palette: code - 40 };
84+ else if (code === 49) delete style.bg;
85+ else if (code >= 90 && code <= 97) style.fg = { palette: code - 90 + 8 };
86+ else if (code >= 100 && code <= 107) style.bg = { palette: code - 100 + 8 };
87+ else if (code === 38 || code === 48) {
88+ const key = code === 38 ? "fg" : "bg";
89+ const kind = codes[i + 1];
90+ if (kind === 5) {
91+ const n = codes[i + 2];
92+ if (n !== undefined && n >= 0 && n <= 255) style[key] = { palette: n };
93+ i += 2;
94+ } else if (kind === 2) {
95+ const [r, g, b] = [codes[i + 2], codes[i + 3], codes[i + 4]];
96+ if ([r, g, b].every((n) => n !== undefined && n >= 0 && n <= 255)) style[key] = { rgb: [r!, g!, b!] };
97+ i += 4;
98+ }
99+ }
100+ }
101+}
102+
103+/**
104+ * One line of a log as styled spans, in order, with every escape
105+ * sequence read or dropped. A line starts unstyled, as each line of
106+ * GitHub's log does.
107+ */
108+export function parseAnsi(text: string): AnsiSpan[] {
109+ const spans: AnsiSpan[] = [];
110+ const style: AnsiStyle = {};
111+ let pending = "";
112+ const push = () => {
113+ if (!pending) return;
114+ const last = spans[spans.length - 1];
115+ if (last && sameStyle(last.style, style)) last.text += pending;
116+ else spans.push({ text: pending, style: { ...style } });
117+ pending = "";
118+ };
119+ let i = 0;
120+ while (i < text.length) {
121+ const char = text[i]!;
122+ const code = char.charCodeAt(0);
123+ if (char === ESC || code === 0x9b) {
124+ const csi = code === 0x9b || text[i + 1] === "[";
125+ if (csi) {
126+ // CSI: parameters, intermediates, then one final byte.
127+ let j = i + (code === 0x9b ? 1 : 2);
128+ const start = j;
129+ while (j < text.length && text.charCodeAt(j) >= 0x30 && text.charCodeAt(j) <= 0x3f) j++;
130+ const params = text.slice(start, j);
131+ while (j < text.length && text.charCodeAt(j) >= 0x20 && text.charCodeAt(j) <= 0x2f) j++;
132+ const final = text[j];
133+ if (final === "m" && /^[\d;:]*$/.test(params)) {
134+ push();
135+ applySgr(style, params);
136+ }
137+ i = final === undefined ? j : j + 1;
138+ continue;
139+ }
140+ const next = text[i + 1];
141+ if (next === "]" || next === "P" || next === "X" || next === "^" || next === "_") {
142+ // OSC and the other strings: to BEL or ESC \. An OSC 8 hyperlink
143+ // is two of these around its text, which stays.
144+ let j = i + 2;
145+ while (j < text.length && text[j] !== "\u0007" && !(text[j] === ESC && text[j + 1] === "\\")) j++;
146+ i = j >= text.length ? j : text[j] === "\u0007" ? j + 1 : j + 2;
147+ continue;
148+ }
149+ // ESC ( B and its kin pick a character set: three characters.
150+ if (next !== undefined && "()*+-./#%".includes(next)) {
151+ i += 3;
152+ continue;
153+ }
154+ // Any other escape is two characters (ESC 7, ESC =, ESC M…).
155+ i += next === undefined ? 1 : 2;
156+ continue;
157+ }
158+ // Other control characters (a bell, a backspace) draw nothing; a tab stays.
159+ if ((code < 0x20 && char !== "\t") || code === 0x7f) {
160+ i++;
161+ continue;
162+ }
163+ pending += char;
164+ i++;
165+ }
166+ push();
167+ return spans;
168+}
169+
170+function sameColor(a: AnsiColor | undefined, b: AnsiColor | undefined): boolean {
171+ if (!a || !b) return a === b;
172+ if ("palette" in a) return "palette" in b && a.palette === b.palette;
173+ return "rgb" in b && a.rgb.every((n, index) => n === b.rgb[index]);
174+}
175+
176+function sameStyle(a: AnsiStyle, b: AnsiStyle): boolean {
177+ return (
178+ !!a.bold === !!b.bold &&
179+ !!a.dim === !!b.dim &&
180+ !!a.italic === !!b.italic &&
181+ !!a.underline === !!b.underline &&
182+ !!a.strike === !!b.strike &&
183+ !!a.inverse === !!b.inverse &&
184+ sameColor(a.fg, b.fg) &&
185+ sameColor(a.bg, b.bg)
186+ );
187+}
188+
189+/** A colour of the 256-colour palette past the first 16, as red, green and blue. */
190+export function paletteRgb(n: number): [number, number, number] {
191+ if (n >= 232) {
192+ const level = 8 + (n - 232) * 10;
193+ return [level, level, level];
194+ }
195+ const index = n - 16;
196+ const step = (value: number) => (value === 0 ? 0 : 55 + value * 40);
197+ return [step(Math.floor(index / 36)), step(Math.floor(index / 6) % 6), step(index % 6)];
198+}
199+
200+function cssColor(color: AnsiColor): { token: number } | { css: string } {
201+ if ("palette" in color) {
202+ if (color.palette < 16) return { token: color.palette };
203+ const [r, g, b] = paletteRgb(color.palette);
204+ return { css: `rgb(${r}, ${g}, ${b})` };
205+ }
206+ return { css: `rgb(${color.rgb.join(", ")})` };
207+}
208+
209+/**
210+ * How a span draws: classes for what the theme decides (the 16 colours,
211+ * weight, slant, lines) and inline colours for the rest.
212+ */
213+export function spanLook(style: AnsiStyle): { className: string; style?: { color?: string; backgroundColor?: string } } {
214+ const classes: string[] = [];
215+ const inline: { color?: string; backgroundColor?: string } = {};
216+ const [fg, bg] = style.inverse ? [style.bg, style.fg] : [style.fg, style.bg];
217+ if (fg) {
218+ const look = cssColor(fg);
219+ if ("token" in look) classes.push(`ansi-fg-${look.token}`);
220+ else inline.color = look.css;
221+ } else if (style.inverse) classes.push("ansi-fg-inverse");
222+ if (bg) {
223+ const look = cssColor(bg);
224+ if ("token" in look) classes.push(`ansi-bg-${look.token}`);
225+ else inline.backgroundColor = look.css;
226+ } else if (style.inverse) classes.push("ansi-bg-inverse");
227+ if (style.bold) classes.push("font-bold");
228+ if (style.dim) classes.push("opacity-70");
229+ if (style.italic) classes.push("italic");
230+ if (style.underline && style.strike) classes.push("[text-decoration-line:underline_line-through]");
231+ else if (style.underline) classes.push("underline");
232+ else if (style.strike) classes.push("line-through");
233+ return { className: classes.join(" "), style: inline.color || inline.backgroundColor ? inline : undefined };
234+}
235+
236+/**
237+ * Spans cut where `query` (any case) appears in their text taken
238+ * together, each piece marked as a match or not, so a search marks what
239+ * it found without losing the colours around it.
240+ */
241+export function markSpans(spans: AnsiSpan[], query: string): (AnsiSpan & { match: boolean })[] {
242+ const wanted = query.trim().toLowerCase();
243+ if (!wanted) return spans.map((span) => ({ ...span, match: false }));
244+ const plain = spans.map((span) => span.text).join("");
245+ const lower = plain.toLowerCase();
246+ // Where matches start and end, in the plain text.
247+ const ranges: [number, number][] = [];
248+ for (let found = lower.indexOf(wanted); found !== -1; found = lower.indexOf(wanted, found + wanted.length)) {
249+ ranges.push([found, found + wanted.length]);
250+ }
251+ if (ranges.length === 0) return spans.map((span) => ({ ...span, match: false }));
252+ const out: (AnsiSpan & { match: boolean })[] = [];
253+ let at = 0;
254+ for (const span of spans) {
255+ const end = at + span.text.length;
256+ let cursor = at;
257+ while (cursor < end) {
258+ const inside = ranges.find(([from, to]) => cursor >= from && cursor < to);
259+ const nextStart = ranges.find(([from]) => from > cursor)?.[0] ?? Infinity;
260+ const stop = Math.min(end, inside ? inside[1] : nextStart);
261+ out.push({ text: plain.slice(cursor, stop), style: span.style, match: Boolean(inside) });
262+ cursor = stop;
263+ }
264+ at = end;
265+ }
266+ return out;
267+}
+2−1
147147 ]) {
148148 assert.ok(heavy(path), path);
149149 }
150− for (const path of ["/", "/acme/rocket", "/acme/rocket/actions", "/acme/rocket/issues/1", "/acme/search"]) {
150+ // A running job's live log is asked for every second; it counts as a page.
151+ for (const path of ["/", "/acme/rocket", "/acme/rocket/actions", "/acme/rocket/issues/1", "/acme/search", "/acme/rocket/actions/jobs/job_1/log"]) {
151152 assert.ok(!heavy(path), path);
152153 }
153154 });
+8−2
4141 /** Files the Worker serves that are never limited: build output, fonts, and top-level files such as robots.txt. */
4242 const UNLIMITED = /^\/(?:assets\/|fonts\/|favicon|[^/]+\.(?:ico|png|svg|txt|xml|webmanifest)$)/;
4343
44−/** What is costly to answer for a signed-out visitor: a repository's archives, a run's page, logs and artifacts, and search. */
44+/**
45+ * What is costly to answer for a signed-out visitor: a repository's
46+ * archives, a run's page, log downloads and artifacts, and search. A
47+ * running job's live log (`actions/jobs/:job/log`, a small read the page
48+ * makes about once a second) counts as a page: with the run's page
49+ * refreshing beside it, it would use up this limit in half a minute.
50+ */
4551 const HEAVY =
46− /^\/(?:search(?:\.data)?$|[^/]+\/[^/]+\/(?:archive\/|actions\/runs\/[^/]+(?:\.data|\/logs\.zip|\/artifacts\/[^/]+)?$|actions\/jobs\/[^/]+\/log))/;
52+ /^\/(?:search(?:\.data)?$|[^/]+\/[^/]+\/(?:archive\/|actions\/runs\/[^/]+(?:\.data|\/logs\.zip|\/artifacts\/[^/]+)?$|actions\/jobs\/[^/]+\/log\.txt$))/;
4753
4854 export function unlimited(pathname: string): boolean {
4955 return UNLIMITED.test(pathname);
+40−1
33
44 import type { JobLogText } from "@g1t/contracts";
55
6−import { archiveFiles, blocks, fileName, highlight, searchLog } from "./log-lines.ts";
6+import { archiveFiles, blocks, classify, fileName, highlight, lastStamp, searchLog, splitStamp } from "./log-lines.ts";
77
88 const LOG = ["Job: test", "##[group]Run cargo test", "cargo test --locked", "##[endgroup]", "test greet ... FAILED", "##[error]Process completed with exit code 101."].join("\n");
99
5757 assert.equal(fileName("build / a:b"), "build _ a_b");
5858 assert.equal(fileName(".."), "job");
5959 });
60+
61+test("each line's time comes off the front, as GitHub's logs stamp it, and colours stay beside the plain text", () => {
62+ const stamped = [
63+ "2026-10-12T09:41:07.1234567Z ##[group]Run cargo build",
64+ "2026-10-12T09:41:07.2000000Z \u001b[36;1mcargo build\u001b[0m",
65+ "2026-10-12T09:41:07.3000000Z ##[endgroup]",
66+ "2026-10-12T09:41:09.0000000Z \u001b[1m\u001b[32m Compiling\u001b[0m g1t v0.2.0",
67+ "2026-10-12T09:41:10.0000000Z ##[error]Process completed with exit code 1.",
68+ "a line from before lines were stamped",
69+ "",
70+ ].join("\n");
71+ const parsed = blocks(stamped);
72+ assert.equal(parsed.length, 4, "a log's last newline adds no line");
73+ assert.deepEqual(parsed[0], {
74+ kind: "group",
75+ title: "Run cargo build",
76+ at: "2026-10-12T09:41:07.1234567Z",
77+ lines: [{ line: { kind: "text", text: "cargo build", at: "2026-10-12T09:41:07.2000000Z", ansi: "\u001b[36;1mcargo build\u001b[0m" }, number: 1 }],
78+ });
79+ assert.deepEqual(parsed[1], {
80+ kind: "line",
81+ line: { kind: "text", text: " Compiling g1t v0.2.0", at: "2026-10-12T09:41:09.0000000Z", ansi: "\u001b[1m\u001b[32m Compiling\u001b[0m g1t v0.2.0" },
82+ number: 2,
83+ });
84+ assert.deepEqual(parsed[2], { kind: "line", line: { kind: "error", text: "Process completed with exit code 1.", at: "2026-10-12T09:41:10.0000000Z" }, number: 3 });
85+ assert.deepEqual(parsed[3], { kind: "line", line: { kind: "text", text: "a line from before lines were stamped" }, number: 4 });
86+ // Search reads the plain text, never the time or the codes.
87+ assert.deepEqual(
88+ searchLog(stamped, "compiling g1t").map((found) => found.number),
89+ [2],
90+ );
91+ assert.deepEqual(searchLog(stamped, "2026-10-12"), []);
92+ assert.deepEqual(searchLog(stamped, "32m"), []);
93+ assert.deepEqual(splitStamp("2026-10-12T09:41:07Z text"), { at: "2026-10-12T09:41:07Z", rest: "text" });
94+ assert.deepEqual(splitStamp("2026-10-12 not a stamp"), { rest: "2026-10-12 not a stamp" });
95+ assert.deepEqual(classify("##[warning]plain"), { kind: "warning", text: "plain" });
96+ assert.equal(lastStamp(stamped), "2026-10-12T09:41:10.0000000Z");
97+ assert.equal(lastStamp("no stamps\n"), undefined);
98+});
+47−9
55
66 import type { JobLogText } from "@g1t/contracts";
77
8+import { stripAnsi } from "./ansi.ts";
9+
810 export type LineKind = "text" | "error" | "warning" | "notice" | "debug" | "command";
9−export type Line = { kind: LineKind; text: string };
11+/**
12+ * A line: its kind and its text, plain (what search reads). `at` is when
13+ * the runner wrote it, from the time GitHub's logs stamp at the start of
14+ * every line; `ansi` is its text with the colour codes it came with, when
15+ * it had any.
16+ */
17+export type Line = { kind: LineKind; text: string; at?: string; ansi?: string };
1018 export type Block =
1119 | { kind: "line"; line: Line; number: number }
12− | { kind: "group"; title: string; lines: { line: Line; number: number }[] };
20+ | { kind: "group"; title: string; lines: { line: Line; number: number }[]; at?: string };
21+
22+/** The time GitHub's logs stamp at the start of a line: `2026-10-12T09:41:07.1234567Z `. */
23+const STAMP = /^(\d{4}-\d\d-\d\dT\d\d:\d\d:\d\d(?:\.\d+)?Z) /;
24+
25+/** A line's stamped time and the rest of it; no time for a line without one (a log from before). */
26+export function splitStamp(raw: string): { at?: string; rest: string } {
27+ const found = STAMP.exec(raw);
28+ return found ? { at: found[1], rest: raw.slice(found[0].length) } : { rest: raw };
29+}
30+
31+/** The time of a log's last stamped line, if it has one. */
32+export function lastStamp(text: string): string | undefined {
33+ let end = text.length;
34+ while (end > 0) {
35+ const start = text.lastIndexOf("\n", end - 1);
36+ const at = splitStamp(text.slice(start + 1, end)).at;
37+ if (at) return at;
38+ end = start;
39+ }
40+ return undefined;
41+}
42+
43+function lineOf(kind: LineKind, rest: string, at: string | undefined): Line {
44+ const out: Line = { kind, text: stripAnsi(rest) };
45+ if (at) out.at = at;
46+ if (out.text !== rest) out.ansi = rest;
47+ return out;
48+}
1349
14−export function classify(raw: string): Line | "group-end" | { group: string } {
15− if (raw.startsWith("##[group]")) return { group: raw.slice(9) };
50+export function classify(stamped: string): Line | "group-end" | { group: string; at?: string } {
51+ const { at, rest: raw } = splitStamp(stamped);
52+ if (raw.startsWith("##[group]")) return at ? { group: stripAnsi(raw.slice(9)), at } : { group: stripAnsi(raw.slice(9)) };
1653 if (raw.startsWith("##[endgroup]")) return "group-end";
1754 for (const kind of ["error", "warning", "notice", "debug"] as const) {
18− if (raw.startsWith(`##[${kind}]`)) return { kind, text: raw.slice(kind.length + 4) };
55+ if (raw.startsWith(`##[${kind}]`)) return lineOf(kind, raw.slice(kind.length + 4), at);
1956 }
20− if (raw.startsWith("[command]")) return { kind: "command", text: raw.slice(9) };
21− return { kind: "text", text: raw };
57+ if (raw.startsWith("[command]")) return lineOf("command", raw.slice(9), at);
58+ return lineOf("text", raw, at);
2259 }
2360
2461 /** Lines into blocks: plain lines, and groups that fold. Lines are numbered from 1, group markers aside. */
2663 const out: Block[] = [];
2764 let group: Extract<Block, { kind: "group" }> | null = null;
2865 let number = 0;
29− for (const raw of text.split("\n")) {
66+ // A log ends with a newline; nothing follows the last one.
67+ for (const raw of (text.endsWith("\n") ? text.slice(0, -1) : text).split("\n")) {
3068 if (raw === "" && number === 0) continue;
3169 const line = classify(raw);
3270 if (line === "group-end") {
3472 continue;
3573 }
3674 if ("group" in line) {
37− group = { kind: "group", title: line.group, lines: [] };
75+ group = line.at ? { kind: "group", title: line.group, lines: [], at: line.at } : { kind: "group", title: line.group, lines: [] };
3876 out.push(group);
3977 continue;
4078 }
+61−0
1+import assert from "node:assert/strict";
2+import { test } from "node:test";
3+
4+import { FIRST_RETRY_MS, IDLE_POLL_MS, MAX_RETRY_MS, QUIET_AFTER_MS, RUNNING_POLL_MS, elapsed, nextPoll, quietWords, retryAfterMs } from "./log-poll.ts";
5+
6+const live = { failures: 0, live: true, running: true };
7+
8+test("a live job is asked every second while a step runs, less often while none does", () => {
9+ assert.deepEqual(nextPoll({ ok: true, done: false, full: false }, live), { delayMs: RUNNING_POLL_MS, failures: 0 });
10+ assert.deepEqual(nextPoll({ ok: true, done: false, full: false }, { ...live, running: false }), { delayMs: IDLE_POLL_MS, failures: 0 });
11+ // A full page: the rest at once.
12+ assert.deepEqual(nextPoll({ ok: true, done: false, full: true }, live), { delayMs: 0, failures: 0 });
13+ // Done, or shown as finished: no more.
14+ assert.deepEqual(nextPoll({ ok: true, done: true, full: false }, live), { delayMs: null, failures: 0 });
15+ assert.deepEqual(nextPoll({ ok: true, done: false, full: false }, { ...live, live: false }), { delayMs: null, failures: 0 });
16+});
17+
18+test("a failed answer is tried again, waiting longer each time, never stopping a live log", () => {
19+ let failures = 0;
20+ const waits: (number | null)[] = [];
21+ for (let i = 0; i < 8; i++) {
22+ const next = nextPoll({ ok: false, status: 503 }, { ...live, failures });
23+ failures = next.failures;
24+ waits.push(next.delayMs);
25+ }
26+ assert.deepEqual(waits, [FIRST_RETRY_MS, 4000, 8000, 16_000, MAX_RETRY_MS, MAX_RETRY_MS, MAX_RETRY_MS, MAX_RETRY_MS]);
27+ // An answer resets it.
28+ assert.deepEqual(nextPoll({ ok: true, done: false, full: false }, { ...live, failures }), { delayMs: RUNNING_POLL_MS, failures: 0 });
29+ // The network failing is a failure like any other.
30+ assert.deepEqual(nextPoll({ ok: false }, live), { delayMs: FIRST_RETRY_MS, failures: 1 });
31+});
32+
33+test("a 429 waits as long as Retry-After says; a 404 stops; a finished job's last fetch gives up", () => {
34+ assert.deepEqual(nextPoll({ ok: false, status: 429, retryAfterMs: 20_000 }, live), { delayMs: 20_000, failures: 1 });
35+ assert.deepEqual(nextPoll({ ok: false, status: 429, retryAfterMs: 500 }, live), { delayMs: FIRST_RETRY_MS, failures: 1 });
36+ assert.deepEqual(nextPoll({ ok: false, status: 429, retryAfterMs: 3_600_000 }, live), { delayMs: 2 * MAX_RETRY_MS, failures: 1 });
37+ assert.deepEqual(nextPoll({ ok: false, status: 404 }, live), { delayMs: null, failures: 1 });
38+ const finished = { failures: 4, live: false, running: false };
39+ assert.deepEqual(nextPoll({ ok: false, status: 500 }, finished), { delayMs: null, failures: 5 });
40+ assert.equal(nextPoll({ ok: false, status: 500 }, { ...finished, failures: 0 }).delayMs, FIRST_RETRY_MS);
41+});
42+
43+test("a quiet step says for how long it has printed nothing", () => {
44+ const start = Date.parse("2026-10-12T10:00:00Z");
45+ assert.equal(quietWords(start, null, start + 130_000), "Running · no output yet, 2m 10s");
46+ assert.equal(quietWords(null, null, start), "Running · no output yet");
47+ // Output a moment ago: nothing to say.
48+ assert.equal(quietWords(start, start + 60_000, start + 65_000), null);
49+ assert.equal(quietWords(start, start + 60_000, start + 60_000 + QUIET_AFTER_MS), "Running · no output for 10s");
50+ assert.equal(quietWords(start, start, start + 3_725_000), "Running · no output for 1h 2m");
51+ assert.equal(elapsed(-5), "0s");
52+});
53+
54+test("Retry-After reads as seconds or as a date", () => {
55+ assert.equal(retryAfterMs("12"), 12_000);
56+ assert.equal(retryAfterMs(null), undefined);
57+ assert.equal(retryAfterMs("soon"), undefined);
58+ const now = Date.parse("2026-10-12T10:00:00Z");
59+ assert.equal(retryAfterMs("Mon, 12 Oct 2026 10:00:30 GMT", now), 30_000);
60+ assert.equal(retryAfterMs("Mon, 12 Oct 2026 09:00:00 GMT", now), 0);
61+});
+83−0
1+/**
2+ * When a job's page asks for more of its log (components/actions.tsx,
3+ * `useJobLog`): about every second while a step is running, every few
4+ * seconds while the job waits between steps or for a machine, and, when
5+ * an answer fails (a 429, a 5xx, the network), again after a wait that
6+ * doubles up to half a minute, or as long as `Retry-After` says. Nothing
7+ * stops it for good but the job finishing or being gone.
8+ */
9+
10+/** While a step is running. */
11+export const RUNNING_POLL_MS = 1000;
12+/** While the job is live but no step is running: queued, starting, between steps. */
13+export const IDLE_POLL_MS = 3000;
14+/** The first wait after a failure, doubled after each one that follows. */
15+export const FIRST_RETRY_MS = 2000;
16+/** The longest wait between tries after failures. */
17+export const MAX_RETRY_MS = 30_000;
18+/** A finished job's last fetch is tried this many times before it gives up. */
19+export const FINISHED_TRIES = 5;
20+
21+export type PollAnswer =
22+ /** An answer: whether the job is done, and whether the page was full (more is waiting). */
23+ | { ok: true; done: boolean; full: boolean }
24+ /** No answer: its status, if there was one, and its `Retry-After` in milliseconds. */
25+ | { ok: false; status?: number; retryAfterMs?: number };
26+
27+export type PollState = {
28+ /** Failures in a row so far. */
29+ failures: number;
30+ /** Whether the page shows the job as still going. */
31+ live: boolean;
32+ /** Whether one of its steps is running now. */
33+ running: boolean;
34+};
35+
36+/** How long to wait before the next fetch, or null to stop; and the failures in a row after this answer. */
37+export function nextPoll(answer: PollAnswer, state: PollState): { delayMs: number | null; failures: number } {
38+ if (answer.ok) {
39+ if (answer.full) return { delayMs: 0, failures: 0 };
40+ if (answer.done || !state.live) return { delayMs: null, failures: 0 };
41+ return { delayMs: state.running ? RUNNING_POLL_MS : IDLE_POLL_MS, failures: 0 };
42+ }
43+ const failures = state.failures + 1;
44+ // The job is not there (deleted, or the repository is gone): nothing to wait for.
45+ if (answer.status === 404) return { delayMs: null, failures };
46+ if (!state.live && failures >= FINISHED_TRIES) return { delayMs: null, failures };
47+ const backoff = Math.min(MAX_RETRY_MS, FIRST_RETRY_MS * 2 ** (failures - 1));
48+ const asked = answer.retryAfterMs !== undefined ? Math.min(answer.retryAfterMs, 2 * MAX_RETRY_MS) : 0;
49+ return { delayMs: Math.max(backoff, asked), failures };
50+}
51+
52+/** How long a running step may print nothing before its log says how long it has been quiet. */
53+export const QUIET_AFTER_MS = 10_000;
54+
55+/** `45s`, `2m 10s`, `1h 5m`, as the run's page counts time. */
56+export function elapsed(ms: number): string {
57+ const seconds = Math.max(0, Math.round(ms / 1000));
58+ if (seconds < 60) return `${seconds}s`;
59+ const minutes = Math.floor(seconds / 60);
60+ if (minutes < 60) return `${minutes}m ${seconds % 60}s`;
61+ return `${Math.floor(minutes / 60)}h ${minutes % 60}m`;
62+}
63+
64+/**
65+ * What a running step's log says under its last line: that nothing has
66+ * come yet, and for how long, or, once it has gone quiet for a while
67+ * (a build that prints nothing as it links, a download), for how long it
68+ * has printed nothing. Null while output is flowing. Times in ms.
69+ */
70+export function quietWords(started: number | null, lastOutput: number | null, now: number): string | null {
71+ if (lastOutput === null) return started === null ? "Running · no output yet" : `Running · no output yet, ${elapsed(now - started)}`;
72+ if (now - lastOutput < QUIET_AFTER_MS) return null;
73+ return `Running · no output for ${elapsed(now - lastOutput)}`;
74+}
75+
76+/** `Retry-After` in milliseconds: seconds, or an HTTP date. */
77+export function retryAfterMs(header: string | null, now = Date.now()): number | undefined {
78+ if (!header) return undefined;
79+ const seconds = Number(header.trim());
80+ if (Number.isFinite(seconds) && seconds >= 0) return seconds * 1000;
81+ const at = Date.parse(header);
82+ return Number.isFinite(at) ? Math.max(0, at - now) : undefined;
83+}
+190−29
11 import {
22 AlertTriangle,
3+ ArrowDown,
34 Bug,
45 Check,
56 ChevronDown,
67 ChevronRight,
8+ Clock,
79 Cloud,
810 Download,
911 FileCode,
2729 X,
2830 XCircle,
2931 } from "lucide-react";
30−import { type ReactNode, useEffect, useRef, useState } from "react";
32+import { type ReactNode, type Ref, type RefObject, useEffect, useLayoutEffect, useMemo, useRef, useState } from "react";
3133 import { Form, Link, useLoaderData, useSearchParams } from "react-router";
3234
3335 import { type Annotation, type EnvironmentReviewer, type Job, type JobSummary, type PendingDeployment, type RunApproval, type RunAttempt, type StepState, isManagedWorkflow } from "@g1t/contracts";
3436
3537 import type { Route } from "./+types/actions-run";
3638 import { page } from "../../lib/meta";
37−import { Duration, LogText, Notes, StatusIcon, shortRef, standingWord, useJobLog } from "../../components/actions";
39+import { Duration, LogText, Notes, StatusIcon, duration, shortRef, standingWord, useJobLog, useNow } from "../../components/actions";
3840 import { Markdown } from "../../components/markdown";
3941 import { RunGraph } from "../../components/run-graph";
4042 import { DetailsDisclosure } from "../../components/details-disclosure";
4749 import { DropdownMenu, DropdownMenuContent, DropdownMenuItem, DropdownMenuTrigger } from "../../components/ui/dropdown-menu";
4850 import { Hint } from "../../components/ui/hint";
4951 import { useWorkflowReason } from "../../components/mirror";
50−import { searchLog } from "../../lib/log-lines";
52+import { lastStamp, searchLog } from "../../lib/log-lines";
53+import { quietWords } from "../../lib/log-poll";
5154 import { listArtifacts, withLegacyArtifacts } from "../../lib/run-artifacts.server";
5255 import { expiresIn, formatBytes, legacyArtifactsWorthAsking } from "../../lib/run-artifacts";
5356 import { actions } from "../../lib/services.server";
141144 defaultOpen,
142145 query = "",
143146 matches = 0,
147+ timestamps = false,
148+ lastOutput = null,
149+ now,
150+ end,
144151 }: {
145152 step: StepState;
146153 text: string | undefined;
148155 /** A search of the job's log: only its matching lines are shown. */
149156 query?: string;
150157 matches?: number;
158+ timestamps?: boolean;
159+ /** When the step last printed something, in ms: its last line's time, or when its last chunk arrived. */
160+ lastOutput?: number | null;
161+ /** Now, ticking while the job runs, for a running step's times. */
162+ now: number;
163+ /** Marks the end of the running step's log, for following it. */
164+ end?: Ref<HTMLDivElement>;
151165 }) {
166+ const running = step.status === "in_progress";
167+ const quiet = running && !query ? quietWords(step.startedAt ? new Date(step.startedAt).getTime() : null, lastOutput, now) : null;
152168 return (
153169 <details className="group border-t border-line first:border-t-0" open={defaultOpen}>
154170 <summary className="flex min-h-11 cursor-pointer list-none items-center gap-2.5 px-3 py-2 text-sm hover:bg-raised/40 sm:min-h-0 sm:px-4">
160176 {matches} {matches === 1 ? "line" : "lines"}
161177 </span>
162178 )}
163− <Duration className="ml-auto shrink-0 font-mono text-xs text-faint" start={step.startedAt} end={step.finishedAt} />
179+ <span className="ml-auto shrink-0 font-mono text-xs text-faint" suppressHydrationWarning>
180+ {step.startedAt ? duration(step.startedAt, step.finishedAt ?? (running ? new Date(now).toISOString() : null)) : ""}
181+ </span>
164182 </summary>
165183 <div className="border-t border-line bg-bg/60">
166− {text === undefined ? (
167− <p className="px-4 py-2 text-xs text-faint">{step.status === "queued" ? "Not started." : step.conclusion === "skipped" ? "Skipped." : "No output yet."}</p>
184+ {text === undefined && !running ? (
185+ <p className="px-4 py-2 text-xs text-faint">{step.status === "queued" ? "Not started." : step.conclusion === "skipped" ? "Skipped." : "No output."}</p>
168186 ) : (
169− <LogText text={text} query={query} />
187+ text !== undefined && <LogText text={text} query={query} timestamps={timestamps} />
188+ )}
189+ {quiet && (
190+ <p className="flex items-center gap-2 px-4 py-2 font-mono text-xs text-muted" aria-live="polite" suppressHydrationWarning>
191+ <span className="size-1.5 shrink-0 animate-pulse rounded-full bg-warn" aria-hidden />
192+ {quiet}
193+ </p>
170194 )}
195+ {running && <div ref={end} aria-hidden className="h-px" />}
171196 </div>
172197 </details>
173198 );
174199 }
175200
201+/** Whether the viewer wants each log line's time shown, kept in this browser. */
202+function useTimestamps(): [boolean, (on: boolean) => void] {
203+ const [on, setOn] = useState(false);
204+ useEffect(() => {
205+ try {
206+ setOn(window.localStorage.getItem(TIMESTAMPS_KEY) === "on");
207+ } catch {
208+ // Storage refused (a private window): off.
209+ }
210+ }, []);
211+ const set = (next: boolean) => {
212+ setOn(next);
213+ try {
214+ if (next) window.localStorage.setItem(TIMESTAMPS_KEY, "on");
215+ else window.localStorage.removeItem(TIMESTAMPS_KEY);
216+ } catch {
217+ // It lasts until the page is left.
218+ }
219+ };
220+ return [on, set];
221+}
222+
223+const TIMESTAMPS_KEY = "g1t:actions:log-timestamps";
224+
176225 /**
226+ * Following the running step's log as it grows, as GitHub does: while the
227+ * end of it is in view, new lines keep it in view; once the viewer
228+ * scrolls up, it stays put and `behind` says there is more below.
229+ */
230+function useFollow(running: number | null, grew: unknown): { end: RefObject<HTMLDivElement | null>; behind: boolean; jump: () => void } {
231+ const end = useRef<HTMLDivElement | null>(null);
232+ const following = useRef(false);
233+ const [behind, setBehind] = useState(false);
234+ // Where the end of the log is: folded away (a closed step draws nothing),
235+ // on screen or nearly (the viewer is reading the latest), or below.
236+ const where = (): "folded" | "here" | "below" => {
237+ const box = end.current?.getBoundingClientRect();
238+ if (!box || (box.width === 0 && box.height === 0)) return "folded";
239+ return box.top <= window.innerHeight + 160 ? "here" : "below";
240+ };
241+ useEffect(() => {
242+ if (running === null) {
243+ following.current = false;
244+ setBehind(false);
245+ return;
246+ }
247+ // The viewer moving decides: at the end, follow; scrolled up, stay.
248+ const moved = () => {
249+ const at = where();
250+ following.current = at === "here";
251+ setBehind(at === "below");
252+ };
253+ // A step folded or opened moves nothing the viewer chose; it only
254+ // changes whether there is anything below to jump to.
255+ const toggled = () => {
256+ const at = where();
257+ if (at === "folded") following.current = false;
258+ setBehind(at === "below");
259+ };
260+ window.addEventListener("scroll", moved, { passive: true });
261+ window.addEventListener("resize", toggled);
262+ document.addEventListener("toggle", toggled, true);
263+ return () => {
264+ window.removeEventListener("scroll", moved);
265+ window.removeEventListener("resize", toggled);
266+ document.removeEventListener("toggle", toggled, true);
267+ };
268+ }, [running]);
269+ useLayoutEffect(() => {
270+ if (running === null || !end.current) return;
271+ if (following.current && where() !== "folded") {
272+ end.current.scrollIntoView({ block: "end" });
273+ return;
274+ }
275+ // Not following: once there is a log and its end is on screen, follow
276+ // from here; a log that arrives longer than the screen is left at its
277+ // top rather than the page jumping to its end.
278+ const at = where();
279+ if (grew && at === "here") following.current = true;
280+ setBehind(at === "below");
281+ }, [grew, running]);
282+ const jump = () => {
283+ following.current = true;
284+ end.current?.scrollIntoView({ block: "end", behavior: "smooth" });
285+ };
286+ return { end, behind, jump };
287+}
288+
289+/**
177290 * Runs again, after asking whether with debug logging: the whole run, its
178291 * failed jobs, or one job (with the jobs that need it).
179292 */
359472
360473 function JobView({ job, base, rerun }: { job: Job; base: string; rerun: ReactNode }) {
361474 const live = job.status !== "completed";
362− const log = useJobLog(`${base}/actions/jobs/${job.id}/log`, live);
363− const [query, setQuery] = useState("");
364475 const failed = job.steps.find((s) => s.conclusion === "failure");
365476 const running = job.steps.find((s) => s.status === "in_progress");
477+ const { byStep: log, grewAt, retrying } = useJobLog(`${base}/actions/jobs/${job.id}/log`, live, Boolean(running));
478+ const [query, setQuery] = useState("");
479+ const [timestamps, setTimestamps] = useTimestamps();
480+ const now = useNow(live);
481+ const runningText = running ? log.get(running.number) : undefined;
482+ // The running step's log is followed while its end is in view, unless a
483+ // failed step is the one held open.
484+ const followed = !failed && running ? running.number : null;
485+ const { end, behind, jump } = useFollow(followed, runningText);
486+ // When the running step last printed: its last line's time, else when
487+ // its last chunk came.
488+ const lastOutput = useMemo(() => {
489+ if (!running) return null;
490+ const at = runningText ? lastStamp(runningText) : undefined;
491+ if (at) return new Date(at).getTime();
492+ return runningText ? (grewAt.get(running.number) ?? null) : null;
493+ }, [running, runningText, grewAt]);
366494 const searching = query.trim().length > 0;
367495 const setUp: StepState = {
368496 number: 0,
382510 <div className="flex flex-wrap items-center gap-3">
383511 <StatusIcon status={job.status} conclusion={job.conclusion} of="job" environment={job.environment} size={18} />
384512 <h3 className="text-base font-semibold">{job.name}</h3>
385− <span className="text-sm text-muted">
513+ <span className="min-w-0 text-sm text-muted">
386514 {job.cancelling ? "Cancelling: running its cleanup steps" : standingWord({ ...job, of: "job" })}
515+ {running && !job.cancelling && (
516+ <>
517+ {" · "}
518+ <span className="text-fg/85">{running.name}</span>
519+ </>
520+ )}
387521 {job.startedAt && (
388522 <>
389523 {" · "}
390− <Duration start={job.startedAt} end={job.finishedAt} />
524+ <span suppressHydrationWarning>{duration(job.startedAt, job.finishedAt ?? (live ? new Date(now).toISOString() : null))}</span>
391525 </>
392526 )}
527+ {retrying && <span className="text-warn"> · Reconnecting to the log…</span>}
393528 </span>
394529 <span className="ml-auto flex items-center gap-2">
395530 {rerun}
430565 </Card>
431566 )}
432567 {job.startedAt && (
433− <Card asChild radius="lg" className="flex items-center gap-2 px-3 py-1.5 text-sm focus-within:border-accent-dim">
434− <label>
435− <Search size={14} className="shrink-0 text-faint" />
436− <input
437− type="search"
438− value={query}
439− onChange={(event) => setQuery(event.target.value)}
440− placeholder="Search logs"
441− aria-label={`Search the log of ${job.name}`}
442− className="min-w-0 grow bg-transparent outline-none placeholder:text-faint"
443− />
444− {searching && (
445− <span className="shrink-0 text-xs text-muted" aria-live="polite">
446− {total} {total === 1 ? "line" : "lines"}
447− </span>
448− )}
449− </label>
450− </Card>
568+ <div className="flex items-center gap-2">
569+ <Card asChild radius="lg" className="flex min-w-0 grow items-center gap-2 px-3 py-1.5 text-sm focus-within:border-accent-dim">
570+ <label>
571+ <Search size={14} className="shrink-0 text-faint" />
572+ <input
573+ type="search"
574+ value={query}
575+ onChange={(event) => setQuery(event.target.value)}
576+ placeholder="Search logs"
577+ aria-label={`Search the log of ${job.name}`}
578+ className="min-w-0 grow bg-transparent outline-none placeholder:text-faint"
579+ />
580+ {searching && (
581+ <span className="shrink-0 text-xs text-muted" aria-live="polite">
582+ {total} {total === 1 ? "line" : "lines"}
583+ </span>
584+ )}
585+ </label>
586+ </Card>
587+ <Hint label={timestamps ? "Hide timestamps" : "Show timestamps"}>
588+ <Button
589+ variant="outline"
590+ size="icon-sm"
591+ aria-pressed={timestamps}
592+ aria-label="Show timestamps"
593+ onClick={() => setTimestamps(!timestamps)}
594+ className="aria-pressed:border-accent-dim aria-pressed:text-fg"
595+ >
596+ <Clock size={14} />
597+ </Button>
598+ </Hint>
599+ </div>
451600 )}
452601 <Card className="overflow-hidden">
453602 {searching && steps.length === 0 && <p className="px-4 py-3 text-sm text-muted">No line of this job's log holds “{query.trim()}”.</p>}
460609 defaultOpen={searching || (step.number !== 0 && step.number === (failed ?? running)?.number)}
461610 query={searching ? query : ""}
462611 matches={matches}
612+ timestamps={timestamps}
613+ now={now}
614+ lastOutput={step.number === running?.number ? lastOutput : null}
615+ end={step.number === followed ? end : undefined}
463616 />
464617 ))}
465618 </Card>
619+ {behind && !searching && (
620+ <div className="pointer-events-none sticky bottom-4 z-10 flex justify-center">
621+ <Button variant="secondary" size="sm" onClick={jump} className="pointer-events-auto shadow-md ring-1 ring-line">
622+ <ArrowDown size={14} />
623+ Jump to latest
624+ </Button>
625+ </div>
626+ )}
466627 </section>
467628 );
468629 }
+63−11
2828 /// The largest cache entry, compressed (`g1t_contracts::actions::CACHE_MAX_ENTRY_BYTES`).
2929 const MAX_CACHE_ENTRY: u64 = 2 * 1024 * 1024 * 1024;
3030
31+/// How often a long transfer says how far it has got.
32+const PROGRESS_EVERY: Duration = Duration::from_secs(5);
33+
34+/// A transfer's progress as GitHub's cache action words it:
35+/// `Received 46137344 of 523190823 (8.8%), 43.9 MBs/sec`.
36+fn progress(verb: &str, done: u64, total: Option<u64>, took: Duration) -> String {
37+ let rate = done as f64 / 1_048_576.0 / took.as_secs_f64().max(0.001);
38+ match total.filter(|total| *total > 0) {
39+ Some(total) => format!("{verb} {done} of {total} ({:.1}%), {rate:.1} MBs/sec", done as f64 * 100.0 / total as f64),
40+ None => format!("{verb} {done} bytes, {rate:.1} MBs/sec"),
41+ }
42+}
43+
3144 fn lines(text: &str) -> Vec<String> {
3245 text.lines().map(str::trim).filter(|line| !line.is_empty() && !line.starts_with('#')).map(str::to_owned).collect()
3346 }
6275 Err(error) => return Err(error.to_string()),
6376 };
6477 let matched = response.header("x-g1t-key").map(str::to_owned).unwrap_or_default();
65− let mut out = std::fs::File::create(file).map_err(|e| e.to_string())?;
66− std::io::copy(&mut response.into_reader().take(MAX_CACHE_ENTRY + 1024), &mut out).map_err(|e| e.to_string())?;
78+ let total = response.header("content-length").and_then(|n| n.parse::<u64>().ok());
79+ let mut out = std::io::BufWriter::new(std::fs::File::create(file).map_err(|e| e.to_string())?);
80+ self.receive(&mut response.into_reader().take(MAX_CACHE_ENTRY + 1024), total, |bytes| out.write_all(bytes))?;
81+ out.flush().map_err(|e| e.to_string())?;
6782 Ok(Some(matched))
6883 }
6984
85+ /// Reads a download to its end, handing `each` every piece, and says
86+ /// how it is going every few seconds as GitHub's cache and artifact
87+ /// actions do (`Received 46137344 of 523190823 (8.8%), 43.9 MBs/sec`),
88+ /// so a long download is never a silent step. Its total in bytes.
89+ fn receive(&mut self, reader: &mut dyn Read, total: Option<u64>, mut each: impl FnMut(&[u8]) -> std::io::Result<()>) -> Result<u64, String> {
90+ let started = Instant::now();
91+ let mut told = Instant::now();
92+ let mut received = 0u64;
93+ let mut buffer = vec![0u8; 256 * 1024];
94+ loop {
95+ let n = reader.read(&mut buffer).map_err(|e| e.to_string())?;
96+ if n == 0 {
97+ break;
98+ }
99+ each(&buffer[..n]).map_err(|e| e.to_string())?;
100+ received += n as u64;
101+ if told.elapsed() >= PROGRESS_EVERY {
102+ told = Instant::now();
103+ self.log.line(&progress("Received", received, total, started.elapsed()));
104+ }
105+ self.log.tick();
106+ }
107+ Ok(received)
108+ }
109+
70110 /// Saves `file` as the cache entry `key`, in parts. `Ok(false)` when
71111 /// the key is already cached.
72112 fn upload_cache(&mut self, key: &str, version: &str, file: &Path) -> Result<bool, String> {
110150 /// Sends `file` in parts of `part_bytes`; each part's number and etag.
111151 fn send_parts(&mut self, base: &str, upload: &str, file: &Path, part_bytes: u64) -> Result<Vec<serde_json::Value>, String> {
112152 let mut reader = std::fs::File::open(file).map_err(|e| e.to_string())?;
153+ let size = reader.metadata().map(|m| m.len()).unwrap_or(0);
154+ let (started, mut told, mut sent) = (Instant::now(), Instant::now(), 0u64);
113155 let mut parts = Vec::new();
114156 let mut buffer = vec![0u8; part_bytes as usize];
115157 for number in 1u32.. {
137179 }
138180 };
139181 parts.push(serde_json::json!({ "part": number, "etag": answer["etag"] }));
182+ sent += filled as u64;
140183 if filled < buffer.len() {
141184 break;
142185 }
186+ // More to send: say how far it has got, as a download does.
187+ if told.elapsed() >= PROGRESS_EVERY {
188+ told = Instant::now();
189+ self.log.line(&progress("Sent", sent, Some(size), started.elapsed()));
190+ }
191+ self.log.tick();
143192 }
144193 Ok(parts)
145194 }
339388 Err(error) => return Err(error.to_string()),
340389 };
341390 let format = response.header("x-g1t-format").map(str::to_owned).unwrap_or_else(|| artifact.format.clone());
391+ let total = response.header("content-length").and_then(|n| n.parse::<u64>().ok()).or(Some(artifact.size));
342392 let mut reader = response.into_reader();
343393 let mut out = std::io::BufWriter::new(std::fs::File::create(file).map_err(|e| e.to_string())?);
344394 let mut hasher = Sha256::new();
345− let mut buffer = vec![0u8; 256 * 1024];
346− loop {
347− let n = reader.read(&mut buffer).map_err(|e| e.to_string())?;
348− if n == 0 {
349− break;
350− }
351− hasher.update(&buffer[..n]);
352− out.write_all(&buffer[..n]).map_err(|e| e.to_string())?;
353− }
395+ self.receive(&mut reader, total, |bytes| {
396+ hasher.update(bytes);
397+ out.write_all(bytes)
398+ })?;
354399 out.flush().map_err(|e| e.to_string())?;
355400 let got = hex::encode(hasher.finalize());
356401 if let Some(expected) = artifact.digest.as_deref().map(|d| d.trim_start_matches("sha256:"))
9741019 }
9751020
9761021 #[test]
1022+ fn transfers_say_how_far_they_have_got_as_githubs_do() {
1023+ assert_eq!(progress("Received", 46_137_344, Some(523_190_823), Duration::from_secs(1)), "Received 46137344 of 523190823 (8.8%), 44.0 MBs/sec");
1024+ assert_eq!(progress("Sent", 1_048_576, None, Duration::from_secs(2)), "Sent 1048576 bytes, 0.5 MBs/sec");
1025+ assert_eq!(progress("Received", 10, Some(0), Duration::ZERO), "Received 10 bytes, 0.0 MBs/sec");
1026+ }
1027+
1028+ #[test]
9771029 fn keys_are_encoded_and_names_checked() {
9781030 assert_eq!(urlencode("Linux-node-abc/1 2"), "Linux-node-abc%2F1%202");
9791031 assert!(check_name("coverage report").is_ok());
+294−23
110110 pub(crate) job_context: Map<String, Value>,
111111 /// Docker actions' images built in this job.
112112 pub(crate) built_actions: containers::Built,
113+ /// `RUNNER_TRACKING_ID`, which every process a step starts inherits.
114+ tracking_id: String,
113115 }
114116
115117 fn text_map(value: Option<&Value>) -> BTreeMap<String, String> {
167169 format!("Run {first}")
168170 }
169171
172+/// What GitHub's runner sets on a step itself, which its `env:` list leaves out.
173+const RUNNER_SET: [&str; 2] = ["GITHUB_ACTION", "GITHUB_ACTION_PATH"];
174+
175+/// The step's variables as GitHub lists them under `env:`: each name and
176+/// its value (masked later, as every line is), a value of several lines
177+/// with the rest indented beneath it.
178+fn env_lines(env: &BTreeMap<String, String>) -> Vec<String> {
179+ let listed: Vec<(&String, &String)> = env.iter().filter(|(name, _)| !RUNNER_SET.contains(&name.as_str())).collect();
180+ if listed.is_empty() {
181+ return Vec::new();
182+ }
183+ let mut lines = vec!["env:".to_owned()];
184+ for (name, value) in listed {
185+ let mut parts = value.split('\n');
186+ lines.push(format!(" {name}: {}", parts.next().unwrap_or_default()));
187+ lines.extend(parts.map(|part| format!(" {part}")));
188+ }
189+ lines
190+}
191+
192+/// How GitHub's runner opens a `run` step, in a group that starts folded:
193+/// `Run` and the script's first line, the whole script (in cyan, as
194+/// GitHub draws it), the shell it runs in and the step's variables.
195+pub(crate) fn script_header(script: &str, shell: &str, env: &BTreeMap<String, String>) -> Vec<String> {
196+ let first = script.lines().find(|line| !line.trim().is_empty()).unwrap_or_default().trim();
197+ let mut lines = vec![format!("##[group]Run {first}")];
198+ lines.extend(script.trim_matches(['\n', '\r']).lines().map(|line| format!("\u{1b}[36;1m{line}\u{1b}[0m")));
199+ lines.push(format!("shell: {shell}"));
200+ lines.extend(env_lines(env));
201+ lines.push("##[endgroup]".into());
202+ lines
203+}
204+
205+/// How GitHub's runner opens a `uses:` step: `Run` and the action, its
206+/// inputs under `with:` and the step's variables under `env:`.
207+pub(crate) fn uses_header(uses: &str, with: &BTreeMap<String, String>, env: &BTreeMap<String, String>) -> Vec<String> {
208+ let mut lines = vec![format!("##[group]Run {uses}")];
209+ if !with.is_empty() {
210+ lines.push("with:".into());
211+ for (name, value) in with {
212+ let mut parts = value.trim_end_matches('\n').split('\n');
213+ lines.push(format!(" {name}: {}", parts.next().unwrap_or_default()));
214+ lines.extend(parts.map(|part| format!(" {part}")));
215+ }
216+ }
217+ lines.extend(env_lines(env));
218+ lines.push("##[endgroup]".into());
219+ lines
220+}
221+
170222 impl Job {
223+ /// A shell's whole path, found on the step's `PATH` as GitHub's runner
224+ /// shows it (`/usr/bin/bash`), or its name when it is not there.
225+ fn program_path(&self, program: &str) -> String {
226+ if Path::new(program).is_absolute() {
227+ return program.to_owned();
228+ }
229+ let path = self.base_env.get("PATH").cloned().unwrap_or_default();
230+ let dirs = self.path_prepend.iter().map(String::as_str).chain(path.split(paths::PATH_SEPARATOR));
231+ let names: Vec<String> = if cfg!(windows) { vec![format!("{program}.exe"), program.to_owned()] } else { vec![program.to_owned()] };
232+ dirs.filter(|dir| !dir.is_empty())
233+ .flat_map(|dir| names.iter().map(move |name| Path::new(dir).join(name)))
234+ .find(|candidate| candidate.is_file())
235+ .map_or_else(|| program.to_owned(), |found| found.display().to_string())
236+ }
237+
171238 pub(crate) fn base_env_value(&self, name: &str) -> Option<String> {
172239 self.base_env.get(name).cloned()
173240 }
364431 return (false, BTreeMap::new(), BTreeMap::new());
365432 }
366433 };
434+ // GitHub's opening of a `run` step, folded: the script, the shell
435+ // it runs in (the program's whole path) and the step's variables.
436+ let shown_program = if self.container.is_some() { program.clone() } else { self.program_path(&program) };
437+ for line in script_header(script, &format!("{shown_program} {}", args.join(" ")), env) {
438+ self.log.line(&line);
439+ }
367440 let args: Vec<String> = args.iter().map(|a| a.replace("{0}", &paths::shown(&script_path))).collect();
368− self.log.line(&format!("shell: {program} {}", args.join(" ")));
369441 let dir = match working_directory {
370442 Some(dir) if Path::new(dir).is_absolute() => PathBuf::from(dir),
371443 Some(dir) => self.workspace.join(dir),
487559 String::new()
488560 }
489561 };
490− self.log.line(&format!("##[group]{title}"));
491− for line in script.lines() {
492− self.log.line(line);
493− }
494− self.log.line("##[endgroup]");
495562 let shell = step
496563 .get("shell")
497564 .map(expr::to_text)
749816 base_env.insert("HOME".into(), std::env::var("HOME").unwrap_or_else(|_| "/home/node".into()));
750817 base_env.extend(text_map(spec.get("variables")));
751818 base_env.insert("GITHUB_EVENT_PATH".into(), paths::shown(&temp.join("event.json")));
819+ // As GitHub's runner marks what a job starts, so "Complete job" finds
820+ // what its steps left running (process::orphans).
821+ let tracking_id = format!("github_{:016x}{:016x}", rand_id(), rand_id());
822+ base_env.insert("RUNNER_TRACKING_ID".into(), tracking_id.clone());
752823
753824 let mut contexts: Map<String, Value> = spec["contexts"].as_object().cloned().unwrap_or_default();
754825 contexts.insert("github".into(), spec["github"].clone());
787858 container: None,
788859 job_context: Map::new(),
789860 built_actions: containers::Built::new(),
861+ tracking_id,
790862 };
791863
792864 // The workflow's env reads github, secrets, inputs and vars; the job's
817889 }
818890 }
819891
892+/// What "Set up job" says of the runner and the machine it runs on.
893+#[derive(Default)]
894+pub(crate) struct Machine {
895+ pub(crate) version: String,
896+ pub(crate) self_hosted: bool,
897+ pub(crate) runner_name: String,
898+ /// `RUNNER_OS` and `RUNNER_ARCH`.
899+ pub(crate) os: String,
900+ pub(crate) arch: String,
901+ /// `/etc/os-release`, where there is one.
902+ pub(crate) os_release: Option<String>,
903+ /// `ImageOS` and `ImageVersion`, when the machine's image sets them.
904+ pub(crate) image: Option<(String, String)>,
905+ pub(crate) cpus: usize,
906+ pub(crate) memory_bytes: Option<u64>,
907+ /// The job token's permissions, by GitHub's names.
908+ pub(crate) permissions: Vec<(String, String)>,
909+}
910+
911+impl Machine {
912+ fn here(spec: &Value, base_env: &BTreeMap<String, String>) -> Machine {
913+ let variables = &spec["variables"];
914+ let text = |name: &str| variables[name].as_str().unwrap_or_default().to_owned();
915+ let self_hosted = variables["RUNNER_ENVIRONMENT"] == "self-hosted";
916+ let image = match (base_env.get("ImageOS"), base_env.get("ImageVersion")) {
917+ (None, None) => None,
918+ (os, version) => Some((os.cloned().unwrap_or_default(), version.cloned().unwrap_or_default())),
919+ };
920+ let permissions = spec
921+ .get("permissions")
922+ .and_then(Value::as_object)
923+ .map(|map| map.iter().map(|(name, access)| (name.clone(), expr::to_text(access))).collect())
924+ .unwrap_or_default();
925+ Machine {
926+ version: env!("CARGO_PKG_VERSION").to_owned(),
927+ self_hosted,
928+ runner_name: if self_hosted { text("RUNNER_NAME") } else { "g1t".to_owned() },
929+ os: text("RUNNER_OS"),
930+ arch: text("RUNNER_ARCH"),
931+ os_release: std::fs::read_to_string("/etc/os-release").ok(),
932+ image,
933+ cpus: std::thread::available_parallelism().map_or(1, usize::from),
934+ memory_bytes: memory_limit(
935+ std::fs::read_to_string("/sys/fs/cgroup/memory.max").ok().as_deref(),
936+ std::fs::read_to_string("/proc/meminfo").ok().as_deref(),
937+ ),
938+ permissions,
939+ }
940+ }
941+}
942+
943+/// The memory a job has: its cgroup's limit, else the machine's.
944+fn memory_limit(cgroup_max: Option<&str>, meminfo: Option<&str>) -> Option<u64> {
945+ let total = meminfo.and_then(|info| {
946+ info.lines().find_map(|line| line.strip_prefix("MemTotal:")).and_then(|rest| rest.trim().trim_end_matches("kB").trim().parse::<u64>().ok()).map(|kb| kb * 1024)
947+ });
948+ let limit = cgroup_max.and_then(|max| max.trim().parse::<u64>().ok());
949+ match (limit, total) {
950+ (Some(limit), Some(total)) => Some(limit.min(total)),
951+ (limit, total) => limit.or(total),
952+ }
953+}
954+
955+/// `pull-requests` as GitHub's log names it: `PullRequests`.
956+fn permission_title(name: &str) -> String {
957+ name.split(['-', '_'])
958+ .map(|word| {
959+ let mut chars = word.chars();
960+ chars.next().map(|first| first.to_ascii_uppercase().to_string() + chars.as_str()).unwrap_or_default()
961+ })
962+ .collect()
963+}
964+
965+/// GitHub's "Set up job", before the actions are downloaded: the runner's
966+/// version and name, the operating system, the image, the machine, what
967+/// the job's token may do and where its secrets come from.
968+pub(crate) fn setup_header(machine: &Machine) -> Vec<String> {
969+ let mut lines = vec![format!("Current runner version: '{}'", machine.version), format!("Runner name: '{}'", machine.runner_name)];
970+ lines.push("##[group]Operating System".into());
971+ let release = machine.os_release.as_deref().unwrap_or_default();
972+ let field = |key: &str| {
973+ release.lines().find_map(|line| line.strip_prefix(key).and_then(|rest| rest.strip_prefix('='))).map(|value| value.trim().trim_matches('"').to_owned()).filter(|v| !v.is_empty())
974+ };
975+ match field("NAME") {
976+ Some(name) => {
977+ lines.push(name);
978+ lines.extend(field("VERSION").or_else(|| field("VERSION_ID")));
979+ }
980+ None => lines.push(format!("{} {}", machine.os, machine.arch).trim().to_owned()),
981+ }
982+ lines.push("##[endgroup]".into());
983+ if machine.image.is_some() || !machine.self_hosted {
984+ lines.push("##[group]Runner Image".into());
985+ if let Some((os, version)) = &machine.image {
986+ if !os.is_empty() {
987+ lines.push(format!("Image: {os}"));
988+ }
989+ if !version.is_empty() {
990+ lines.push(format!("Version: {version}"));
991+ }
992+ }
993+ if !machine.self_hosted {
994+ lines.push("Included Software: Node 24, Python 3, Go, Rust".into());
995+ }
996+ lines.push("##[endgroup]".into());
997+ }
998+ lines.push("##[group]Machine".into());
999+ lines.push(if machine.self_hosted { "Self-hosted".into() } else { "Hosted by g1t".to_owned() });
1000+ lines.push(format!("Architecture: {}", machine.arch));
1001+ lines.push(format!("CPUs: {}", machine.cpus));
1002+ if let Some(bytes) = machine.memory_bytes {
1003+ let gib = bytes as f64 / (1024.0 * 1024.0 * 1024.0);
1004+ let shown = if (gib - gib.round()).abs() < 0.05 { format!("{}", gib.round()) } else { format!("{gib:.1}") };
1005+ lines.push(format!("Memory: {shown} GB"));
1006+ }
1007+ lines.push("##[endgroup]".into());
1008+ let granted: Vec<&(String, String)> = machine.permissions.iter().filter(|(_, access)| access != "none" && !access.is_empty()).collect();
1009+ if !granted.is_empty() {
1010+ lines.push("##[group]G1T_TOKEN Permissions".into());
1011+ lines.extend(granted.iter().map(|(name, access)| format!("{}: {access}", permission_title(name))));
1012+ lines.push("##[endgroup]".into());
1013+ }
1014+ lines.push("Secret source: Actions".into());
1015+ lines.push("Prepare workflow directory".into());
1016+ lines
1017+}
1018+
8201019 /// The job's `defaults.run`, its own over the workflow's.
8211020 fn run_defaults(spec: &Value) -> Map<String, Value> {
8221021 let mut defaults = spec["workflow"]["defaults"]["run"].as_object().cloned().unwrap_or_default();
8481047 job.report_steps();
8491048
8501049 job.log.step(0);
851− job.log.line(&format!("Job: {}", job.spec["name"].as_str().unwrap_or_default()));
852− let variables = &job.spec["variables"];
853− if variables["RUNNER_ENVIRONMENT"] == "self-hosted" {
854− let text = |name: &str| variables[name].as_str().unwrap_or_default().to_owned();
855− job.log.line(&format!("Runner: {}, self-hosted, {} {}", text("RUNNER_NAME"), text("RUNNER_OS"), text("RUNNER_ARCH")));
856− } else {
857− job.log.line("Runner: g1t, Linux X64 (Debian bookworm, Node 24, Python 3, Go, Rust)");
1050+ // GitHub's "Set up job": the runner, the machine, the token, then the
1051+ // actions the job uses.
1052+ for line in setup_header(&Machine::here(&job.spec, &job.base_env)) {
1053+ job.log.line(&line);
8581054 }
8591055 if let Some(Value::Object(matrix)) = job.contexts.get("matrix")
8601056 && !matrix.is_empty()
8611057 {
8621058 job.log.line(&format!("Matrix: {}", serde_json::to_string(matrix).unwrap_or_default()));
8631059 }
864− // What its G1T_TOKEN may do, as its `permissions:` gave it.
865− if let Some(Value::Object(permissions)) = job.spec.get("permissions").cloned() {
866− job.log.line("##[group]G1T_TOKEN permissions");
867− for (name, access) in &permissions {
868− if access.as_str() != Some("none") {
869− job.log.line(&format!("{name}: {}", access.as_str().unwrap_or_default()));
870− }
871− }
872− job.log.line("##[endgroup]");
873− }
8741060 if job.docker_hosted {
8751061 let registry = job.contexts["github"]["server_url"].as_str().and_then(crate::docker::engine::registry_host);
8761062 let token = job.contexts.get("secrets").and_then(|s| s.get("G1T_TOKEN")).map(expr::to_text).filter(|t| !t.is_empty());
8961082 job.step_names = names;
8971083 job.report_steps();
8981084 }
1085+ if prepared {
1086+ job.log.line(&format!("Complete job name: {}", job.spec["name"].as_str().unwrap_or_default()));
1087+ }
8991088 let containers_started = prepared && job.start_containers();
9001089 job.log.flush();
9011090
9811170 // The job's outputs, read now that every step has run.
9821171 let env = job.env_context(&frame);
9831172 let contexts = job.contexts_for(&frame, &env);
1173+ // GitHub's "Complete job": the job's outputs set, and whatever its
1174+ // steps left running stopped.
1175+ let number = job.step_names.len() as u32 + 1;
1176+ job.step_names.push("Complete job".into());
1177+ job.report_steps();
1178+ job.log.step(number);
1179+ job.log.step_state(number, "Complete job", "in_progress", None);
9841180 let mut outputs = Map::new();
9851181 if let Some(Value::Object(declared)) = job.spec["spec"].get("outputs") {
1182+ job.log.line("Evaluate and set job outputs");
9861183 for (name, value) in declared {
9871184 let value = job.with_scope(&contexts, |scope| expr::interpolate_value(value, scope)).unwrap_or(Value::Null);
1185+ job.log.line(&format!("Set output '{name}'"));
9881186 outputs.insert(name.clone(), Value::String(expr::to_text(&value)));
9891187 }
9901188 }
1189+ let outputs = job.log.withhold_secrets(&outputs);
1190+ job.log.line("Cleaning up orphan processes");
1191+ let orphans = process::orphans(&job.tracking_id);
1192+ for (pid, name) in &orphans {
1193+ job.log.line(&format!("Terminate orphan process: pid ({pid}) ({name})"));
1194+ }
1195+ process::kill_orphans(&orphans);
1196+ job.log.step_state(number, "Complete job", "completed", Some("success"));
9911197 // Cancelled, the job ends so however its cleanup went (and g1t holds
9921198 // to that whatever it is told).
9931199 let conclusion = if report::cancelled() {
10391245 use super::*;
10401246
10411247 #[test]
1248+ fn set_up_job_says_what_runs_the_job_as_github_does() {
1249+ let machine = Machine {
1250+ version: "0.2.0".into(),
1251+ runner_name: "g1t".into(),
1252+ os: "Linux".into(),
1253+ arch: "X64".into(),
1254+ os_release: Some("PRETTY_NAME=\"Debian GNU/Linux 12 (bookworm)\"\nNAME=\"Debian GNU/Linux\"\nVERSION_ID=\"12\"\nVERSION=\"12 (bookworm)\"\n".into()),
1255+ image: Some(("ubuntu24".into(), "20261005.1".into())),
1256+ cpus: 4,
1257+ memory_bytes: Some(12 * 1024 * 1024 * 1024),
1258+ permissions: vec![("contents".into(), "read".into()), ("id-token".into(), "none".into()), ("metadata".into(), "read".into()), ("pull-requests".into(), "write".into())],
1259+ ..Machine::default()
1260+ };
1261+ let text = setup_header(&machine).join("\n");
1262+ assert_eq!(
1263+ text,
1264+ "Current runner version: '0.2.0'\nRunner name: 'g1t'\n\
1265+ ##[group]Operating System\nDebian GNU/Linux\n12 (bookworm)\n##[endgroup]\n\
1266+ ##[group]Runner Image\nImage: ubuntu24\nVersion: 20261005.1\nIncluded Software: Node 24, Python 3, Go, Rust\n##[endgroup]\n\
1267+ ##[group]Machine\nHosted by g1t\nArchitecture: X64\nCPUs: 4\nMemory: 12 GB\n##[endgroup]\n\
1268+ ##[group]G1T_TOKEN Permissions\nContents: read\nMetadata: read\nPullRequests: write\n##[endgroup]\n\
1269+ Secret source: Actions\nPrepare workflow directory"
1270+ );
1271+ // A self-hosted machine without an image of GitHub's, or an os-release.
1272+ let own = Machine { version: "0.2.0".into(), self_hosted: true, runner_name: "build-box".into(), os: "macOS".into(), arch: "ARM64".into(), cpus: 8, ..Machine::default() };
1273+ let text = setup_header(&own).join("\n");
1274+ assert!(text.contains("Runner name: 'build-box'\n##[group]Operating System\nmacOS ARM64\n##[endgroup]\n##[group]Machine\nSelf-hosted"), "{text}");
1275+ assert!(!text.contains("Runner Image") && !text.contains("Memory") && !text.contains("Permissions"), "{text}");
1276+ assert_eq!(memory_limit(Some("max\n"), Some("MemTotal: 16384000 kB\n")), Some(16_384_000 * 1024));
1277+ assert_eq!(memory_limit(Some("4294967296\n"), Some("MemTotal: 16384000 kB\n")), Some(4_294_967_296));
1278+ assert_eq!(memory_limit(None, None), None);
1279+ assert_eq!(permission_title("security-events"), "SecurityEvents");
1280+ }
1281+
1282+ #[test]
1283+ fn a_run_step_opens_with_its_script_shell_and_variables_folded() {
1284+ let env: BTreeMap<String, String> = [("CARGO_TERM_COLOR", "always"), ("GITHUB_ACTION", "__run"), ("KEY", "line one\nline two")]
1285+ .into_iter()
1286+ .map(|(k, v)| (k.to_owned(), v.to_owned()))
1287+ .collect();
1288+ let lines = script_header("\n node build.mjs --all\necho done\n", "/usr/bin/bash -e {0}", &env);
1289+ assert_eq!(
1290+ lines,
1291+ [
1292+ "##[group]Run node build.mjs --all",
1293+ "\u{1b}[36;1m node build.mjs --all\u{1b}[0m",
1294+ "\u{1b}[36;1mecho done\u{1b}[0m",
1295+ "shell: /usr/bin/bash -e {0}",
1296+ "env:",
1297+ " CARGO_TERM_COLOR: always",
1298+ " KEY: line one",
1299+ " line two",
1300+ "##[endgroup]",
1301+ ]
1302+ );
1303+ // No variables: no `env:`.
1304+ assert!(!script_header("make", "sh -e {0}", &BTreeMap::new()).contains(&"env:".to_owned()));
1305+ let with: BTreeMap<String, String> = [("path", "~/.cargo\ntarget\n"), ("key", "k")].into_iter().map(|(k, v)| (k.to_owned(), v.to_owned())).collect();
1306+ assert_eq!(
1307+ uses_header("actions/cache@v4", &with, &BTreeMap::new()),
1308+ ["##[group]Run actions/cache@v4", "with:", " key: k", " path: ~/.cargo", " target", "##[endgroup]"]
1309+ );
1310+ }
1311+
1312+ #[test]
10421313 fn debug_logging_comes_from_a_secret_a_variable_or_a_debug_rerun() {
10431314 let contexts = |value: Value| -> Map<String, Value> { serde_json::from_value(value).unwrap() };
10441315 let none = json!({});
+86−0
223223 #[cfg(not(unix))]
224224 fn signal(_child: &std::process::Child, _signal: &str) {}
225225
226+/// What the job's steps started and left running, as GitHub's "Complete
227+/// job" finds it: every process whose environment carries the job's
228+/// `RUNNER_TRACKING_ID`, which each step's processes inherit, by pid and
229+/// name. Read from /proc, so only on Linux; elsewhere nothing is found.
230+pub(crate) fn orphans(tracking_id: &str) -> Vec<(u32, String)> {
231+ let Ok(entries) = std::fs::read_dir("/proc") else {
232+ return Vec::new();
233+ };
234+ let marker = format!("RUNNER_TRACKING_ID={tracking_id}");
235+ let own = std::process::id();
236+ let mut found = Vec::new();
237+ for entry in entries.flatten() {
238+ let Some(pid) = entry.file_name().to_str().and_then(|name| name.parse::<u32>().ok()) else {
239+ continue;
240+ };
241+ if pid == own {
242+ continue;
243+ }
244+ // Another user's process cannot be read, and is not the job's.
245+ let Ok(environ) = std::fs::read(entry.path().join("environ")) else {
246+ continue;
247+ };
248+ if !environ.split(|byte| *byte == 0).any(|pair| pair == marker.as_bytes()) {
249+ continue;
250+ }
251+ let stat = std::fs::read_to_string(entry.path().join("stat")).unwrap_or_default();
252+ if let Some(name) = live_name(&stat) {
253+ found.push((pid, name));
254+ }
255+ }
256+ found.sort();
257+ found
258+}
259+
260+/// A running process's name from `/proc/<pid>/stat` (`pid (name) state …`),
261+/// whose name may hold spaces and parentheses; None for a zombie, which
262+/// has already ended.
263+fn live_name(stat: &str) -> Option<String> {
264+ let open = stat.find('(')?;
265+ let close = stat.rfind(')')?;
266+ let state = stat.get(close + 1..)?.split_whitespace().next()?;
267+ (state != "Z").then(|| stat.get(open + 1..close).map(str::to_owned)).flatten()
268+}
269+
270+/// Kills the processes `orphans` found.
271+pub(crate) fn kill_orphans(found: &[(u32, String)]) {
272+ #[cfg(unix)]
273+ for (pid, _) in found {
274+ if let Ok(pid) = libc::pid_t::try_from(*pid) {
275+ // SAFETY: kill(2) on one pid; it reads no memory of ours.
276+ unsafe {
277+ libc::kill(pid, libc::SIGKILL);
278+ }
279+ }
280+ }
281+ #[cfg(not(unix))]
282+ let _ = found;
283+}
284+
226285 /// Runs the command, sending its output (stdout and stderr together, a
227286 /// line at a time) through `commands` to the log, until it ends or
228287 /// `timeout` passes.
361420 mod tests {
362421 use super::parse_command;
363422
423+ /// What a step left running is found by the job's tracking id, and
424+ /// only that.
425+ #[cfg(target_os = "linux")]
426+ #[test]
427+ fn orphans_are_found_by_the_jobs_tracking_id() {
428+ use super::{kill_orphans, live_name, orphans};
429+ let id = format!("github_test{}", std::process::id());
430+ let mut left = std::process::Command::new("sleep").arg("30").env("RUNNER_TRACKING_ID", &id).spawn().unwrap();
431+ let mut other = std::process::Command::new("sleep").arg("30").env("RUNNER_TRACKING_ID", "github_someone_else").spawn().unwrap();
432+ // /proc shows the new environment once exec has happened.
433+ let mut found = Vec::new();
434+ for _ in 0..50 {
435+ found = orphans(&id);
436+ if !found.is_empty() {
437+ break;
438+ }
439+ std::thread::sleep(std::time::Duration::from_millis(20));
440+ }
441+ assert_eq!(found, [(left.id(), "sleep".to_owned())]);
442+ kill_orphans(&found);
443+ assert!(!left.wait().unwrap().success(), "killed");
444+ let _ = other.kill();
445+ let _ = other.wait();
446+ assert_eq!(live_name("12 (tmux: server) S 1 12 12"), Some("tmux: server".into()));
447+ assert_eq!(live_name("13 (gone) Z 1 13 13"), None);
448+ }
449+
364450 /// A cancelled step hears SIGINT, and its own trap runs.
365451 #[cfg(unix)]
366452 #[test]
+79−8
22 //! annotations, and how it ended. Every report carries the job's token.
33
44 use std::sync::atomic::{AtomicBool, Ordering};
5−use std::time::{Duration, Instant};
5+use std::time::{Duration, Instant, SystemTime, UNIX_EPOCH};
66
77 use anyhow::Result;
88 use g1t_actions::mask;
99 use serde_json::{Value, json};
1010
11−/// How long log lines wait before they are sent.
12−const FLUSH_EVERY: Duration = Duration::from_millis(1500);
11+/// How long log lines wait before they are sent: about a second, so a
12+/// running step's page follows it closely, at one write to g1t a second.
13+const FLUSH_EVERY: Duration = Duration::from_millis(1000);
1314 /// How much log is sent at once.
1415 const FLUSH_BYTES: usize = 64 * 1024;
1516 /// The most one step may add to the job's summary, as on GitHub.
192193 }
193194 }
194195
195− /// The log so far: what was sent and what waits to be.
196− #[cfg(all(test, unix))]
196+ /// The log so far, what was sent and what waits to be, without the
197+ /// time each line is stamped with.
198+ #[cfg(test)]
197199 pub(crate) fn buffered(&self) -> String {
198− format!("{}{}", self.flushed, self.buffer)
200+ unstamped(&format!("{}{}", self.flushed, self.buffer))
199201 }
200202
201203 /// Starts writing to step `number` (0 for the job's setup).
223225 }
224226 }
225227
228+ /// Adds a line to the log, masked, each of its lines stamped with the
229+ /// time, as GitHub's runner writes its logs
230+ /// (`2026-10-12T09:41:07.1234567Z text`).
226231 pub(crate) fn line(&mut self, text: &str) {
227232 let masked = self.mask(text);
228− self.buffer.push_str(&masked);
229− self.buffer.push('\n');
233+ let at = stamp(SystemTime::now());
234+ for line in masked.split('\n') {
235+ self.buffer.push_str(&at);
236+ self.buffer.push(' ');
237+ self.buffer.push_str(line);
238+ self.buffer.push('\n');
239+ }
230240 if self.buffer.len() >= FLUSH_BYTES || self.last.elapsed() >= FLUSH_EVERY {
231241 self.flush();
232242 }
337347 }
338348 }
339349
350+/// A time as GitHub's logs stamp each line: RFC 3339 in UTC, to a tenth
351+/// of a microsecond (`2026-10-12T09:41:07.1234567Z`).
352+pub(crate) fn stamp(at: SystemTime) -> String {
353+ let since = at.duration_since(UNIX_EPOCH).unwrap_or_default();
354+ let seconds = since.as_secs();
355+ let (days, rest) = (seconds / 86_400, seconds % 86_400);
356+ let (year, month, day) = civil(days as i64);
357+ format!(
358+ "{year:04}-{month:02}-{day:02}T{:02}:{:02}:{:02}.{:07}Z",
359+ rest / 3600,
360+ rest % 3600 / 60,
361+ rest % 60,
362+ since.subsec_nanos() / 100
363+ )
364+}
365+
366+/// The calendar date `days` after 1970-01-01 (Howard Hinnant's
367+/// `civil_from_days`).
368+fn civil(days: i64) -> (i64, u32, u32) {
369+ let z = days + 719_468;
370+ let era = z.div_euclid(146_097);
371+ let doe = z.rem_euclid(146_097);
372+ let yoe = (doe - doe / 1460 + doe / 36_524 - doe / 146_096) / 365;
373+ let doy = doe - (365 * yoe + yoe / 4 - yoe / 100);
374+ let mp = (5 * doy + 2) / 153;
375+ let day = (doy - (153 * mp + 2) / 5 + 1) as u32;
376+ let month = (if mp < 10 { mp + 3 } else { mp - 9 }) as u32;
377+ let year = yoe + era * 400 + i64::from(month <= 2);
378+ (year, month, day)
379+}
380+
381+/// A log without the time stamped at the start of each line.
340382 #[cfg(test)]
383+pub(crate) fn unstamped(text: &str) -> String {
384+ text.split_inclusive('\n')
385+ .map(|line| match line.split_once(' ') {
386+ Some((at, rest)) if at.len() == 28 && at.ends_with('Z') && at.as_bytes()[10] == b'T' => rest,
387+ _ => line,
388+ })
389+ .collect()
390+}
391+
392+#[cfg(test)]
341393 mod tests {
342394 use super::*;
343395
396+ #[test]
397+ fn every_line_is_stamped_with_the_time_as_github_stamps_it() {
398+ assert_eq!(stamp(UNIX_EPOCH), "1970-01-01T00:00:00.0000000Z");
399+ assert_eq!(stamp(UNIX_EPOCH + Duration::new(1_791_797_067, 123_456_789)), "2026-10-12T09:24:27.1234567Z");
400+ // A leap day, and the last day of February in a century that has none.
401+ assert_eq!(stamp(UNIX_EPOCH + Duration::from_secs(951_782_400)), "2000-02-29T00:00:00.0000000Z");
402+ assert_eq!(stamp(UNIX_EPOCH + Duration::from_secs(4_107_542_399)), "2100-02-28T23:59:59.0000000Z");
403+ let mut log = log(&["s3cr3t"]);
404+ log.line("one s3cr3t\ntwo");
405+ let lines: Vec<&str> = log.buffer.lines().collect();
406+ assert_eq!(lines.len(), 2, "each line of a message is stamped");
407+ for (line, text) in lines.iter().zip(["one ***", "two"]) {
408+ let (at, rest) = line.split_once(' ').unwrap();
409+ assert_eq!((at.len(), &at[10..11], &at[27..]), (28, "T", "Z"), "{line}");
410+ assert_eq!(rest, text);
411+ }
412+ assert_eq!(log.buffered(), "one ***\ntwo\n");
413+ }
414+
344415 fn log(secrets: &[&str]) -> Log {
345416 Log::new(Api::offline(), mask::all_variants(secrets.iter().copied()))
346417 }
+18−2
369369 return true;
370370 }
371371 self.log.line("Prepare all required actions");
372+ self.log.line("Getting action download info");
372373 let mut ready = true;
373374 for (owner, repo, git_ref) in &wanted {
374375 if self.fetch_remote_action(owner, repo, git_ref).is_none() {
420421 ok
421422 }
422423
424+ fn log_header(&mut self, uses: &str, with: &BTreeMap<String, String>, env: &BTreeMap<String, String>) {
425+ for line in super::uses_header(uses, with, env) {
426+ self.log.line(&line);
427+ }
428+ }
429+
423430 fn deadline_left(&self) -> Duration {
424431 self.remaining_time()
425432 }
437444 _timeout: Duration,
438445 ) -> (bool, BTreeMap<String, String>) {
439446 let uses = uses.trim();
447+ let (name, git_ref) = uses.split_once('@').unwrap_or((uses, ""));
448+ let lower = name.to_ascii_lowercase();
449+ // The step opens as GitHub's do: `Run` and the action, its inputs
450+ // and variables, folded. An action fetched from a repository lists
451+ // its inputs as they are read, its defaults among them.
452+ let fetched = !uses.starts_with("docker://") && !native(&lower, self.docker_hosted);
453+ if !fetched {
454+ self.log_header(uses, with, env);
455+ }
440456 if let Some(image) = uses.strip_prefix("docker://") {
441457 // `with.args` and `with.entrypoint` are the container's; every
442458 // input is also an `INPUT_` variable, as on GitHub.
454470 let (ok, outputs, _) = self.run_docker(&run);
455471 return (ok, outputs);
456472 }
457− let (name, git_ref) = uses.split_once('@').unwrap_or((uses, ""));
458− let lower = name.to_ascii_lowercase();
459473 if lower == "docker/setup-buildx-action" && native(&lower, self.docker_hosted) {
460474 return self.setup_buildx(with);
461475 }
470484 _ => {}
471485 }
472486 let Some(found) = self.resolve_action(uses) else {
487+ self.log_header(uses, with, env);
473488 return (false, BTreeMap::new());
474489 };
475490 let Action { dir, local, manifest: action, .. } = &found;
478493 let env_context = env.clone();
479494 let contexts = self.contexts_for(frame, &env_context);
480495 let inputs = self.action_inputs(action, with, &contexts, true);
496+ self.log_header(uses, &inputs, env);
481497
482498 let runs = action.get("runs").cloned().unwrap_or(Value::Null);
483499 let using = runs.get("using").map(expr::to_text).unwrap_or_default().to_ascii_lowercase();
+1−1
5252 SIGNED_LIMIT: { worker: "services/packages", namespaceId: 4102, limit: 5000, per: "person, workspace or agent" },
5353 // apps/web (workers/app.ts): the front door.
5454 WEB_ANONYMOUS_LIMIT: { worker: "apps/web", namespaceId: 4201, limit: 600, per: "address, signed-out pages" },
55− WEB_HEAVY_LIMIT: { worker: "apps/web", namespaceId: 4202, limit: 30, per: "address, signed-out archives, run pages, logs and search" },
55+ WEB_HEAVY_LIMIT: { worker: "apps/web", namespaceId: 4202, limit: 30, per: "address, signed-out archives, run pages, log downloads and search" },
5656 WEB_SESSION_LIMIT: { worker: "apps/web", namespaceId: 4203, limit: 1200, per: "session, signed-in requests" },
5757 WEB_ADDRESS_LIMIT: { worker: "apps/web", namespaceId: 4204, limit: 3000, per: "address, every request that reaches the Worker" },
5858 GIT_ANONYMOUS_LIMIT: { worker: "apps/web", namespaceId: 4205, limit: 120, per: "address, git requests without credentials" },
+12−6
2929 /// The most a single log report may add.
3030 const MAX_CHUNK_BYTES: usize = 256 * 1024;
3131 const MAX_ANNOTATIONS: usize = 50;
32+/// A batch of a job's log, under the next `seq` of that job's, worked out
33+/// in the same statement (SQLite runs one write at a time).
34+const LOG_INSERT: &str =
35+ "INSERT INTO logs (job_id, seq, step, text) SELECT ?1, COALESCE(MAX(seq), 0) + 1, ?2, ?3 FROM logs WHERE job_id = ?1";
3236 /// The most one step's job summary keeps, in bytes, and how many steps of a
3337 /// job may have one, as on GitHub.
3438 pub(crate) const MAX_SUMMARY_BYTES: usize = 1024 * 1024;
24522456 #[derive(Deserialize)]
24532457 struct Size {
24542458 n: Option<f64>,
2455− seq: Option<f64>,
24562459 }
24572460 let size = self
24582461 .db
2459− .prepare("SELECT SUM(LENGTH(text)) AS n, MAX(seq) AS seq FROM logs WHERE job_id = ?")
2462+ .prepare("SELECT SUM(LENGTH(text)) AS n FROM logs WHERE job_id = ?")
24602463 .bind(&[job.id.as_str().into()])?
24612464 .first::<Size>(None)
24622465 .await?;
2463− let (used, seq) = size.map_or((0, 0.0), |s| (s.n.unwrap_or(0.0) as usize, s.seq.unwrap_or(0.0)));
2466+ let used = size.and_then(|s| s.n).unwrap_or(0.0) as usize;
24642467 if used < MAX_LOG_BYTES {
24652468 if used + text.len() >= MAX_LOG_BYTES {
24662469 text.push_str("\n… The log reached its limit of 4 MB; the rest is not kept.\n");
24672470 }
2471+ // The next `seq` is taken in the insert itself, so two
2472+ // batches at once (a report sent again while the first
2473+ // was still being written) never reach for the same one
2474+ // and lose a chunk to the primary key.
24682475 self.db
2469− .prepare("INSERT INTO logs (job_id, seq, step, text) VALUES (?, ?, ?, ?)")
2470− .bind(&[job.id.as_str().into(), // Numbers go to D1 as f64: a u64 would be a BigInt, which it refuses.
2471− (seq + 1.0).into(), (report["step"].as_u64().unwrap_or(0) as u32).into(), text.into()])?
2476+ .prepare(LOG_INSERT)
2477+ .bind(&[job.id.as_str().into(), (report["step"].as_u64().unwrap_or(0) as u32).into(), text.into()])?
24722478 .run()
24732479 .await?;
24742480 }