12 Commits

Author SHA1 Message Date
chrg6
c040ca6c5f Write the frame-time summary and the stutter map at a fatal error too, the map only when its lock is free.
dispatch.c fatal_end wrote only the profiler's samples, so a run that ended in a FATAL had no "frametime" or
stutter-map lines for its last period: the numbers that would show what the game was doing before it failed.

perf.c perf_summary_flush_try (weak in dispatch.c for builds without perf.c) runs after fs_save_crash_wait: ft_stop,
then the running period's "frametime: at a fatal error" lines and the stutter map. The failing thread may hold any
lock, so stutter_map.c gains stutter_report_as(tag, try_only), which only tries sm_lock and writes nothing when it is
taken (stutter_report keeps the blocking take); the back end's exit lines (gfx_exit_log) and the trace's segments
(seg_close) are left out, as they read state the failure may have left half made. The crash report keeps no summary:
its state may be damaged.

Not reproduced before the change (a missing diagnostic). tests/fatal_exit_check.py now wants the summary at
rt_fatal and checks statically that perf_summary_flush_try only tries the map's lock and leaves the back end out;
tests/stutter_hitch_check.c gets the trylock stand-in it needs. fatal_exit_check, stutter_hitch_check,
stutter_map_check and the compile checks of every runtime file pass.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-11-13 18:43:23 -05:00
chrg6
a473e763b2 Tie the stutter map's cause count to perf.c's at compile time, and rewrap the comment that lists the causes.
The review of d84aa5fb and c05e6528 found that nothing at compile time tied perf.c FT_C_N to stutter_map.c SM_CAUSES:
they sit in different translation units, perf.c ft_frame passes stutter_frame n = FT_C_N, and the areas' by_cause
counts and cause_short are indexed against SM_CAUSES, so a cause added on one side only would mislabel the map without
an error (tests/stutter_hitch_check.c checks only its own names[]). stutter_map.h now defines STUTTER_CAUSES,
stutter_map.c sizes SM_CAUSES from it, and perf.c asserts FT_C_N == STUTTER_CAUSES beside the FT_C_* list. With
STUTTER_CAUSES set to 11 the assertion stops perf.c's compile.

The review also found that the header comment line of stutter_map.c listing the causes ran to 142 columns, where the
file wraps at 120; the paragraph is rewrapped without a change of words.

No change to what runs. perf.c, stutter_map.c and the other files that include stutter_map.h (romfs.c, vk_exec_draw.c,
vk_pipeline.c) compile with the dev flags, perf.c and stutter_map.c add no -Wall -Wextra warnings, and
stutter_hitch_check and stutter_map_check pass.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-11-13 18:41:39 -05:00
chrg6
395f57a2fa Count the hitch in the run's last frames in the stutter map's exit report.
A hitch is decided only after the two frames that follow it, and an episode closes only at the next frame that is not
a candidate (stutter_map.c cand_decide, episode_close). The exit's report summed the areas as they were, so a hitch in
the last two frames before the exit, or a run of long frames ending there, was never counted: the audit's probe
(Av/stutter_exit_probe.c with the real stutter_map.c) printed 0 hitches for a 150 ms frame followed by 0, 1 or 2
frames, and 1 only from 3 frames on. The periodic and focus-loss reports only count it later; the exit loses it.

stutter_report("exit") now adds to its printed totals what the run would have counted: the open episode as
episode_close counts it (a hitch, or two frames or more), and the candidates still waiting, where one over
SM_HITCH_SURE_NS counts whatever follows and each joins the episode of the frame before it as cand_decide joins it. A
waiting candidate under the sure line is left out, as it may be a change of pace. The episode's area decides play or
load, and its first frame's cause goes into the by-cause totals. exit_tail only reads this state: the exit's report
runs on another thread (perf.c perf_summary_flush from the window's close or the game's exit) while the presenting
thread, which owns ep, the candidates and the areas' play counts, may still be in stutter_frame; closing the episode
from there would race it. The per-area lines and the other reports are unchanged.

tests/stutter_hitch_check.c checks six tails (a 150 ms frame followed by 0, 1 or 2 frames, two 150 ms frames, two
with one frame after them, and 87/91/96 ms): the exit's report prints one hitch more than the areas hold, the same
count the run reaches once it goes on. All six printed one fewer before the change. stutter_hitch_check and
stutter_map_check pass; stutter_map.c compiles with the dev flags and with -Wall -Wextra without new warnings.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-11-13 18:41:39 -05:00
chrg6
110c1b24f9 Make the stutter map's report copy the map under its lock and sort and log the copy without it.
stutter_map.c stutter_report held sm_lock from its start to its end: through a qsort over up to SM_PIPES (4096)
pipeline entries and up to about 85 log lines. The replay thread takes sm_lock in stutter_miss, and the pipeline
workers in stutter_ready from inside vk_pipeline.c's P.lock, which the draw path takes too (ready_note), so a worker
waiting for sm_lock while it held P.lock could hold up a drawing thread for the length of a report. Since 7b0dbeb1 the
report runs every 5 minutes instead of 10 and at a focus loss in play, on the presenting thread.

The report now copies the areas (at most 128), the used pipeline entries and the two lost counts into one malloc'd
block under sm_lock, releases it, and sorts and logs from the copy; the static pointer list it sorted is gone with it,
so two reports at once (the exit's and a periodic one) no longer share it. The areas' play counts still belong to the
presenting thread; copying them under sm_lock does not change that. perf.c session_report's comment now says the map
is copied under its lock.

The output text is unchanged: a scratch harness that ran the same frames, misses and ready notes (6 areas, 300 draws)
through the old and the new stutter_map.c printed identical reports, 50 lines each. Not reproduced before the change
(the hold is estimated under a millisecond, through the log queue). stutter_hitch_check and stutter_map_check pass;
stutter_map.c and perf.c compile with the dev flags and with -Wall -Wextra without new warnings.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-11-13 18:41:39 -05:00
chrg6
af8e2a323b Charge the frames a memory-census walk overlapped to census, the memory report's time to a report part, and walk once at frame 3600N.
With mem_census = 1 and trace = perf, vk_memory.c census_main walks the address space for 100-240 ms on its own
thread, holding the process's address-space lock. The replaying thread's write-watch queries wait for that lock
("mem: slow write-watch query: 20-34 ms ... 0 pages written"), and ft_frame charged the frame to "replay": in the
0.10.0 fresh session (nx2navi.1.log, 7,974,927 bytes) 63 of the stutter map's 66 replay hitches sat beside such a
walk, 49 of them at frames 600N+1..3. The presenting thread's own 600-frame memory report (10-17 ms, timed in
vk_mem_census since b81a9561) went to "unattributed". And at frame 3600N, census_check walked on the presenting thread
and the same frame's heap_log started census_main's second walk.

- perf.c perf_census_walk brackets census_main's walk (atomics); ft_frame moves the part of a frame over 25 ms (or a
  stutter-map candidate) that overlapped the walk out of the replay part first, then out of the unattributed part,
  into "census". The rule is runtime/perf_census.h census_charge, capped by the overlap and the frame.
- A new cause "report": vk_mem_census feeds the report's time (perf_report_part), and so do perf.c's memory
  snapshots and its 600-frame sizes lines; the next frame takes it, so the overlap rule no longer has to infer it.
  The cause list changes together: perf.c FT_C_* and ft_cause_name, stutter_map.c SM_CAUSES and cause_short,
  tests/stutter_hitch_check.c names[].
- census_check records the frame it walked (perf_census_walked_frame); heap_log does not start census_main for that
  frame, so frame 3600N walks once. A frame stamp, not a time window, since prof_commit_census can fail and leave
  perf_note_wc uncalled.
- The "mem: process" line gives the walk's start and end on the run's clock and its length, so a play-test with
  mem_census = 0 can tell the walk from the presenting thread's report as the cause of the 600N+1 hitches.

New tests/census_charge_check.py builds runtime/perf_census.h alone: no overlap, partial, contained and still-running
walks, the charge from replay first, capped by the overlap and the parts, and 100,000 random frames in which the census
part never passes the frame; docs/building.md describes it. Diagnostics only: NX2NAVI_MEM_CENSUS defaults to 0, and
nothing in gameplay, pacing or the save changes. Not reproduced before the change (it needs a game run). The pass's
known-issues table, which should say that hitch counts are taken with mem_census = 0 and trace off, is not in the
repository. census_charge_check, stutter_hitch_check and stutter_map_check pass; every runtime file compiles with the
dev flags, and perf.c, stutter_map.c and vk_memory.c add no -Wall -Wextra warnings.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-11-13 18:41:39 -05:00
chrg6
0472734008 Time the hand-off to the present thread, the present call and other threads' acquire waits, and count the acquire's GPU wait once.
The perf lines could not see pacing. In the 0.10.0 fresh session (nx2navi.1.log, 7,974,927 bytes) all 666 windows read
"pacing 0%" and "bound: cpu" and all 70 slow-frame lines "pacing 0.0 drain 0.0", while 610 windows had a 16.x ms
interval at fps_limit 60 under the game's own limiter. The pacer's wait happened where perf does not count it:
vk_backend.c present_image's wait for the present thread to take the previous picture was untimed, perf_end drops
waits on any thread but the presenting and replay ones (a game may acquire its window image on another), and the
acquire's GPU wait was counted twice, as pacing around b->fence_wait and as a fence wait inside vk_sync_fence_wait
(F-7-04).

- host.h: PERF_HANDOFF, the presenting thread's wait to hand the present thread the next picture, timed in
  present_image from under pl (where pending is read) and kept in PresentJob.handoff_ns. perf_end_any counts a wait
  on any other guest thread into a sum that perf_present adds to the frame before ft_frame reads its parts.
- nvn_api_obj.c nvnWindowAcquireTexture: the pacer's sleep is timed with perf_end_any; the GPU wait counts only as
  the fence wait it is; one line names the threads that acquire and present once the first present is known.
- vk_backend.c present_main: the TRACE=present line adds the present call's time (vkQueuePresentKHR, under the queue
  lock, where an overlay's frame limiter sleeps) and the job's hand-off wait; with trace=perf, a line per 60 presents
  gives the present thread's blit and submit, paced wait, present call (avg, max), time past target and the hand-off.
- perf.c: "handoff" in the window line's shares and the slow-frame line, "hand-off" in the worst-frame lines and as a
  cause of its own for frames over 25 ms and the stutter map. The "bound:" rule stays as it is until play-test numbers
  exist.
- The cause list changes together: perf.c FT_C_* and ft_cause_name, stutter_map.c SM_CAUSES and cause_short,
  tests/stutter_hitch_check.c names[] (now sized from SM_CAUSES), and tools/stutter_map.py, whose cause and hitch
  patterns now take a hyphen. flight.c's frames.tsv gets a handoff_ms column (blocked_names checked against PERF_N),
  and tools/flight_view.py lists it.
- tools/perf_summary.py reads the hand-off share, the present-thread lines and the TRACE=present lines, and prints
  percentiles of the present interval, paced wait, time past target, present call and hand-off.

New tests/perf_summary_check.py makes lines with the runtime's format strings (checked against the C sources) and
checks the percentiles, the window averages and the hand-off share, and that older lines without these fields still
parse; tests/stutter_map_check.py gets a hand-off hitch and area cause, which the old patterns dropped. Diagnostics
only: no wait, pacing or presentation change. Not reproduced before the change (it needs a game run with trace=perf).
perf_summary_check, stutter_map_check, stutter_hitch_check, flight_flash_check and frame_step_check pass; every
runtime file compiles with the dev flags after the host.h change, and the changed files add no -Wall -Wextra warnings.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-11-13 18:41:39 -05:00
chrg6
baf83fda6a Make a stutter-map episode end at its last frame that stood out once the frames after it settle into a pace.
At 40 fps or less every frame is over 25 ms and so a hitch candidate. A frame that stood out opened an episode with
its hitch flag set, every following paced candidate joined it as a consecutive frame, and the cut after
SM_EPISODE_MAX frames applied only to episodes without a hitch. So the episode grew until the frame rate rose again:
a 150 ms frame followed by 300 frames at 30 fps counted one hitch of about 10 s, and five 120 ms hitches at a steady
30 fps counted as one.

cand_decide now keeps the episode up to its last frame that stood out (frame, summed time, frame count). When more
than SM_EPISODE_MAX paced frames follow that frame, the paced frames are a change of pace and the episode ends at the
frame that stood out and is counted with its time to there. An episode without such a frame is cut as before, and
episode_close is unchanged, so the 87/91/96 ms episode of 2f640fb8 keeps its 274 ms.

tests/stutter_hitch_check.c gets both cases: 150 ms then 300 frames at 30 fps counts one hitch of 150 ms, and five
120 ms hitches at 30 fps count five of 120 ms each. Both failed before the change (0 hitches counted while the run
lasted). stutter_hitch_check and stutter_map_check pass; stutter_map.c compiles with the dev flags and with -Wall
-Wextra without new warnings.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-11-13 18:41:39 -05:00
chrg6
2f640fb8ed Make the stutter map count runs of long frames as one hitch and the texture pool's area loads as loads.
In the 2026-11-13 session three frames of 87, 91 and 96 ms after an area load each counted as a change of pace, as each was followed by one as long, and loads that only the texture pool saw (no area file read, so no scene line) were charged to play. Consecutive long frames are now one episode, counted once with their summed time, its line giving that time and the first frame's parts; a run of more than 8 long frames none of which stands out is still a change of pace. The texture pool's start and end of an area load mark an area load for the map, as the game's own loads do.

With trace = perf, the slow write-watch queries and freezes past the 200 lines they may log are counted and given every 60 frames, so a late area load still shows them; the session's lines had run out by frame 36,387.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-11-13 15:57:52 -05:00
chrg6
7b0dbeb18d Write the session's reports when the window loses the focus in play, more often in play, and log every end of the game in the launcher.
The session of 2026-11-13 ended 8 s after its window lost the focus, after 7 minutes of play, with none of the game's exit lines: no frame-time summary of its last period, no stutter map of its last minute and no growth ranking at all, as the ranking came every 10 minutes. When the window loses the focus in play, the present thread now writes the frame-time summary so far (starting a new period), the stutter map and the growth ranking at its next present, at most once a minute; formatting only, nothing asks the device. The growth ranking comes every 2 minutes of play instead of 10, the stutter map every 5 instead of 10.

A process that ends through exit() rather than plat_exit now writes the log thread's queue last, after the frame-time summary's exit handler, instead of losing it.

The launcher logged a game's end only for a nonzero code, so the session's end with code 0 left no line anywhere. It now logs every end of a game it started, and when the game's log has no line of the game's own end (the window's close, the game's ExitProcess, a timed run's end, a FATAL or exit line), it notes the end there too.

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-11-13 15:57:52 -05:00
chrg6
f7487ceee5 Make the memory census walk once and fire on the process's own commit, not on its private bytes.
With mem_census = 1 the census trigger compared the private bytes with the last census, and Windows charges the video memory to them, so every gigabyte of textures started another 130-260 ms walk on the presenting thread: 22 of the 33 walks of the 2026-11-13 session came from that trigger, while the process's own commit grew 307 MiB in play. The trigger now reads the private bytes less the write-combined memory of the last walk (and what the driver's device-local figure grew since), compares them with the highest figure seen at a census, and waits 60 s after the last walk; the 3600-frame censuses stay.

On Windows one walk of the address space now gives both the commit census and the guest regions' committed bytes, which mem_guest_census walked a second time. The census counts the driver's write-combined views apart instead of as guest memory, counts as guest only the reserved guest regions and the loaded modules, and ranks the process's own allocations wherever they lie. The frame after a walk charges its time to a new "census" cause in the frame-time summary and the stutter map instead of "unattributed".

Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-11-13 15:57:51 -05:00
chrg6
e7c2fc6a6b Make the stutter map name the areas without the perf trace, and count a hitch only when the frames after it are shorter: a hitch is now measured against the median of the last 32 frames, so a steady change of pace (the game drawing at 60 fps after 200) is no longer counted as a run of hitches.
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-11-13 08:23:11 -05:00
chrg6
97671e8ea7 Add the stutter map: each hitch of a play session with its area, what the frame waited for and the pipelines and shaders its draws met missing, and every 10 minutes and at exit the areas ranked by their hitches and the pipelines that cost the most (stutter_map = 1, off by default). tools/stutter_map.py turns a log into a report and counts what a game folder recorded that a pipeline list lacks.
Co-Authored-By: Claude Opus 5.5 <noreply@anthropic.com>
2026-11-13 07:31:57 -05:00