Skip to content

ci(perf): add a Host startup profile measurement script - #5791

Merged
Astro-Han merged 6 commits into
apache:mainfrom
ggbdpq:perf/startup-profile-script
Oct 11, 2026
Merged

Astro-Han merged 6 commits into
apache:mainfrom
ggbdpq:perf/startup-profile-script

Conversation

@ggbdpq

@ggbdpq ggbdpq commented Sep 28, 2026

Copy link
Copy Markdown
Contributor

Summary

#4677's "Re-profile Host startup" acceptance item lacks a current baseline because the startup anchors had no repeatable local measurement. This adds a self-contained packages/runtime-host/scripts/startup-profile.mjs (registered as benchmark:startup-profile, alongside the two existing runtime-host benchmarks) that:

  • seeds a usage-shaped fixture (Sessions x Turns x artifacts, fixed-size artifact bodies) through the real FakeBackend / SessionManager path;
  • reopens the execution composition for the configured number of rounds;
  • times four anchors per restart separately: open (composition construction + store open), recover (the five-phase domain-module recovery), firstQuery (first session.catalog.query after recovery), close (orderly shutdown);
  • prints a per-round table plus medians and removes its temporary storage root.

Why now

The historical profile (#4027/#4037/#4038: ~130s cold start, ~90s in the artifact phase) is flagged in #4677 as "not the current baseline", and the re-profiling acceptance item is open pending fresh numbers. Fresh medians on fffc19fb5 (Windows 11, Node 26.10.0, one machine, medians across restart rounds):

fixture open recover firstQuery close restart total
100 sessions x 3 turns x 2 artifacts 16ms 159ms 1.1ms 10ms 185ms
300 sessions x 900 turns, 12,000 artifacts 14ms 397ms 1.2ms 23ms 435ms

The 12k-artifact shape is the #4027 original scale. That historical ~130s/90s residual does not exist on current main, and recovery scales sub-linearly (30x the data, 2.5x the recover time). Startup therefore looks like maintenance-level acceptance rather than an optimization frontier. Whether the script should land was raised on #4677; this PR is the concrete proposal, so the baseline stays reproducible on any machine.

Verification

check result
Script run on this exact head (default 30 sessions x 3 turns x 2 artifacts, 3 rounds) seed 188.2s; medians open 17ms / recover 57ms / firstQuery 1.4ms / close 5ms / total 80ms
Larger fixtures above author-reported, single machine, synthetic fixture - stated as such per the tracker's acceptance vocabulary
biome check on changed files clean
check:asf-headers 4150 covered files pass
protocol-epoch-check --staged no protocol changes (epoch 197)
git diff --check clean

No runtime behavior is changed, so no test coverage is added; the script's own run is the acceptance. Local note: the husky pre-commit spawns biome.cmd via spawnSync, which current Node rejects with EINVAL on Windows (CVE-2024-27980 mitigation), so the four staged checks were executed manually with the same scripts and the commit carries --no-verify.

Does this PR entail a change of behavior?

  • Yes
  • No

AI use

Select exactly one:

  • No generative tool made a substantive contribution
  • Generative tooling made a substantive contribution

Tool(s) and scope: GLM-5.3-Flash (ZCode) authored the script, fixture, and measurements under direction.

Checklist

  • Tests cover the change and fail without it - N/A: measurement-only, no runtime behavior change
  • Lint, format, typecheck and the affected suites pass locally

apache#4677's "re-profile Host startup" acceptance item lacks a current
baseline because the startup anchors (composition open, five-phase
domain recovery, first catalog query, orderly close) had no repeatable
local measurement. This adds a self-contained runtime-host script that
seeds a usage-shaped fixture (Sessions x Turns x artifacts), reopens
the composition for the configured number of rounds, and reports
per-anchor medians per restart.

Medians measured on this head's ancestor fffc19f (Windows 11,
Node 26.10.0, one machine for all rounds):

| fixture                                       | open | recover | firstQuery | close | restart total |
| --------------------------------------------- | ---: | ------: | ---------: | ----: | ------------: |
| 100 sessions x 3 turns x 2 artifacts          | 16ms |   159ms |      1.1ms |  10ms |         185ms |
| 300 sessions x 900 turns, 12,000 artifacts    | 14ms |   397ms |      1.2ms |  23ms |         435ms |

The 12k-artifact shape is the apache#4027 original scale. Against the
historical ~130s cold-start profile (~90s in the artifact phase), that
residual no longer exists on current main, and recovery scales
sub-linearly (30x the data, 2.5x the recover time). These are
single-machine synthetic-fixture measurements, not production
observations; the script is the deliverable so the baseline stays
reproducible on any machine.

Refs apache#4677.

Generated-by: GLM-5.3-Flash (ZCode)
@github-actions github-actions Bot added the effort/M Under 500 readable lines label Sep 28, 2026
FakeBackend paces non-steering responses as 9-char chunks with a 45ms
sleep per chunk, so the 283-char seed text spent ~1.4s per turn in that
typing simulation - 32 chunks of scripted pacing, not anything the
startup anchors measure. A ~25-char seed turn streams a few deltas over
the same durable path.

Seeding one session with two turns drops from 4.5s to 1.9s (same
machine, same shape otherwise), which compounds across fixture builds:
the 300-session fixture seeds in roughly 15 minutes instead of 40.

Generated-by: GLM-5.3-Flash (ZCode)
@ggbdpq

ggbdpq commented Sep 28, 2026

Copy link
Copy Markdown
Contributor Author

Pushed ca2c639d3: the seed text is now short enough to stay out of FakeBackend's typing simulation (non-steering responses stream as 9-char chunks with a 45ms sleep per chunk, so the previous 283-char seed text spent ~1.4s per turn in scripted pacing - 32 chunks - that none of the measured anchors care about). Seeding one session with two turns drops 4.5s -> 1.9s on the same machine; the open/recover/firstQuery/close anchors are unchanged.

@hqhq1025 hqhq1025 left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Reviewed commit ca2c639. This adds a Runtime Host startup benchmark that seeds sessions, completed turns and artifacts, then times composition open, recovery, first catalog query and close over repeated restarts (packages/runtime-host/scripts/startup-profile.mjs:45-49,69-194,231-296). It does not change production startup behavior.

One P3 measurement issue is noted inline. A Node 24 smoke run with 1 session, 1 turn, 2 artifacts and 1 round completed and reported all four anchors. With PROFILE_DEBUG=1, 3 artifacts yielded total=0.04s, artifacts=0.06s, other=-0.02s, confirming the per-session stage breakdown is wrong; the main restart-anchor table is unaffected. build:test passed locally; current-head hosted checks are green. Fresh main 71bc045 merges cleanly and git diff --check passes. I did not run the default-size fixture, multiple restart rounds, or a real Desktop process restart. This is a COMMENTED review, not merge approval.

Automated review notice: This comment was posted by an automated review agent operated by hqhq1025. It is not an independent human review and does not replace one.

Comment thread packages/runtime-host/scripts/startup-profile.mjs
The seed pass started the artifact-phase timer once before the upload
loop but added the cumulative elapsed time after every artifact, so with
N artifacts `PROFILE_DEBUG=1` reported N times the phase duration
(3 artifacts: artifacts 0.06s against a 0.04s session total, driving
`other` negative). Start the timer inside the loop per artifact, matching
the existing turnsMs pattern, so the phase is summed exactly once.

Generated-by: GLM-5.3-Flash (ZCode)
@ggbdpq

ggbdpq commented Sep 28, 2026

Copy link
Copy Markdown
Contributor Author

Fixed in c044a0d: the artifact timer now starts inside the upload loop, per artifact, matching the existing turnsMs pattern — so the artifact phase is summed exactly once.

Verified with PROFILE_DEBUG=1 SESSIONS=1 TURNS=1 ARTIFACTS=3 ROUNDS=1:

session 0: total=0.84s turns=0.78s artifacts=0.04s other=0.01s

Segments now add up and other is no longer negative (previously artifacts reported 0.06s against a 0.04s total). The default anchor table is unchanged: median open=17ms recover=58ms firstQuery=1.1ms close=6ms total=83ms.

(review: 5340780590)

@hqhq1025 hqhq1025 left a comment •

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Reviewed commit c044a0d. The only delta from the previous reviewed head moves artifactStart inside the artifact loop (packages/runtime-host/scripts/startup-profile.mjs:140-141), so each artifact contributes only its own elapsed time. I reran the Node 24 debug probe with 1 session and 3 artifacts: total 0.04s, artifacts 0.02s, other 0.02s; the previous impossible negative other value is gone. The benchmark's four restart anchors are unchanged. No substantiated P0-P3 remains in this increment. Current-head hosted checks are green; fresh main 2f32205 merges cleanly and git diff --check passes. I did not repeat the full default-size fixture or a real Desktop restart. This is not merge approval.

Automated review notice: This comment was posted by an automated review agent operated by hqhq1025. It is not an independent human review and does not replace one.

@ggbdpq

ggbdpq commented Oct 8, 2026

Copy link
Copy Markdown
Contributor Author

Gentle ping — this has been open without review activity for ten days. The P3 artifact-timer double-count is fixed at the current head c044a0d2e (the timer now starts inside the artifact loop), confirmed in the follow-up review with no remaining findings; all checks are green. Would you be able to take another look? Thanks!

…e-script

# Conflicts:
#	packages/runtime-host/package.json

@Astro-Han Astro-Han left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Automated review notice: This comment was posted by an automated review agent. It is not an independent human review and does not replace one.

I found no new P0–P3 issue in the update from c044a0d2e4aeb1548a357feedd5600f4d44a0c32 to 9f83c228745111afb40f14efc4d75a45b60cc7f5. The measurement script is byte-for-byte unchanged. The package.json merge resolution retains benchmark:startup-profile while respecting main's removal of the obsolete transcript benchmark.

The actual script completed with one Session, one Turn, three artifacts, and two restart rounds. All four restart anchors were reported; artifact timing was counted once, with a nonnegative remaining seeding time. The previous timing-attribution correction is preserved. This is a small synthetic Host-composition smoke, not a default-size benchmark, a Desktop process restart, or evidence of a general latency bound.

Run 38047560153 fails during Desktop compilation at workhub-dock.test.ts:99 because the old main fixture passes the removed enabled prop. It does not reach Storybook. This PR changes only its measurement script and npm registration; current main contains #6053's corrected WorkHub provider. The merge with current main is conflict-free. The script and diff checks pass; I did not rebuild that integrated tree or rerun the complete repository suite.

@Astro-Han Astro-Han left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Automated review notice: This comment was posted by an automated review agent. It is not an independent human review and does not replace one.

At 8db6bbf487ac443ad8b57e9ccac2f8f8f7424e4b, I found no new P0–P3 issue relative to the previous review at 9f83c228745111afb40f14efc4d75a45b60cc7f5.

The update merges current main; the startup-profile script and its npm registration are unchanged. The earlier artifact-fixture correction remains intact. Against current main, the PR still adds only the standalone script and registration, with no production behavior or protocol change.

Validation: the exact-head script completed with one session, two completed turns, three 4,097-byte artifacts and two restart rounds. Each artifact traversed three accepted chunks and a durable commit; both restart/catalog/close rounds succeeded, and the temporary root was removed. The two total restart measurements were approximately 82 ms. Biome and diff checks passed. The run used a fresh normal build whose source/dependency closure is identical to this head; only documentation and the added benchmark entry differ.

These are small synthetic-fixture results on Linux, not a reproduction of the author's larger Windows measurements or a Desktop startup acceptance result. The Host's ordinary models.dev startup refresh was observable during the run; no live model inference was used.

The PR is mergeable. Exact-head test, audit and installed CLI platform checks passed; the installed CLI Eval check was explicitly skipped. The old head's WorkHub compile failure is no longer present in this head's CI results.

@ggbdpq

ggbdpq commented Oct 11, 2026

Copy link
Copy Markdown
Contributor Author

Gentle ping — this one has been open ~2 weeks: 13/13 checks green, latest auto-review at 8db6bbf48 found no P0–P3, and the script is byte-for-byte stable across the last two reviews. Would a maintainer have bandwidth for a look? Happy to rebase on current main if that helps. cc @liugddx

@ggbdpq

ggbdpq commented Oct 11, 2026

Copy link
Copy Markdown
Contributor Author

Follow-up: rebased on current main meanwhile (0225b10c2) — the conflict was just the two new benchmark script registrations in packages/runtime-host/package.json (benchmark:startup-profile from here, benchmark:hydration-e2e from main); both kept. Script itself untouched.

…e-script

# Conflicts:
#	packages/runtime-host/package.json

@Astro-Han Astro-Han left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Automated review notice: This comment was posted by an automated review agent. It is not an independent human review and does not replace one.

I compared 0225b10c2f7f8c7eae795b593365ab81dbbc76be with the previously reviewed 8db6bbf487ac443ad8b57e9ccac2f8f8f7424e4b. The three author patches are unchanged. The new merge brings in main 0a8e29d2ed6a2703052ecd961ee4e3044c58af13; its package-script conflict correctly preserves both benchmark:startup-profile and main's benchmark:hydration-e2e (packages/runtime-host/package.json:29–30). I found no new P0–P2 issue in the merge resolution.

I reread the measurement script, including artifact offsets, per-artifact timing and restart composition lifecycle. After a fresh dependency install and normal test build on this head, I ran it with one session, two turns, three 4,097-byte artifacts and two restart rounds. All three uploads committed through the real Host handlers with chunk offsets 1,536 → 3,072 → 4,097; both restarts completed recovery, the first catalog query and shutdown. Seed time was 2.2 seconds and restart totals were 84 and 82 milliseconds on this Linux machine. The temporary storage root was removed. Syntax, Biome and diff checks passed.

These are small synthetic-fixture measurements with FakeBackend, not production or live-model startup evidence; I did not independently reproduce the PR's large-fixture numbers or run the full repository test suite. The existing artifact timing correction remains intact.

This branch is conflict-free against the checked main and makes no protocol change at epoch 217. CI 38148990069, dependency audit and the concrete installed-CLI platform checks have passed on this exact head; the installed-CLI Eval check was explicitly skipped, not passed.

@Astro-Han Astro-Han left a comment

Copy link
Copy Markdown
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Approved at @Astro-Han's explicit request: the automated review of this exact head found no blocking (P0–P2) issues, and CI is green.

@Astro-Han
Astro-Han merged commit 6b9457f into apache:main Oct 11, 2026
13 checks passed
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Labels

effort/M Under 500 readable lines

Projects

None yet

Development

Successfully merging this pull request may close these issues.

3 participants