Log sections: ::group:: folds a job's output on the run page d9b3b84605a4
oxygenflow#31 (last part). A job folds its own output into sections by printing ::group::TITLE and later ::endgroup:: (as GitHub Actions does; a new ::group:: ends the one before). The run page shows each section closed with how long it took, and the one still going open; the live view opens, fills and closes sections as lines arrive. Per-line times were already shown. Tested: sections from marked lines (closed, ended by the next, still going), and a run page folding a build's compile section with its 1.5s. closes andymccall/oxygenflow#31
- Author
- Andy McCall @andymccall <[email protected]>
- When
- · 2026-10-14 04:50 UTC
- Signature
- ✔ signed by Andy McCall
- Hash
d9b3b84605a4f30f778d73011e379e8178f33d8d2c6d3d6704c7f5f7e108d5f7- Depends on
- 0b203bbf7cc3 42fa95540468 4d2e44d79b03 4f6925337848 501d8b268dd4 8933faff2043 93be9ce4653e af9c6ca11c49 d23464c0ac60 e8fa53694f68
- Depended on by
- nothing yet
- In bookmarks
- api-unknown-fields cancel-landed-runs diffusion-pin-bookmark draft-ready main oh-comment-body-file proposal-list-fast
- In tags
- v0.5.0 v0.5.1 v0.5.2 v0.6.0 v0.6.1 v0.7.0 v0.8.0 v0.9.0 v0.9.1 v0.9.11 v0.9.15 v0.9.16 v0.9.19 v0.9.2 v0.9.20 v0.9.21 v0.9.22 v0.9.23 v0.9.24 v0.9.3 v0.9.4 v0.9.5 v0.9.6 v0.9.7 v0.9.8 v0.9.9
- Edits
- 16 atoms, 0 tree operations, 6 files
Browse the tree at this change
modified assets/hub.js +26 −4
| … | 342 unchanged lines |
||
| 343 | 343 | if (j.status === "running" || j.status === "failed") d.open = true; |
|
| 344 | 344 | var log = d.querySelector("[data-log]"); |
|
| 345 | 345 | var stick = log.scrollTop + log.clientHeight >= log.scrollHeight - 4; |
|
| 346 | + | // Sections (oxygenflow#31): ::group::TITLE opens one, ::endgroup:: |
|
| 347 | + | // (or the next ::group::) closes it; the open one takes the lines. |
|
| 348 | + | var open = log.querySelector("details[data-open-group]"); |
|
| 349 | + | var secs = function (ms) { return Math.floor(ms / 1000) + "." + Math.floor(ms % 1000 / 100) + "s"; }; |
|
| 350 | + | var close = function (t) { |
|
| 351 | + | if (!open) return; |
|
| 352 | + | open.removeAttribute("data-open-group"); open.open = false; |
|
| 353 | + | var took = document.createElement("span"); took.className = "took"; took.textContent = " " + secs(t - Number(open.getAttribute("data-from"))); |
|
| 354 | + | open.querySelector("summary").appendChild(took); open = null; |
|
| 355 | + | }; |
|
| 346 | 356 | j.lines.forEach(function (l) { |
|
| 347 | - | var ln = document.createElement("span"); ln.className = "ln s-" + l.stream; |
|
| 348 | - | var t = document.createElement("span"); t.className = "t"; t.textContent = (l.t / 1000).toFixed(1) + "s"; |
|
| 349 | - | ln.appendChild(t); ln.appendChild(document.createTextNode(l.text)); |
|
| 350 | - | log.appendChild(ln); log.appendChild(document.createTextNode("\n")); |
|
| 357 | + | var tt = document.createElement("span"); tt.className = "t"; tt.textContent = secs(l.t); |
|
| 358 | + | if (l.text.indexOf("::group::") === 0) { |
|
| 359 | + | close(l.t); |
|
| 360 | + | open = document.createElement("details"); open.className = "log-group"; open.open = true; |
|
| 361 | + | open.setAttribute("data-open-group", ""); open.setAttribute("data-from", l.t); |
|
| 362 | + | var sum = document.createElement("summary"); sum.className = "ln"; |
|
| 363 | + | sum.appendChild(tt); sum.appendChild(document.createTextNode(l.text.slice(9).trim())); |
|
| 364 | + | open.appendChild(sum); log.appendChild(open); |
|
| 365 | + | } else if (l.text.trim() === "::endgroup::") { |
|
| 366 | + | close(l.t); |
|
| 367 | + | } else { |
|
| 368 | + | var ln = document.createElement("span"); ln.className = "ln s-" + l.stream; |
|
| 369 | + | ln.appendChild(tt); ln.appendChild(document.createTextNode(l.text)); |
|
| 370 | + | var into = open || log; |
|
| 371 | + | into.appendChild(ln); into.appendChild(document.createTextNode("\n")); |
|
| 372 | + | } |
|
| 351 | 373 | log.setAttribute("data-seq", l.seq); |
|
| 352 | 374 | }); |
|
| 353 | 375 | if (stick && j.lines.length) log.scrollTop = log.scrollHeight; |
|
| … | 320 unchanged lines |
modified crates/hub/src/web/flow.rs +98 −1
| … | 308 unchanged lines |
||
| 309 | 309 | /// Failed tests a run page lists per job; the rest are counted. |
|
| 310 | 310 | const SHOWN_FAILURES: i64 = 50; |
|
| 311 | 311 | ||
| 312 | + | /// A stretch of a job's log as the run page shows it: a line, or a |
|
| 313 | + | /// section the job marked with `::group::TITLE` … `::endgroup::` |
|
| 314 | + | /// (oxygenflow#31), shown folded with how long it took. |
|
| 315 | + | pub enum Segment { |
|
| 316 | + | Line(fdb::LogLine), |
|
| 317 | + | Group(Section), |
|
| 318 | + | } |
|
| 319 | + | ||
| 320 | + | pub struct Section { |
|
| 321 | + | pub title: String, |
|
| 322 | + | /// When it began, and ended (`None` while it is still going). |
|
| 323 | + | pub from_t: i64, |
|
| 324 | + | pub to_t: Option<i64>, |
|
| 325 | + | pub lines: Vec<fdb::LogLine>, |
|
| 326 | + | } |
|
| 327 | + | ||
| 328 | + | /// A log's lines in sections. A section left open is still going; a new |
|
| 329 | + | /// `::group::` ends the one before (sections do not nest). |
|
| 330 | + | pub fn sections(lines: &[fdb::LogLine]) -> Vec<Segment> { |
|
| 331 | + | let mut out: Vec<Segment> = Vec::new(); |
|
| 332 | + | let mut open: Option<Section> = None; |
|
| 333 | + | for l in lines { |
|
| 334 | + | if let Some(title) = l.text.strip_prefix("::group::") { |
|
| 335 | + | if let Some(g) = open.take() { |
|
| 336 | + | out.push(Segment::Group(Section { to_t: Some(l.t), ..g })); |
|
| 337 | + | } |
|
| 338 | + | open = Some(Section { title: title.trim().to_string(), from_t: l.t, to_t: None, lines: Vec::new() }); |
|
| 339 | + | } else if l.text.trim() == "::endgroup::" { |
|
| 340 | + | if let Some(g) = open.take() { |
|
| 341 | + | out.push(Segment::Group(Section { to_t: Some(l.t), ..g })); |
|
| 342 | + | } |
|
| 343 | + | } else { |
|
| 344 | + | match open.as_mut() { |
|
| 345 | + | Some(g) => g.lines.push(l.clone()), |
|
| 346 | + | None => out.push(Segment::Line(l.clone())), |
|
| 347 | + | } |
|
| 348 | + | } |
|
| 349 | + | } |
|
| 350 | + | if let Some(g) = open { |
|
| 351 | + | out.push(Segment::Group(g)); |
|
| 352 | + | } |
|
| 353 | + | out |
|
| 354 | + | } |
|
| 355 | + | ||
| 356 | + | /// Milliseconds as the log shows them: `12.3s`. |
|
| 357 | + | pub fn secs(ms: impl std::borrow::Borrow<i64>) -> String { |
|
| 358 | + | let ms = *ms.borrow(); |
|
| 359 | + | format!("{}.{}s", ms / 1000, ms % 1000 / 100) |
|
| 360 | + | } |
|
| 361 | + | ||
| 312 | 362 | pub struct JobLog { |
|
| 313 | 363 | pub j: fdb::Job, |
|
| 314 | 364 | pub artifacts: Vec<fdb::Artifact>, |
|
| 315 | 365 | pub lines: Vec<fdb::LogLine>, |
|
| 366 | + | /// The lines in sections (oxygenflow#31). |
|
| 367 | + | pub segments: Vec<Segment>, |
|
| 316 | 368 | pub duration: String, |
|
| 317 | 369 | /// The last line shown; the live view asks for what follows. |
|
| 318 | 370 | pub last_seq: i64, |
|
| … | 55 unchanged lines |
||
| 374 | 426 | Some(r) if r.broken() > 0 => crate::junit::failures(&app.db, r.id, SHOWN_FAILURES).await.unwrap_or_default(), |
|
| 375 | 427 | _ => vec![], |
|
| 376 | 428 | }; |
|
| 377 | - | logs.push(JobLog { duration: crate::flow::duration(j), j: j.clone(), artifacts, lines, last_seq, coverage, tests, failures }); |
|
| 429 | + | let segments = sections(&lines); |
|
| 430 | + | logs.push(JobLog { |
|
| 431 | + | duration: crate::flow::duration(j), |
|
| 432 | + | j: j.clone(), |
|
| 433 | + | artifacts, |
|
| 434 | + | lines, |
|
| 435 | + | segments, |
|
| 436 | + | last_seq, |
|
| 437 | + | coverage, |
|
| 438 | + | tests, |
|
| 439 | + | failures, |
|
| 440 | + | }); |
|
| 378 | 441 | } |
|
| 379 | 442 | let duration = match run.finished_ms { |
|
| 380 | 443 | Some(f) => crate::flow::human_ms(f - run.created_ms), |
|
| … | 389 unchanged lines |
||
| 770 | 833 | svg, |
|
| 771 | 834 | ) |
|
| 772 | 835 | .into_response()) |
|
| 836 | + | } |
|
| 837 | + | ||
| 838 | + | #[cfg(test)] |
|
| 839 | + | mod section_tests { |
|
| 840 | + | use super::*; |
|
| 841 | + | ||
| 842 | + | fn line(seq: i64, t: i64, text: &str) -> fdb::LogLine { |
|
| 843 | + | fdb::LogLine { seq, t, stream: "out".into(), text: text.into() } |
|
| 844 | + | } |
|
| 845 | + | ||
| 846 | + | #[test] |
|
| 847 | + | fn marked_lines_fold_into_sections() { |
|
| 848 | + | let lines = vec![ |
|
| 849 | + | line(1, 0, "booting"), |
|
| 850 | + | line(2, 100, "::group::cargo build"), |
|
| 851 | + | line(3, 200, "Compiling a"), |
|
| 852 | + | line(4, 900, "Compiling b"), |
|
| 853 | + | line(5, 4_300, "::endgroup::"), |
|
| 854 | + | line(6, 4_400, "::group::cargo test"), |
|
| 855 | + | line(7, 4_500, "test x ... ok"), |
|
| 856 | + | line(8, 5_000, "::group::lint"), |
|
| 857 | + | line(9, 5_100, "clean"), |
|
| 858 | + | ]; |
|
| 859 | + | let segs = sections(&lines); |
|
| 860 | + | assert_eq!(segs.len(), 4); |
|
| 861 | + | assert!(matches!(&segs[0], Segment::Line(l) if l.text == "booting")); |
|
| 862 | + | let Segment::Group(build) = &segs[1] else { panic!("a section") }; |
|
| 863 | + | assert_eq!((build.title.as_str(), build.from_t, build.to_t, build.lines.len()), ("cargo build", 100, Some(4_300), 2)); |
|
| 864 | + | let Segment::Group(test) = &segs[2] else { panic!("a section") }; |
|
| 865 | + | assert_eq!(test.to_t, Some(5_000), "a new section ends the one before"); |
|
| 866 | + | let Segment::Group(lint) = &segs[3] else { panic!("a section") }; |
|
| 867 | + | assert_eq!((lint.to_t, lint.lines.len()), (None, 1), "still going"); |
|
| 868 | + | assert_eq!(secs(4_200), "4.2s"); |
|
| 869 | + | } |
|
| 773 | 870 | } |
modified crates/hub/tests/flow.rs +10 −1
| … | 3942 unchanged lines |
||
| 3943 | 3943 | let id = j["job_id"].as_i64().unwrap(); |
|
| 3944 | 3944 | let (name, ph) = (j["job"]["name"].as_str().unwrap().to_string(), j["pipeline_hash"].as_str().unwrap().to_string()); |
|
| 3945 | 3945 | let exit = if name == "test" { 1 } else { 0 }; |
|
| 3946 | - | let log = serde_json::json!({ "records": [{ "t": 1, "stream": "out", "text": format!("{name} ran") }] }); |
|
| 3946 | + | let log = serde_json::json!({ "records": [ |
|
| 3947 | + | { "t": 1, "stream": "out", "text": format!("{name} ran") }, |
|
| 3948 | + | { "t": 2, "stream": "out", "text": "::group::compile" }, |
|
| 3949 | + | { "t": 5, "stream": "out", "text": "cc a.c" }, |
|
| 3950 | + | { "t": 1502, "stream": "out", "text": "::endgroup::" }, |
|
| 3951 | + | ]}); |
|
| 3947 | 3952 | call(&h.app, "POST", &format!("/api/v1/flow/jobs/{id}/log"), Some("runner-secret"), Some(log.to_string())).await; |
|
| 3948 | 3953 | assert_eq!( |
|
| 3949 | 3954 | finish(&h.app, id, serde_json::json!({ "exit_code": exit, "duration_ms": 10, "receipt": receipt(&name, &ph, exit as u32) })) |
|
| … | 1 unchanged lines |
||
| 3951 | 3956 | StatusCode::NO_CONTENT |
|
| 3952 | 3957 | ); |
|
| 3953 | 3958 | } |
|
| 3959 | + | // Marked lines fold into a section, with how long it took (#31). |
|
| 3960 | + | let (_, page) = call(&h.app, "GET", &format!("/andy/flaky/flow/{}", run.number), None, None).await; |
|
| 3961 | + | assert!(page.contains(r#"<details class="log-group" data-from="2">"#), "{page}"); |
|
| 3962 | + | assert!(page.contains(r#"compile <span class="took">1.5s</span></summary>"#) && !page.contains("::endgroup::"), "{page}"); |
|
| 3954 | 3963 | let status = |n: &'static str| { |
|
| 3955 | 3964 | let (app, run_id) = (h.app.clone(), run.id); |
|
| 3956 | 3965 | async move { db::flow::jobs(&app.db, run_id).await.unwrap().into_iter().find(|j| j.name == n).unwrap() } |
|
| … | 39 unchanged lines |
modified docs/spec.md +1 −1
| … | 486 unchanged lines |
||
| 487 | 487 | ||
| 488 | 488 | Viewers who may not start runs get no button. The Flow tab says why: Flow is off for the repository, they are not signed in, or they lack write access. **Re-run** on a finished run's page runs its state again. |
|
| 489 | 489 | ||
| 490 | - | Runs only ever take committed states already in the repository, never uncommitted work. A run writes no history: its receipts are signed statements about a state (Oxygen spec §14.6). Running a state again adds another statement. The environment hash shows whether it ran in the same environment, and a matching result is independent confirmation. The new run's checks replace the old ones for that state, and the run page says what started it (pushed by, started by, re-run of #N by). |
|
| 490 | + | Runs only ever take committed states already in the repository, never uncommitted work. A run writes no history: its receipts are signed statements about a state (Oxygen spec §14.6). Running a state again adds another statement. The environment hash shows whether it ran in the same environment, and a matching result is independent confirmation. The new run's checks replace the old ones for that state, and the run page says what started it (pushed by, started by, re-run of #N by). Each log line shows its time since the job began, and a job folds its own output into sections by printing `::group::TITLE` and later `::endgroup::` (as GitHub Actions does; a new `::group::` ends the one before): the run page shows each section closed with how long it took, the one still going open, live as lines arrive (oxygenflow#31). |
|
| 491 | 491 | - **Runs and jobs.** A run holds the repository, bookmark, state hash and heads, pipeline hash and pusher; one job per pipeline job with its compiled form, sandbox and dependencies. Job states: `queued`, `running`, `passed`, `failed`, `skipped` (a dependency did not pass), `error` (the runner could not run it). A run is `running` while any job is, then `passed` when every job passed, else `failed`. |
|
| 492 | 492 | - **Runner API** (runner token): `POST /api/v1/flow/claim` hands out the oldest queued job whose dependencies passed and whose tier the runner offers, marking it `running`, with a **job token**; `204` when there is none. `POST /api/v1/flow/jobs/{id}/log` appends log records (text cut at 16 KiB, at most 50 000 per job); `POST /api/v1/flow/jobs/{id}/finish` records the exit code and receipt (the hub recomputes the receipt hash) and settles dependents. Only the runner holding the job may report on it. |
|
| 493 | 493 | - **Runners** (Admin → Runners, site administrators). |
|
| … | 263 unchanged lines |
modified templates/flow_run.html +3 −2
| … | 43 unchanged lines |
||
| 44 | 44 | </details>{% endfor %} |
|
| 45 | 45 | {% if t.broken() > l.failures.len() as i64 %}<p class="small mute">and {{ t.broken() - l.failures.len() as i64 }} more failures; the junit artifact has them all.</p>{% endif %} |
|
| 46 | 46 | </div>{% endif %} |
|
| 47 | - | <pre class="flow-log" data-log data-seq="{{ l.last_seq }}">{% for line in l.lines %}<span class="ln s-{{ line.stream }}"><span class="t">{{ line.t / 1000 }}.{{ "{:01}"|format(line.t % 1000 / 100) }}s</span>{{ line.text }}</span> |
|
| 48 | - | {% endfor %}</pre> |
|
| 47 | + | <pre class="flow-log" data-log data-seq="{{ l.last_seq }}">{% for seg in l.segments %}{% match seg %}{% when crate::web::flow::Segment::Line(line) %}<span class="ln s-{{ line.stream }}"><span class="t">{{ crate::web::flow::secs(line.t) }}</span>{{ line.text }}</span> |
|
| 48 | + | {% when crate::web::flow::Segment::Group(g) %}<details class="log-group" data-from="{{ g.from_t }}"{% if g.to_t.is_none() %} open data-open-group{% endif %}><summary class="ln"><span class="t">{{ crate::web::flow::secs(g.from_t) }}</span>{{ g.title }}{% if let Some(e) = g.to_t %} <span class="took">{{ crate::web::flow::secs(e - g.from_t) }}</span>{% endif %}</summary>{% for line in g.lines %}<span class="ln s-{{ line.stream }}"><span class="t">{{ crate::web::flow::secs(line.t) }}</span>{{ line.text }}</span> |
|
| 49 | + | {% endfor %}</details>{% endmatch %}{% endfor %}</pre> |
|
| 49 | 50 | {% if !l.j.placed.is_empty() %}<p class="small mute pad">Ran on {{ l.j.runner }}: {{ l.j.placed }}.</p>{% endif %} |
|
| 50 | 51 | {% if l.j.status == "queued" && !l.j.waiting.is_empty() %}<p class="small warn pad" data-waiting>Waiting: {{ l.j.waiting }}.</p>{% else if l.lines.is_empty() && l.j.status == "queued" %}<p class="small mute pad">Waiting for a runner{% if !l.j.depends_on().is_empty() %} and for {{ l.j.depends_on().join(", ") }}{% endif %}.</p>{% endif %} |
|
| 51 | 52 | {% if l.lines.is_empty() && l.j.status == "skipped" %}<p class="small mute pad">Skipped: a job it depends on did not pass.</p>{% endif %} |
|
| … | 4 unchanged lines |
modified templates/style.css +4 −0
| … | 496 unchanged lines |
||
| 497 | 497 | .tests-failure pre.flow-log { padding: 6px 8px; margin: 4px 0; white-space: pre-wrap; word-break: break-word; max-height: 24em; overflow: auto; } |
|
| 498 | 498 | pre.flow-log .ln { display: block; padding: 0 12px; white-space: pre-wrap; word-break: break-word; } |
|
| 499 | 499 | pre.flow-log .t { display: inline-block; min-width: 5.5em; color: var(--mute); user-select: none; } |
|
| 500 | + | pre.flow-log details.log-group > summary { cursor: pointer; font-weight: 600; list-style: none; } |
|
| 501 | + | pre.flow-log details.log-group > summary::before { content: "▸ "; color: var(--mute); } |
|
| 502 | + | pre.flow-log details.log-group[open] > summary::before { content: "▾ "; } |
|
| 503 | + | pre.flow-log details.log-group > summary .took { font-weight: 400; color: var(--mute); margin-left: 6px; } |
|
| 500 | 504 | pre.flow-log .s-err { color: color-mix(in srgb, var(--bad) 75%, var(--ink)); } |
|
| 501 | 505 | pre.flow-log .s-flow, pre.flow-log .s-console { color: var(--mute); font-style: italic; } |
|
| 502 | 506 | table.flow-runs td.st { width: 1.5em; } |
|
| … | 674 unchanged lines |