Public: anyone can read this; the crew can change it.
A run page shows its log live from /events and opens no EventSource of its own #2866
Check · Review · Land · Live done — Landed and live in production.
scout/forge:scout/2843-a-run-page-shows-its-log-live-from-event → main 4 commits fork 3 threads · 3 unresolved
6 files
changed +117
−24
README.md +7
| @@ -1461,6 +1461,13 @@ work here. | ||
| 1461 | 1461 | |
| 1462 | 1462 | ## What works today |
| 1463 | 1463 | |
| 1464 | - **A run page's live log** rides the page's one `/events` connection (its | |
| 1465 | `run.log` frames); it opens no stream of its own. Known gaps, both silent: a | |
| 1466 | frame the server cuts for size (64 lines or 16 KB) loses its omitted lines | |
| 1467 | until the next reconnect's catch-up read, and a run whose log was already cut | |
| 1468 | to its last 512 KB at render gets no catch-up read. The page says | |
| 1469 | "Reconnecting" while the connection is down. | |
| 1470 | ||
| 1464 | 1471 | - **Cut a wave** — Settings → *Cut a wave* (repository admins, same-origin |
| 1465 | 1472 | POST; web-only, the terminal's settings hand over to the web) opens a pull |
| 1466 | 1473 | adding `waves/<next>.md`, listing the pulls merged since the last wave and |
src/web/client.ts +42 −19
| @@ -224,7 +224,6 @@ export const studioRunJs = /* js */ ` | ||
| 224 | 224 | (function () { |
| 225 | 225 | var log = document.getElementById('run-log'); |
| 226 | 226 | if (!log) return; |
| 227 | var url = log.getAttribute('data-stream'); | |
| 228 | 227 | var who = log.getAttribute('data-who') || 'agent'; |
| 229 | 228 | var cap = parseInt(log.getAttribute('data-cap') || '0', 10) || 0; |
| 230 | 229 | var pulse = document.getElementById('run-pulse'); |
| @@ -360,28 +359,52 @@ export const studioRunJs = /* js */ ` | ||
| 360 | 359 | }); |
| 361 | 360 | } |
| 362 | 361 | |
| 363 | if (!url || typeof EventSource === 'undefined') return; | |
| 364 | var source = new EventSource(url); | |
| 362 | // The page opens no stream of its own: the shared /events connection | |
| 363 | // (liveRegionsJs) carries this run's lines as run.log frames, handed on as | |
| 364 | // forge:run-log, and its state change as the run.finished event. | |
| 365 | var runId = log.getAttribute('data-run'); | |
| 366 | if (!runId) return; | |
| 367 | var logUrl = log.getAttribute('data-log'); | |
| 365 | 368 | var empty = document.getElementById('run-empty'); |
| 366 | var seeded = false; | |
| 367 | source.addEventListener('line', function (event) { | |
| 368 | if (!seeded) { | |
| 369 | if (event.lastEventId === '1') { | |
| 370 | Array.prototype.slice.call(log.querySelectorAll('.ln:not(#run-pulse)')).forEach(function (el) { log.removeChild(el); }); | |
| 371 | } | |
| 372 | seeded = true; | |
| 373 | if (empty) empty.hidden = true; | |
| 374 | } | |
| 375 | var text = event.data; | |
| 376 | try { var parsed = JSON.parse(text); if (typeof parsed === 'string') text = parsed; } catch (err) {} | |
| 369 | // Lines on the page: those the server drew from the file, then each added | |
| 370 | // here. A catch-up read of the file adds only what is past that count, and | |
| 371 | // frames wait for it, so a line is never drawn twice. | |
| 372 | var have = parseInt(log.getAttribute('data-seen') || '-1', 10); | |
| 373 | var catching = false; | |
| 374 | function put(text) { | |
| 375 | if (empty) empty.hidden = true; | |
| 377 | 376 | add(draw(text)); |
| 377 | have++; | |
| 378 | 378 | if (/^(\\$ |test-shards: |\\(fail\\) |\u2500\u2500 shard )/.test(text)) stepsSoon(); |
| 379 | } | |
| 380 | function catchUp() { | |
| 381 | if (have < 0 || !logUrl || !window.fetch || catching) return; | |
| 382 | catching = true; | |
| 383 | fetch(logUrl, { credentials: 'same-origin' }) | |
| 384 | .then(function (r) { return r.ok ? r.text() : ''; }) | |
| 385 | .then(function (body) { | |
| 386 | var all = body.split('\n'); | |
| 387 | if (all[all.length - 1] === '') all.pop(); | |
| 388 | all.slice(have).forEach(put); | |
| 389 | }) | |
| 390 | .catch(function () {}) | |
| 391 | .then(function () { catching = false; }); | |
| 392 | } | |
| 393 | var conn = document.getElementById('run-conn'); | |
| 394 | document.addEventListener('forge:live', function (e) { | |
| 395 | var st = e.detail && e.detail.state; | |
| 396 | if (conn) conn.hidden = st !== 'reconnecting'; | |
| 397 | if (st === 'open') catchUp(); | |
| 379 | 398 | }); |
| 380 | source.addEventListener('done', function (event) { | |
| 381 | source.close(); | |
| 382 | var run; | |
| 383 | try { run = JSON.parse(event.data); } catch (err) { return; } | |
| 384 | paint(run); | |
| 399 | document.addEventListener('forge:run-log', function (e) { | |
| 400 | var d = e.detail; | |
| 401 | if (!d || d.run !== runId || catching || !Array.isArray(d.lines)) return; | |
| 402 | d.lines.forEach(function (l) { if (typeof l === 'string') put(l); }); | |
| 403 | }); | |
| 404 | document.addEventListener('forge:event', function (e) { | |
| 405 | var d = e.detail; | |
| 406 | if (!d || d.kind !== 'run.finished' || !d.payload || d.payload.runId !== runId) return; | |
| 407 | paint(d.payload); | |
| 385 | 408 | if (stepsTimer) { window.clearTimeout(stepsTimer); stepsTimer = 0; } |
| 386 | 409 | steps(); |
| 387 | 410 | if (steer) { |
src/web/studio/log.ts +5
| @@ -59,6 +59,9 @@ export function logBox(opts: { | ||
| 59 | 59 | cap: number; |
| 60 | 60 | lines: readonly string[]; |
| 61 | 61 | stream?: string; |
| 62 | /** A run still going, read live from the shared /events stream: its id, | |
| 63 | * where the plain log is read to catch up, and how many lines are drawn. */ | |
| 64 | live?: { run: string; log: string; seen?: number }; | |
| 62 | 65 | pulse?: boolean; |
| 63 | 66 | className?: string; |
| 64 | 67 | extra?: Html; |
| @@ -75,6 +78,8 @@ export function logBox(opts: { | ||
| 75 | 78 | data-who="${opts.who}" |
| 76 | 79 | data-cap="${opts.cap}" |
| 77 | 80 | ${opts.stream ? html`data-stream="${opts.stream}"` : null} |
| 81 | ${opts.live ? html`data-run="${opts.live.run}" data-log="${opts.live.log}"` : null} | |
| 82 | ${opts.live?.seen !== undefined ? html`data-seen="${opts.live.seen}"` : null} | |
| 78 | 83 | > |
| 79 | 84 | ${when( |
| 80 | 85 | hidden > 0, |
src/web/studio/run.ts +25 −4
| @@ -25,7 +25,7 @@ import { getUserById } from "../../core/users.ts"; | ||
| 25 | 25 | import { repoDir } from "../../git/repos.ts"; |
| 26 | 26 | import type { Ctx } from "../../http/context.ts"; |
| 27 | 27 | import { crumbsFor, repoBase, repoHeader, repoPalette } from "../chrome.ts"; |
| 28 | import { studioRunJs } from "../client.ts"; | |
| 28 | import { liveRegionsJs, studioRunJs } from "../client.ts"; | |
| 29 | 29 | import { html, raw, when, type Html } from "../html.ts"; |
| 30 | 30 | import { runLine } from "../describe.ts"; |
| 31 | 31 | import { page } from "../layout.ts"; |
| @@ -107,7 +107,7 @@ export async function runView( | ||
| 107 | 107 | const all = ctx.url.searchParams.get("all") === "1"; |
| 108 | 108 | const held = listHeldSecrets(db, run.id); |
| 109 | 109 | const carried = carriedBy(db, run.id); |
| 110 | const stream = `/api/v1/repos/${repo.ownerName}/${repo.name}/runs/${run.id}/log?follow=1`; | |
| 110 | const logPath = `/api/v1/repos/${repo.ownerName}/${repo.name}/runs/${run.id}/log`; | |
| 111 | 111 | |
| 112 | 112 | // The pull this run's tell has become, once one exists: the tell itself |
| 113 | 113 | // when the run is already a pull's own (feedback, a failed check, a |
| @@ -299,6 +299,16 @@ export async function runView( | ||
| 299 | 299 | }, |
| 300 | 300 | )} |
| 301 | 301 | <div class="run-live" id="run-live" data-state="${run.state}"> |
| 302 | ${when( | |
| 303 | unfinished && !logHidden, | |
| 304 | // No id, so the shared script never refetches the page for it: its | |
| 305 | // only job is to make \`liveRegionsJs\` open the one /events | |
| 306 | // connection this log and its finish ride on. | |
| 307 | () => html`<span data-live="run.finished" hidden></span> | |
| 308 | <p class="muted small" id="run-conn" role="status" hidden> | |
| 309 | Reconnecting; lines written meanwhile appear when it is back. | |
| 310 | </p>`, | |
| 311 | )} | |
| 302 | 312 | ${when(!logHidden, () => logBox({ |
| 303 | 313 | id: "run-log", |
| 304 | 314 | who, |
| @@ -308,7 +318,18 @@ export async function runView( | ||
| 308 | 318 | lines, |
| 309 | 319 | allHref: `${base}/runs/${run.id}?all=1`, |
| 310 | 320 | truncated, |
| 311 | ...(unfinished ? { stream } : {}), | |
| 321 | // Lines come from the shared /events stream; `seen` lets the page | |
| 322 | // tell what it already drew from what it missed before connecting | |
| 323 | // (only knowable when the file was read whole). | |
| 324 | ...(unfinished | |
| 325 | ? { | |
| 326 | live: { | |
| 327 | run: run.id, | |
| 328 | log: logPath, | |
| 329 | ...(truncated ? {} : { seen: lines.length }), | |
| 330 | }, | |
| 331 | } | |
| 332 | : {}), | |
| 312 | 333 | pulse: run.state === "running", |
| 313 | 334 | extra: html`<button type="button" class="run-jump" id="run-jump" hidden> |
| 314 | 335 | newer below |
| @@ -383,7 +404,7 @@ export async function runView( | ||
| 383 | 404 | crumbs: crumbsFor(repo), |
| 384 | 405 | palette: repoPalette(ctx, repo), |
| 385 | 406 | body, |
| 386 | scriptJs: studioRunJs, | |
| 407 | scriptJs: `${liveRegionsJs}\n${studioRunJs}`, | |
| 387 | 408 | // The no-script half of a live log: with JavaScript off, the page |
| 388 | 409 | // refreshes itself while the run is going (`layout.ts` writes it inside |
| 389 | 410 | // `<noscript>`, so a browser running the stream above never reloads). |
test/studio-runs.test.ts +35
| @@ -520,6 +520,41 @@ describe("working: a run's own page in the studio", () => { | ||
| 520 | 520 | expect(page).not.toContain("?mode=dev"); |
| 521 | 521 | }); |
| 522 | 522 | |
| 523 | test("a running run's page reads its log from the one /events stream and opens no other", async () => { | |
| 524 | const run = createRun(app.db, { | |
| 525 | repoId: repo.id, | |
| 526 | kind: "agent", | |
| 527 | actorId: scoutId, | |
| 528 | reason: "assigned", | |
| 529 | }); | |
| 530 | claimRun(app.db, run.id); | |
| 531 | appendRunLog(app.config.dataDir, run.id, "first"); | |
| 532 | appendRunLog(app.config.dataDir, run.id, "second"); | |
| 533 | ||
| 534 | const page = await ( | |
| 535 | await get(`/alice/engine/runs/${run.id}`, writerCookie) | |
| 536 | ).text(); | |
| 537 | // Every EventSource the page's HTML and script open is /events. | |
| 538 | const opened = [...page.matchAll(/new EventSource\(([^,;]*)/g)].map( | |
| 539 | (m) => m[1]!, | |
| 540 | ); | |
| 541 | expect(opened.length).toBeGreaterThan(0); | |
| 542 | for (const arg of opened) expect(arg).toStartWith("'/events"); | |
| 543 | // The connection is really opened: liveRegionsJs only connects when the | |
| 544 | // page has a [data-live] element, and a script's text proves nothing. | |
| 545 | expect(page).toMatch(/<span data-live="run\.finished"[^>]*>/); | |
| 546 | expect(page).toContain('id="run-conn"'); | |
| 547 | expect(page).not.toContain("follow=1"); | |
| 548 | expect(page).not.toContain("data-stream="); | |
| 549 | // The run's frames arrive on that connection; the file's lines are | |
| 550 | // counted so none is drawn twice. | |
| 551 | expect(page).toContain("'run.log'"); | |
outdated
This assertion proves nothing about the connection. |
||
| 552 | expect(page).toContain("forge:run-log"); | |
| 553 | expect(page).toContain(`data-run="${run.id}"`); | |
| 554 | expect(page).toContain('data-seen="2"'); | |
| 555 | expect(page).toContain(">second<"); | |
| 556 | }); | |
| 557 | ||
| 523 | 558 | test("a long transcript holds its last window, and the whole of it is one step deeper at ?all=1", async () => { |
| 524 | 559 | const run = createRun(app.db, { |
| 525 | 560 | repoId: repo.id, |
test/web-apps.test.ts +3 −1
| @@ -379,7 +379,9 @@ describe("apps, runs and the crew on the web", () => { | ||
| 379 | 379 | const html = await bodyOf(alice, `/alice/hello/runs/${run!.id}`); |
| 380 | 380 | const after = isGoing(); |
| 381 | 381 | if (before === after) { |
| 382 | expect(html.includes("data-stream=")).toBe(before); | |
| 382 | // The tail is live while the run goes: it names its run (read from /events), not a stream. | |
| 383 | expect(html.includes(`data-run="${run!.id}"`)).toBe(before); | |
| 384 | expect(html.includes("data-stream=")).toBe(false); | |
| 383 | 385 | expect(hasMetaRefresh(html)).toBe(before); |
| 384 | 386 | break; |
| 385 | 387 | } |
new above
offline
Frames are dropped while
catchingis true, and only the file read restores them. That is correct, but if the fetch fails the lines are lost until the next reconnect. Retry the catch-up once on failure.