MagicBeanDev/Longshot

Watch

Fork 19

WIP: feat(profile): HOS_HLE_STATS=1 counts HLE, host-call and NVN export calls #153

Draft

klimovich008 wants to merge 8 commits from klimovich008/Longshot:feat/hle-call-counters into main

klimovich008 commented

2026-11-13 07:34:37 +00:00

First-time contributor

Port of NotRexed/Hookshot#2580 (draft there). It went through five gpt-6.1-sol review rounds, as that PR's description says. Each round's findings were fixed, and the last round found none. It has no GitHub reviews. The commits are the same, rebased onto Longshot main, plus one that gives the test Longshot's file names.

Why

The CPU profile's calls column came from a local patch that nobody else could rebuild. With this PR, anyone can count how often each HLE function, host call and NVN export runs, behind a switch that is off by default.

What changed

host/hos.h: the HLE(sym) macro counts entries in a tail-called arm (hos_hle_counted). With counting off, an entry pays one flag test and a branch.
host/hos_hostcall.c: logs hle: blocks about every 5 s, each stamped with the monotonic clock times it covers (begin_ns, end_ns). Host calls are counted in a64_call_miss and a64_lookup_host. The host-call table is read under its lock and the counters are published atomically. If the report thread can't start, counting stays off.
host/hos_main.c: turns counting on before the game starts.
host/nvn_native.c: counts SDK export calls in nvn2_dispatch.
scripts/cpu_report.py (--calls):
- joins only complete, timed blocks inside the measured window to native frame returns over the same clock span;
- estimates time per call as sampled occupancy, from the same run's HOS_SAMPLE_ALL stacks;
- reads logs without timestamps for rates only, with no per-frame or per-call figures.
scripts/crit.py: names an HLE body that wasn't inlined after its imp_<sym> entry.
docs/development.md, docs/cpu-profile.md: the switch and how to collect a counting run. The profile's existing calls and per-call columns predate the clock-checked joins, so they are marked for regeneration. This PR does not recompute them.
tests/test_hle_stats.py, tests/test_cpu_report.py: switching on and off, NVN exports, 32-bit wrap, concurrent callers with the reporter running, a failed thread start, the complete-block and window checks, and nine broken variants that must be caught.

Flags and settings

Flag	What it does	Default now	Recommendation	Helps on	Doesn't help on	Untested on
`HOS_HLE_STATS=1`	Logs `hle:` call counts about every 5 s, with clock boundaries, for `cpu_report.py --calls`	off	Keep off. It is a profiling switch, and performance numbers come from runs without it	Profiling	Play	Linux, web build

Measurements

These are the measurements from the Hookshot PR, taken before the move to Longshot. They were not repeated on Longshot main.

Baseline: Hookshot main @ 46780503. "This PR" is the same base with this PR's commits on top (the Hookshot branch). It was not remeasured on Longshot main, which has changed since that base. The figures use the old 32:9 standard test and are not comparable with 16:9 numbers.

main: Hookshot 46780503
this PR: Hookshot feat/hle-call-counters on 46780503 (the same commits as here)
Hardware: AMD RX 9070 XT (Adrenalin 26.10.2), Ryzen 7 5700X3D, 64 GB, Windows 11
Scene: Hyrule Field, fast camera turn; 32:9 (HOS_WINDOW_SIZE=2560x720, HOS_ASPECT=3.5556), HOS_FPS_MAX=240, HOS_FPS_LOG=1, no upscaler or frame generation
Method:

20 s window from the load, warm caches, 11 alternating pairs; HOS_HLE_STATS unset in both arms.
8 pairs were valid:
- pair 0 was dropped because another job ran beside it;
- pairs 1 and 3 were dropped for a game clock off 1.000 and a stall of over 250 ms inside the window, one in each arm.
The game clock was judged only from readings whose whole interval lies inside the window. That check drops the same two runs.
Only the exe's code differs between the arms. The renderer DLL includes host/hos.h, but its code and data match the base byte for byte, apart from the version string.
How to reproduce: the standard test with HOS_HLE_STATS unset, alternating main and this PR.

8 valid pairs	main @ `46780503`	this PR @ Hookshot `feat/hle-call-counters`, counting off
fps (median)	53.1	53.4
CPU ms a frame (median)	76.31	75.38
p99 frame, ms	24.77	23.63
frames over 250 ms	0	0

The per-pair difference in CPU ms a frame (this PR minus main) ranges from -4.5 to +2.4 ms. The mean is -0.31 and the median +0.10, and this PR is lower in 4 of the 8 pairs. No measurable cost.

One run with counting on (HOS_HLE_STATS=1, same base and hardware) checked the reporting end to end, not the cost:

All 18 hle: blocks were complete and timed, with no gaps between them.
Four fell wholly inside the measured play window and joined to 1,026 native frames over 20.005 s.
LockMutex and UnlockMutex came out within 0.1% of each other, at about 12,930 calls a frame each.

Testing

Tested:

On Longshot main @ 39647e1a. The branch was then rebased onto 6b7fa356, whose only change since (#148) is to the release script, its test and the README, none of which this PR touches:
- tests/test_hle_stats.py passes with llvm-mingw clang++ and with g++ (MSYS2 UCRT64), and tests/test_cpu_report.py passes.
- python -I -B tests/run_all.py (Windows, llvm-mingw 20261104): 466 passed, 4 failed, 69 skipped. The 4 also fail on main on this PC: nx2/test_nup_paths.py, tests/test_check_third_party.py, tests/test_setup_runtime.py, tests/test_release.py.
- Every host/*.c syntax-compiles with llvm-mingw, except five that need third-party headers not installed here (dav1d, zstd, opus, ffmpeg). None of the five use the counters.
In the game: the measurements above, run on Hookshot.

Not tested:

The per-call time estimates have not run on real data. On the enabled run, the game reached its first frame late on a fresh runtime, and the sampler's fixed window covered mostly the load. cpu_report.py --calls reported the estimates as unavailable instead of guessing, which is the intended behaviour. The estimate path is covered by the test fixtures only.
No game run on a Longshot build yet.
Linux and the web build.

Needs other testers:

Linux: HOS_HLE_STATS=1 logs hle: blocks and the game runs normally, with no change when the switch is off (request to open).

Screenshots

Nothing on screen.

Risk and rollback

The HLE(sym) macro is on every HLE entry's path. With counting off, the only change is one flag test, and the measurement above shows no cost. With it on, an extra thread wakes about every 5 s and every counted call does an atomic increment. Reverting the commits removes it all.

Reviewer notes

Start with hos.h (the macro) and hos_hostcall.c (the counters and the report thread). The calls and per-call columns already in docs/cpu-profile.md are left for a regenerated profile. This PR only marks them.

Issues

None.

Checklist

For everyone

One topic.
The title is a Conventional Commit (type(scope): description).
Rebased on current main.
python -I -B tests/run_all.py run and passing (any failure that also fails on main is named above).
Tested in the game, or what wasn't is named under Testing.
Testing filled in: what was tested, what wasn't, and what needs other testers (with test requests).
Measured: main and this PR at named commits, on the same PC, scene and settings, at least 2 interleaved runs each, the median reported.
No game files, dumps, build output or generated files.
third_party/ untouched (a new folder with a PROVENANCE.md instead).
The license is OK: GPL-3.0-or-later, nothing incompatible and nothing decompiled.

If applicable

AI assistance recorded with Assisted-by: / Co-Authored-By: trailers.
Flags noted, and the switch reference updated (docs/development.md, the README).
Host code builds on both Windows (llvm-mingw) and Linux, with UTF-8 paths. (Windows syntax compile only; Linux not built.)
Docs updated.

🤖 Generated with Claude Code

Port of [NotRexed/Hookshot#2580](https://github.com/NotRexed/Hookshot/pull/2580) (draft there). It went through five gpt-6.1-sol review rounds, as that PR's description says. Each round's findings were fixed, and the last round found none. It has no GitHub reviews. The commits are the same, rebased onto Longshot `main`, plus one that gives the test Longshot's file names. ## Why The CPU profile's calls column came from a local patch that nobody else could rebuild. With this PR, anyone can count how often each HLE function, host call and NVN export runs, behind a switch that is off by default. ## What changed - `host/hos.h`: the `HLE(sym)` macro counts entries in a tail-called arm (`hos_hle_counted`). With counting off, an entry pays one flag test and a branch. - `host/hos_hostcall.c`: logs `hle:` blocks about every 5 s, each stamped with the monotonic clock times it covers (`begin_ns`, `end_ns`). Host calls are counted in `a64_call_miss` and `a64_lookup_host`. The host-call table is read under its lock and the counters are published atomically. If the report thread can't start, counting stays off. - `host/hos_main.c`: turns counting on before the game starts. - `host/nvn_native.c`: counts SDK export calls in `nvn2_dispatch`. - `scripts/cpu_report.py` (`--calls`): - joins only complete, timed blocks inside the measured window to native frame returns over the same clock span; - estimates time per call as sampled occupancy, from the same run's `HOS_SAMPLE_ALL` stacks; - reads logs without timestamps for rates only, with no per-frame or per-call figures. - `scripts/crit.py`: names an HLE body that wasn't inlined after its `imp_<sym>` entry. - `docs/development.md`, `docs/cpu-profile.md`: the switch and how to collect a counting run. The profile's existing calls and per-call columns predate the clock-checked joins, so they are marked for regeneration. This PR does not recompute them. - `tests/test_hle_stats.py`, `tests/test_cpu_report.py`: switching on and off, NVN exports, 32-bit wrap, concurrent callers with the reporter running, a failed thread start, the complete-block and window checks, and nine broken variants that must be caught. ## Flags and settings | Flag | What it does | Default now | Recommendation | Helps on | Doesn't help on | Untested on | |---|---|---|---|---|---|---| | `HOS_HLE_STATS=1` | Logs `hle:` call counts about every 5 s, with clock boundaries, for `cpu_report.py --calls` | off | Keep off. It is a profiling switch, and performance numbers come from runs without it | Profiling | Play | Linux, web build | ## Measurements These are the measurements from the Hookshot PR, taken before the move to Longshot. They were not repeated on Longshot `main`. Baseline: Hookshot `main` @ 46780503. "This PR" is the same base with this PR's commits on top (the Hookshot branch). It was not remeasured on Longshot `main`, which has changed since that base. The figures use the old 32:9 standard test and are not comparable with 16:9 numbers. main: Hookshot 46780503 this PR: Hookshot `feat/hle-call-counters` on 46780503 (the same commits as here) Hardware: AMD RX 9070 XT (Adrenalin 26.10.2), Ryzen 7 5700X3D, 64 GB, Windows 11 Scene: Hyrule Field, fast camera turn; 32:9 (`HOS_WINDOW_SIZE=2560x720`, `HOS_ASPECT=3.5556`), `HOS_FPS_MAX=240`, `HOS_FPS_LOG=1`, no upscaler or frame generation Method: - 20 s window from the load, warm caches, 11 alternating pairs; `HOS_HLE_STATS` unset in both arms. - 8 pairs were valid: - pair 0 was dropped because another job ran beside it; - pairs 1 and 3 were dropped for a game clock off 1.000 and a stall of over 250 ms inside the window, one in each arm. - The game clock was judged only from readings whose whole interval lies inside the window. That check drops the same two runs. - Only the exe's code differs between the arms. The renderer DLL includes `host/hos.h`, but its code and data match the base byte for byte, apart from the version string. How to reproduce: the standard test with `HOS_HLE_STATS` unset, alternating main and this PR. | 8 valid pairs | main @ 46780503 | this PR @ Hookshot `feat/hle-call-counters`, counting off | |---|---|---| | fps (median) | 53.1 | 53.4 | | CPU ms a frame (median) | 76.31 | 75.38 | | p99 frame, ms | 24.77 | 23.63 | | frames over 250 ms | 0 | 0 | The per-pair difference in CPU ms a frame (this PR minus main) ranges from -4.5 to +2.4 ms. The mean is -0.31 and the median +0.10, and this PR is lower in 4 of the 8 pairs. No measurable cost. **One run with counting on** (`HOS_HLE_STATS=1`, same base and hardware) checked the reporting end to end, not the cost: - All 18 `hle:` blocks were complete and timed, with no gaps between them. - Four fell wholly inside the measured play window and joined to 1,026 native frames over 20.005 s. - `LockMutex` and `UnlockMutex` came out within 0.1% of each other, at about 12,930 calls a frame each. ## Testing **Tested:** - On Longshot `main` @ 39647e1a. The branch was then rebased onto 6b7fa356, whose only change since (#148) is to the release script, its test and the README, none of which this PR touches: - `tests/test_hle_stats.py` passes with llvm-mingw clang++ and with g++ (MSYS2 UCRT64), and `tests/test_cpu_report.py` passes. - `python -I -B tests/run_all.py` (Windows, llvm-mingw 20261104): 466 passed, 4 failed, 69 skipped. The 4 also fail on `main` on this PC: `nx2/test_nup_paths.py`, `tests/test_check_third_party.py`, `tests/test_setup_runtime.py`, `tests/test_release.py`. - Every `host/*.c` syntax-compiles with llvm-mingw, except five that need third-party headers not installed here (dav1d, zstd, opus, ffmpeg). None of the five use the counters. - In the game: the measurements above, run on Hookshot. **Not tested:** - **The per-call time estimates have not run on real data.** On the enabled run, the game reached its first frame late on a fresh runtime, and the sampler's fixed window covered mostly the load. `cpu_report.py --calls` reported the estimates as unavailable instead of guessing, which is the intended behaviour. The estimate path is covered by the test fixtures only. - No game run on a Longshot build yet. - Linux and the web build. **Needs other testers:** - Linux: `HOS_HLE_STATS=1` logs `hle:` blocks and the game runs normally, with no change when the switch is off (request to open). ## Screenshots Nothing on screen. ## Risk and rollback The `HLE(sym)` macro is on every HLE entry's path. With counting off, the only change is one flag test, and the measurement above shows no cost. With it on, an extra thread wakes about every 5 s and every counted call does an atomic increment. Reverting the commits removes it all. ## Reviewer notes Start with `hos.h` (the macro) and `hos_hostcall.c` (the counters and the report thread). The calls and per-call columns already in `docs/cpu-profile.md` are left for a regenerated profile. This PR only marks them. ## Issues None. ## Checklist ### For everyone - [x] One topic. - [x] The title is a Conventional Commit (`type(scope): description`). - [x] Rebased on current `main`. - [x] `python -I -B tests/run_all.py` run and passing (any failure that also fails on `main` is named above). - [x] Tested in the game, or what wasn't is named under Testing. - [ ] Testing filled in: what was tested, what wasn't, and what needs other testers (with test requests). - [x] Measured: main and this PR at named commits, on the same PC, scene and settings, at least 2 interleaved runs each, the median reported. - [x] No game files, dumps, build output or generated files. - [x] `third_party/` untouched (a new folder with a `PROVENANCE.md` instead). - [x] The license is OK: GPL-3.0-or-later, nothing incompatible and nothing decompiled. ### If applicable - [x] AI assistance recorded with `Assisted-by:` / `Co-Authored-By:` trailers. - [x] Flags noted, and the switch reference updated (docs/development.md, the README). - [ ] Host code builds on both Windows (llvm-mingw) and Linux, with UTF-8 paths. (Windows syntax compile only; Linux not built.) - [x] Docs updated. 🤖 Generated with [Claude Code](https://claude.com/claude-code)

klimovich008 added 8 commits

2026-11-13 07:34:38 +00:00

feat: HOS_HLE_STATS=1 logs how often each HLE function and host call ran 4c338b51a2

The CPU profile's "calls a frame" and "us a call" columns (docs/cpu-profile.md,
scripts/cpu_report.py --calls) came from a local patch, so nobody else could
rebuild them. The HLE macro now keeps a counter per function, counted only
with HOS_HLE_STATS=1; a thread logs the counts of the last 5 s, with the host
calls' (counted in a64_call_miss as for HOS_HOSTCALL_STATS), in the "hle:"
lines cpu_report.py reads. Off by default: a call then costs a load and a
branch more.

Assisted-by: Claude Code
Co-Authored-By: Claude Opus 5.5 <[email protected]>

fix: HLE call counters: NVN exports counted, every row printed, wrap-safe counts, no off-path register saves bc7ce6e626

From review: the sdk's NVN exports (nvn2_dispatch) went to their host call
directly and were never counted; they now go through a64_call_miss when
HOS_HLE_STATS is on. The report printed 150 rows while moving every
baseline, so later rows lost their counts: it prints all of them. Counts
since the last report are taken unsigned, so a 32-bit count passing its
maximum is not skipped. The macro's counted arm is a tail call
(hos_hle_counted calls the body), so a leaf handler saves no registers
for it when the switch is off. cpu_report.py reads a summary's rows up
to the next summary, skipping other threads' lines logged in between.

Assisted-by: Claude Code
Co-Authored-By: Claude Opus 5.5 <[email protected]>

fix(scripts): an HLE body not inlined (hle_<sym> in the linker map) is named as its imp_<sym> entry 3cbe6ec39f

From review: with the HLE macro's counted arm, a body the compiler keeps out
of line is its own symbol, hle_<sym>. cpu_report.py's maps and crit.py's
import frames knew only imp_<sym>, so such a function's samples lost their
SDK name, description and call counts. The counter's own functions no longer
start with hle_, so that prefix means an HLE body only.

Assisted-by: Claude Code
Co-Authored-By: Claude Opus 5.5 <[email protected]>

style: the HLE macro on continued lines again; a comment wrapped at the line width f2c52d7a38

Assisted-by: Claude Code
Co-Authored-By: Claude Opus 5.5 <[email protected]>

fix(profile): keep overload call counts separate dd6ce7926d

Truncating HLE names merges existing overloads in the call-count log. The
report then assigns their combined count to each full function, making
calls per frame and time per call incorrect.

Log one full name per row and retain the full name when joining profile
symbols. Cover two real overload names with different counts and reject a
mutation that restores truncation.

The actual producer/parser check reports 100/100 on the old code and 60/40
with the fix. The expanded fixture passes with GCC and llvm-mingw and catches
all seven broken variants. Both Windows compilers syntax-check the whole C
file using retained runtime headers. Full-suite and parent-feature off-path
performance checks remain pending.

Assisted-by: OpenAI Codex
Co-Authored-By: Codex <[email protected]>

fix(profile): time the HLE counter reports and join them to frames by clock 8d324fbccb

Reporting fixes by Codex. Each `hle:` summary now carries its measured
monotonic span (begin_ns/end_ns) instead of a nominal 5 s; cpu_report.py
reads only complete blocks and joins them to native frame returns over
that same span, and per-call figures become estimated sampled occupancy
from the same run's timestamped stacks. The report reads the host-call
table under its lock and a failed thread start turns counting back off.
The docs flag the CPU profile's existing call columns for regeneration.

The default-off macro (hos.h), main's startup hook and nvn_native.c are
unchanged.

Co-Authored-By: Claude Opus 5.5 <[email protected]>

test(cpu_report): give the HLE summary fixture one row a line, as the counter logs them 8003976f37

The parser now takes a block only when its rows match the head's count and total, and a row ends in ";".

Co-Authored-By: Claude Opus 5.5 <[email protected]>

test(hle_stats): Longshot's file names (longshot_env.h, longshot.exe, longshot.map)

CI / Conventional Commit title (pull_request) Blocked by required conditions

Details

CI / Python source checks (ubuntu-24.04, part 1/2) (pull_request) Blocked by required conditions

Details

CI / Python source checks (ubuntu-24.04, part 2/2) (pull_request) Blocked by required conditions

Details

CI / SPIR-V fixtures (global narrow load/store, direct surface atomics, F2I immediate) (pull_request) Blocked by required conditions

Details

CI / Workflow lint (actionlint) (pull_request) Blocked by required conditions

Details

Third-party parts / As their notes say (pull_request) Blocked by required conditions

Details

Third-party parts / The same as upstream (pull_request) Blocked by required conditions

Details

PR description / Description follows the template (pull_request_target) Successful in 8s

Details

a4ce1b54ce

Assisted-by: Claude Code
Co-Authored-By: Claude Opus 5.5 <[email protected]>

CI / Conventional Commit title (pull_request) Blocked by required conditions

Details

CI / Python source checks (ubuntu-24.04, part 1/2) (pull_request) Blocked by required conditions

Details

CI / Python source checks (ubuntu-24.04, part 2/2) (pull_request) Blocked by required conditions

Details

CI / SPIR-V fixtures (global narrow load/store, direct surface atomics, F2I immediate) (pull_request) Blocked by required conditions

Details

CI / Workflow lint (actionlint) (pull_request) Blocked by required conditions

Details

Third-party parts / As their notes say (pull_request) Blocked by required conditions

Details

Third-party parts / The same as upstream (pull_request) Blocked by required conditions

Details

PR description / Description follows the template (pull_request_target) Successful in 8s

Details

This pull request is marked as a work in progress.

Some workflows are waiting to be reviewed.

This branch is out-of-date with the base branch

View command line instructions

Checkout

From your project repository, check out a new branch and test the changes.

git fetch -u 'feat/hle-call-counters:klimovich008-feat/hle-call-counters'

git switch 'klimovich008-feat/hle-call-counters'

No reviewers

No milestone

No project

No assignees

1 participant

Notifications

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/Longshot!153

No description provided.

Rows
Columns