Public: anyone can read this; the crew can change it.
An issue page's Server-Timing names its phases: session, thread, links, render #3222
Check · Review · Land · Live done — Landed and live in production.
scout/forge:scout/3193-an-issue-page-s-server-timing-names-its → main 1 commit fork 2 threads · 2 unresolved
2 files
changed +66
−4
src/web/studio/tell.ts +28 −4
| @@ -8,6 +8,7 @@ | ||
| 8 | 8 | * one closed Details section. |
| 9 | 9 | */ |
| 10 | 10 | |
| 11 | import { notePhase, takeSessionTime } from "../../core/route_timing.ts"; | |
| 11 | 12 | import { cardPath } from "../og/path.ts"; |
| 12 | 13 | import { mayEditIssue } from "../../actions/issues.ts"; |
| 13 | 14 | import { marksByName } from "../../core/marks.ts"; |
| @@ -264,6 +265,18 @@ async function studioTell( | ||
| 264 | 265 | issue: Issue, |
| 265 | 266 | ): Promise<Response> { |
| 266 | 267 | const db = ctx.app.db; |
| 268 | const { request } = ctx; | |
| 269 | const started = performance.now(); | |
| 270 | notePhase(request, "session", takeSessionTime(request)); | |
| 271 | let linksMs = 0; | |
| 272 | const links = <T>(work: () => T): T => { | |
| 273 | const t = performance.now(); | |
| 274 | try { | |
| 275 | return work(); | |
| 276 | } finally { | |
| 277 | linksMs += performance.now() - t; | |
| 278 | } | |
| 279 | }; | |
| 267 | 280 | const base = repoBase(repo); |
| 268 | 281 | // The only address the page *posts* to: the reply, the close and every |
| 269 | 282 | // Details form live under `/issues/:number`, whether a reader arrived |
| @@ -271,7 +284,7 @@ async function studioTell( | ||
| 271 | 284 | // does not move with the noun. |
| 272 | 285 | const thread = `${base}/issues/${issue.number}`; |
| 273 | 286 | const direction = repo.directionIssueId === issue.id; |
| 274 | const closingPull = openPullsClosing(db, repo.id).get(issue.number); | |
| 287 | const closingPull = links(() => openPullsClosing(db, repo.id).get(issue.number)); | |
| 275 | 288 | const wordCtx: WordCtx = { |
| 276 | 289 | db, |
| 277 | 290 | dir: repoDir(ctx.app.reposRoot, repo.ownerName, repo.name), |
| @@ -367,6 +380,7 @@ async function studioTell( | ||
| 367 | 380 | </div> |
| 368 | 381 | </div>`; |
| 369 | 382 | |
| 383 | const threadStart = performance.now(); | |
| 370 | 384 | const talk = conversation(ctx, repo, issue, { |
| 371 | 385 | openVerb: "opened this", |
| 372 | 386 | editAction: |
| @@ -374,6 +388,11 @@ async function studioTell( | ||
| 374 | 388 | ? `${repoBase(repo)}/issues/${issue.number}/edit` |
| 375 | 389 | : undefined, |
| 376 | 390 | }); |
| 391 | const threadMs = performance.now() - threadStart; | |
| 392 | const dependencies = links(() => | |
| 393 | dependenciesCard(ctx, repo, issue, `${thread}/dependencies`), | |
| 394 | ); | |
| 395 | const teams = links(() => issueTeamsCard(ctx, repo, issue, `${thread}/teams`)); | |
| 377 | 396 | const applied = labelsFor(db, issue.id); |
| 378 | 397 | const allLabels = listLabels(db, repo.id); |
| 379 | 398 | // Closed until asked for: neither is the next thing a person does here, |
| @@ -384,7 +403,7 @@ async function studioTell( | ||
| 384 | 403 | <summary>Details</summary> |
| 385 | 404 | ${assigneeCard(ctx, repo, issue, `${thread}/assignee`)} |
| 386 | 405 | ${labelsCard(ctx, repo, issue, applied, allLabels, `${thread}/labels`)} |
| 387 | ${issueTeamsCard(ctx, repo, issue, `${thread}/teams`)} | |
| 406 | ${teams} | |
| 388 | 407 | ${sealCard(ctx, repo, issue, `${thread}/seal`)} |
| 389 | 408 | </details>`; |
| 390 | 409 | |
| @@ -409,7 +428,7 @@ async function studioTell( | ||
| 409 | 428 | ${privateWorkCard(ctx, repo, issue, `${thread}/private`)} |
| 410 | 429 | ${runsCard} |
| 411 | 430 | ${closingCard} |
| 412 | ${dependenciesCard(ctx, repo, issue, `${thread}/dependencies`)} | |
| 431 | ${dependencies} | |
| 413 | 432 | ${details} |
| 414 | 433 | </aside> |
| 415 | 434 | </div> |
| @@ -420,7 +439,7 @@ async function studioTell( | ||
| 420 | 439 | lastCommentId: talk.lastCommentId, |
| 421 | 440 | })}`; |
| 422 | 441 | |
| 423 | return page({ | |
| 442 | const response = page({ | |
| 424 | 443 | ctx, |
| 425 | 444 | title: `${issue.title} · ${repo.name}`, |
| 426 | 445 | ogImage: cardPath("issue", repo, issue), |
| @@ -436,6 +455,11 @@ async function studioTell( | ||
| 436 | 455 | styleCss: labelCss([...allLabels, ...applied]), |
| 437 | 456 | scriptJs: liveClientJs, |
| 438 | 457 | }); |
| 458 | // Render is what is left of the page's own time once the named phases are out. | |
| 459 | notePhase(request, "thread", threadMs); | |
| 460 | notePhase(request, "links", linksMs); | |
| 461 | notePhase(request, "render", Math.max(0, performance.now() - started - linksMs - threadMs)); | |
| 462 | return response; | |
| 439 | 463 | } |
| 440 | 464 | |
| 441 | 465 | /** |
test/issue-timing.test.ts added +38
| @@ -0,0 +1,38 @@ | ||
| 1 | /** An issue page's Server-Timing names session, thread, links and render, and they fit inside app. */ | |
| 2 | import { afterAll, beforeAll, expect, test } from "bun:test"; | |
| 3 | import { snappyFixture, type SnappyFixture } from "../bench/snappy.ts"; | |
| 4 | ||
| 5 | let f: SnappyFixture; | |
| 6 | ||
| 7 | beforeAll(async () => { | |
| 8 | f = await snappyFixture(); | |
| 9 | }, 120_000); | |
| 10 | afterAll(async () => { | |
| 11 | await f.close(); | |
| 12 | }); | |
| 13 | ||
| 14 | async function timing(cookie?: string): Promise<Map<string, number>> { | |
| 15 | const repo = f.repos[0]!; | |
| 16 | const res = await fetch(`${f.base}/${repo.ownerName}/${repo.name}/issues/4`, { | |
| 17 | headers: cookie ? { cookie } : {}, | |
| 18 | }); | |
| 19 | await res.arrayBuffer(); | |
| 20 | expect(res.status).toBe(200); | |
| 21 | const got = new Map<string, number>(); | |
| 22 | for (const part of (res.headers.get("server-timing") ?? "").split(", ")) { | |
Only /issues/4 is requested. /tells/:n goes through the same handler, so add one request there. |
||
| 23 | const m = /^([a-z-]+);dur=(\d+\.\d)/.exec(part); | |
| 24 | if (m) got.set(m[1]!, Number(m[2])); | |
| 25 | } | |
| 26 | return got; | |
| 27 | } | |
| 28 | ||
| 29 | for (const who of ["owner", "anonymous"] as const) { | |
| 30 | test(`${who}: the issue page names its four phases and they sum to no more than app`, async () => { | |
| 31 | const got = await timing(who === "owner" ? f.ownerCookie : undefined); | |
| 32 | const phases = ["session", "thread", "links", "render"]; | |
| 33 | for (const name of phases) expect(got.has(name)).toBe(true); | |
| 34 | const sum = phases.reduce((n, name) => n + got.get(name)!, 0); | |
| 35 | // Each is rounded to a tenth of a millisecond. | |
| 36 | expect(sum).toBeLessThanOrEqual(got.get("app")! + 0.4); | |
| 37 | }); | |
| 38 | } |
new above
offline
render absorbs the awaited cards (word, runs, closing) and the Details cards. Fine for now, but name those phases later so render says what it costs.