MagicBeanDev/Hookshot
Archived
Watch
6
0
Fork
You've already forked Hookshot
 0
Code Issues 125 Pull requests 205 Activity

feat(build): build_times.json and the build's last lines say where the time went #2693

Closed
github-sync wants to merge 1 commit from github/pr/2693 into main
pull from: github/pr/2693
merge into: MagicBeanDev:main
Conversation 1 Commits 1 Files changed 2 +146 -3
github-sync commented 2026-11-12 07:27:35 +00:00
Owner

@jordanella opened this pull request on GitHub · 2026-11-12 06:35 UTC · original
Merged on GitHub in a9d5a0b14b

A build says its total and its compile time, and nothing about the rest. On Windows a clean build spends ~20 minutes outside the compile, and a one-file edit's build ~10 s, with no line saying where. This is the dev-loop proposal's A1 (#2636): the measurement the later items wait on.

Change

  • Every stage is timed: make_game.py times checks, read, lift, compile and finish from its own @@stage lines.
  • So are the parts it can see from lines the steps already print:
    • the lift's steps (lift: <step> in Ns, discovered ... (Ns));
    • build.py's planning, from its start to its <n> files, <n> jobs line, when every source has been read and hashed for its object key;
    • the compile (compiled in Ns);
    • each link (linked <file>: ... (Ns)).
  • The times are kept: they go into the build's entry in build_times.json as "phases", and the build ends with a table.
  • Nothing new for the Builders: no new @@ line, they read the same lines as before, and @@times is unchanged.

From a real build on Windows (Ryzen 9 3900X, NVMe), one gpu/vk/vk_draw.cpp edit:

where the time went:
  checks                                  2 s
  read                                    0 s
  lift                                    0 s
  compile                                28 s
    planning                              8 s
    compiling                            18 s
    linking hookshot.exe                  3 s
    linking hookshot_vk.dll               0 s
  finish                                  2 s
the build took 0:00:32, compiled in 0:00:28 (the last one 0:00:21)

The first thing it shows: planning, mostly reading and hashing ~1.4 GB of lifted C to compute object keys, is 7.5 s of a 32 s edit build. That makes A5 (a stat cache in front of the content hash) worth doing next.

Testing

  • tests/test_build_times.py: five new tests.
    • The clock against the real line formats, with a fake time source.
    • A stage entered twice adds up, and planning counts only in the compile stage.
    • The phases are stored with the build, and absent when none are given.
    • run() and say() feed the clock, and no @@phase line exists.
    • They fail against main's make_game.py; with this change all 19 tests pass.
  • A real build with this make_game.py printed the table above and wrote the same phases to build_times.json.
  • Every check that reads make_game.py (52), on Windows, passes apart from test_cpp_preflight, test_linux_update and test_prepare_stall, which fail the same way on a clean main here.
  • Not tested here: the Builder's window with the new lines. They're ordinary log lines, and it acts only on the @@ lines it knows.

🤖 Generated with Claude Code

> [@jordanella](https://github.com/jordanella) opened this pull request on GitHub · 2026-11-12 06:35 UTC · [original](https://github.com/NotRexed/Hookshot/pull/2693) > **Merged on GitHub** in https://git.magicbean.dev/MagicBeanDev/Hookshot/commit/a9d5a0b14b788a2e18d2a12d8fcac27edd28934c A build says its total and its compile time, and nothing about the rest. On Windows a clean build spends ~20 minutes outside the compile, and a one-file edit's build ~10 s, with no line saying where. This is the dev-loop proposal's A1 (#2636): the measurement the later items wait on. ## Change - **Every stage is timed:** `make_game.py` times checks, read, lift, compile and finish from its own `@@stage` lines. - **So are the parts it can see from lines the steps already print:** - the lift's steps (`lift: <step> in Ns`, `discovered ... (Ns)`); - `build.py`'s **planning**, from its start to its `<n> files, <n> jobs` line, when every source has been read and hashed for its object key; - the compile (`compiled in Ns`); - each link (`linked <file>: ... (Ns)`). - **The times are kept:** they go into the build's entry in `build_times.json` as `"phases"`, and the build ends with a table. - **Nothing new for the Builders:** no new `@@` line, they read the same lines as before, and `@@times` is unchanged. From a real build on Windows (Ryzen 9 3900X, NVMe), one `gpu/vk/vk_draw.cpp` edit: ``` where the time went: checks 2 s read 0 s lift 0 s compile 28 s planning 8 s compiling 18 s linking hookshot.exe 3 s linking hookshot_vk.dll 0 s finish 2 s the build took 0:00:32, compiled in 0:00:28 (the last one 0:00:21) ``` **The first thing it shows:** planning, mostly reading and hashing ~1.4 GB of lifted C to compute object keys, is 7.5 s of a 32 s edit build. That makes A5 (a stat cache in front of the content hash) worth doing next. ## Testing - **`tests/test_build_times.py`:** five new tests. - The clock against the real line formats, with a fake time source. - A stage entered twice adds up, and planning counts only in the compile stage. - The phases are stored with the build, and absent when none are given. - `run()` and `say()` feed the clock, and no `@@phase` line exists. - They fail against `main`'s `make_game.py`; with this change all 19 tests pass. - **A real build** with this `make_game.py` printed the table above and wrote the same phases to `build_times.json`. - **Every check that reads `make_game.py` (52), on Windows,** passes apart from `test_cpp_preflight`, `test_linux_update` and `test_prepare_stall`, which fail the same way on a clean `main` here. - **Not tested here:** the Builder's window with the new lines. They're ordinary log lines, and it acts only on the `@@` lines it knows. 🤖 Generated with [Claude Code](https://claude.com/claude-code) <!-- github-sync:item:2693 -->
A build said its total and its compile time, and nothing of the rest: on Windows a clean build spent ~20 minutes outside
the compile, and an edit's build ~10 s, with no line saying where (the dev-loop proposal's A1, #2636).

make_game.py now times each stage (checks, read, lift, compile, finish) from its own @@stage lines, and the parts it
knows from the lines the steps already print: the lift's steps ("lift: <step> in Ns", "discovered ... (Ns)"), build.py's
planning (its start to "<n> files, <n> jobs", where every source is read and hashed for its object key), the compile
("compiled in Ns") and each link ("linked <file>: ... (Ns)"). They go into the build's entry in build_times.json as
"phases", and the build ends with a "where the time went" table. No new @@ line: the builders read the same lines as
before. tests/test_build_times.py checks the clock against those lines, the record, and that run() and say() feed it.

Co-Authored-By: Claude Opus 5.5 (1M context) <[email protected]>
github-sync commented 2026-11-12 14:44:19 +00:00
Author
Owner

@Joey-Magnus approved on GitHub · 2026-11-12 14:34 UTC · original

I merged this into current main and ran tests/test_build_times.py: 19 tests OK. PhaseClock only reads lines the steps already print, and there's no new @@ line, so the Builders' parsers see the same output as before. In the KEPT_STALE path, make_game.py re-enters "lift" and then "compile", so since resets and the second build.py run's planning time isn't counted from the first one's start. The PLANNED match is limited to the compile stage, so a lift line that happens to look like "N files, N jobs" can't count as planning. I also merged it on top of #2686 and #2706: both merge cleanly and the tests still pass. #2706 doesn't change build.py's "N files, N jobs" or "compiled in" lines, which this depends on. The 7.5 s of planning in a 32 s edit build is a useful number for the next step.

> [@Joey-Magnus](https://github.com/Joey-Magnus) approved on GitHub · 2026-11-12 14:34 UTC · [original](https://github.com/NotRexed/Hookshot/pull/2693#pullrequestreview-5876234555) I merged this into current main and ran `tests/test_build_times.py`: 19 tests OK. `PhaseClock` only reads lines the steps already print, and there's no new `@@` line, so the Builders' parsers see the same output as before. In the KEPT_STALE path, `make_game.py` re-enters "lift" and then "compile", so `since` resets and the second `build.py` run's planning time isn't counted from the first one's start. The `PLANNED` match is limited to the compile stage, so a lift line that happens to look like "N files, N jobs" can't count as planning. I also merged it on top of #2686 and #2706: both merge cleanly and the tests still pass. #2706 doesn't change `build.py`'s "N files, N jobs" or "compiled in" lines, which this depends on. The 7.5 s of planning in a 32 s edit build is a useful number for the next step. <!-- github-sync:r:5876234555 -->
github-sync closed this pull request 2026-11-12 17:58:36 +00:00
Commenting is not possible because the repository is archived.
Reviewers
No reviewers
Labels
Clear labels   
accessibility
Barrier affecting people with disabilities

  
autorelease: pending

   
autorelease: tagged

   
bug
Something isn't working

  
dependencies
Pull requests that update a dependency file

  
documentation
Improvements or additions to documentation

  
duplicate
This issue or pull request already exists

  
enhancement
New feature or request

  
github_actions
Pull requests that update GitHub Actions code

  
good first issue
Good for newcomers

  
help wanted
Extra attention is needed

  
invalid
This doesn't seem right

  
question
Further information is requested

  
testing wanted

   
wontfix
This will not be worked on

No labels
accessibility
autorelease: pending
autorelease: tagged
bug
dependencies
documentation
duplicate
enhancement
github_actions
good first issue
help wanted
invalid
question
testing wanted
wontfix
Milestone
Clear milestone
No items
No milestone
Assignees
Clear assignees
No assignees
1 participant
Due date
The due date is invalid or out of range. Please use the format "yyyy-mm-dd".

No due date set.

Dependencies

No dependencies set

Reference
MagicBeanDev/Hookshot!2693
No description provided.