Ocarina of Time: keep the frame ratio at step × base / 60, count a half-rate frame once, and test the stub

dm/games/0400486024DEC000/README.md

@@ -35,6 +35,7 @@ Measured on an M6 Mac with 16 GB, headless, on one walk with camera turns (`walk
 - Current: the title and menu, a movie behind them, are a locked 60 fps (p50 16.67 ms, GPU span 15.6 ms).
 - Resolved: the title movie and the cutscene movies stuttered in small regular jerks at that steady 60 fps on a Mac that decodes AV1 with dav1d (M1, M2). The frames were on time and the movie's pictures were not: the player's `advance` (`main+0x3b61ea0`) found no new picture in 546 and 569 of about 2,900 frames of the title on an M2 Pro, and showed the last one again. Two causes, both general: [packets decoded inside the submission](../../../docs/reference/movies.md#nncodec-packets-decoded-inside-the-submission), on the player's one reader thread, which also gives the shown pictures back, and [dav1d one frame at a time](../../../docs/reference/movies.md#dav1d-decoded-one-frame-at-a-time) (15.4 ms a packet in the movie's heaviest five seconds, 122 ms the longest). After: 0 or 1 in 2,567 to 3,036 frames a run (eight runs of 54 s, headless, `DM_PROBE=main:3b61ed8,main:3b61f80` counting the failed and the good calls), and `DecodeAsync` returns in 0.1 ms at the median and 1.1 ms at the 99th percentile, from 1.9 and 120 ms. Open: not run on an M1 or M2 with four performance cores, nor on an iPad; a Mac with a hardware AV1 decoder (M3 on) decodes with VideoToolbox, where only the first cause applied, not measured.
 - Game speed: the game steps its time by a frame ratio, its base rate (60, or 30) / its int frame rate, whatever the frame took (`main+0x6e6cc4` on v131072), so frames longer than a vsync played in slow motion (seen by the user on a slower Mac; [issue 1375](https://github.com/seedds/nxnative/issues/1375)'s M1 Max ran the title at about 28 fps). With `fps_target 60` the ratio is the host's frame step × base / 60 ([A fixed frame step plays in slow motion on a slow Mac](../../../docs/reference/frame-rate.md#a-fixed-frame-step-plays-in-slow-motion-on-a-slow-mac)), a stub placed by its function's fingerprint ([`patches.py`](patches.py)). Mac runs on the M6 (2026-11-08, a test host on the libraries of chain `3ee493b2c3a4`): the user's play sessions held 60 fps with 2- and 3-vsync holds while areas loaded, game time 1.000 of real time by the host's count. That count is the stub's own; no run on a Mac slow enough to show the slow motion before and after.
+- Current: the base rate of 30 is the framework's half rate, not a cutscene speed. The ratio's unit is 1/60 s whatever the base (the time object's step in seconds is ratio / 60, `main+0x3b4e300`). While bit 0 of the framework's `+0x24f` is set, bit 1 flips each pass of its frame function (`main+0x346c680`), and with both set the draw and the present return at once (`main+0x2cb020`, `main+0x40cd20`): the calc tree, the ratio's function in it (`ModuleSystem::moduleCalc_` by its job's name), runs twice a drawn frame. So each calc takes half the frame's step, step × 30 / 60, as the console's 30 / 30 = 1 twice a 30 fps frame; the step alone ([PR #1996](https://github.com/seedds/nxnative/pull/1996)) would run that mode at twice its speed. The stub counts a half-rate frame's vsyncs once, at the calc that is drawn: counted at both, the log's game time read twice the real time there. `test_oot_frame_step.py` runs the stub at both bases under Unicorn and fails on the step alone. The mode was not met in play: on an iPhone Duo (2026-11-09, docked, a build with HookLink's stub, through the opening, Link's house, Kokiri Forest and the Deku Tree's speech) the stub ran once a present in every 1,800-present window (its vsyncs and the dropped ones add up to the real time within 0.03 s). What the half-speed cutscenes of that PR were: [movies](https://github.com/seedds/nxnative/issues/1922), whose player takes one picture a calc.
 - Sizes since the host answers graphics scale tier 0 docked ([The graphics scale does not follow the operation mode](../../../docs/reference/services.md#the-graphics-scale-does-not-follow-the-operation-mode)): the game's output is 2560x1440 and its top internal resolution 1920x1080. Every size and time in this note was taken with tier 1, at 0.8 of that (2048x1152 and 1536x864, and the dynamic resolution's levels with them), and has not been taken again. With tier 0 on `main` (two contributors' runs, only that answer changed): M4 Pro (20-core GPU), docked, fullscreen, GPU p50 15.0 ms against 12.9-14.0 ms, 59.0 fps against 55.8-59.8; M5 Pro (20-core GPU, 48 GB), Dynamic resolution off, 24 minutes of play, GPU p50 12.7 ms, 58.4 fps. Open: a slower Mac, and the routes of [`bench.tsv`](bench.tsv), with tier 0.
 - Current: walking the village at the game's top internal resolution, 1536x864: a locked 60 fps, mean 16.67 ms over each settled window. Per 2,700 frames: 0-8 frames over 25 ms and 0-2 over 33 ms. Frame p95 17.8-18.9 ms with no window, as the game's own loop moves around its fence wait; in a window p95 17.8 ms, 3 over 25 ms and 5-16 over 18 ms per 600. GPU span p50 16.5 ms, summed GPU 15.8 ms, CPU 6 ms, about 101 passes a frame. The heavy stretch where the village opens (about 1,560 draws) holds 16.65-16.8 ms by lowering its resolution, then returns to full. The main pass used to sit at 763x429 at the same GPU time: [marked shaders tested depth late](../../../docs/reference/frame-rate.md#a-hosts-own-store-in-a-fragment-shader-moves-its-depth-test).
 - Before [pool shaders stopped counting as depth readers](../../../docs/reference/rendering.md#pool-shaders-taken-as-depth-readers): passes 118, 104, 219, 224 in a four-frame cycle, frame times 15, 15, 18, 18.5 ms, mean 16.9 ms. Half the frames rendered the reflection probe's faces with one draw a pass.

dm/games/0400486024DEC000/patches.py

@@ -2,33 +2,50 @@
 # MATCH_FRAME_STEP as described there ("Registered patches"). Patches of Nintendo SDK module builds are in dm/tools/sdk_patches.py
 from nso_asm import ADRP, B
 
-# The game's frame ratio. Once a frame the function at main+0x6e6be0 (v131072) divides its base rate (60.0, or 30.0 while bit 0 of [x21+0x24f] is set) by the int frame rate at
-# [x21+0x2c8] (fdiv s8,s1,s0 at +0xe4) and hands the result to the time object (main+0x3b4e300: ratio at +0x10, 1 / ratio at +0x14, round(60 / ratio) at +0x1c), which the game
-# steps by; the frame's own time never enters it, so a frame that takes two vsyncs at rate 60 plays at half speed. The stub gives the ratio the host's step instead: step × base / 60
-# (the division's value when the host keeps frames 60 / rate vsyncs), and counts the vsyncs stepped. Until the host has decided a step, and at fps_target 0, the division runs.
-# s0 and x16 / x17 are free there (s0 is written again on every path before it is read; the function uses neither x16 nor x17); s1 keeps the base rate.
+# The game's frame ratio. Once a frame the function at main+0x6e6be0 (v131072, ModuleSystem::moduleCalc_ by the name of its job) divides its base rate (60.0, or 30.0 while
+# bit 0 of [x21+0x24f] is set) by the int frame rate at [x21+0x2c8] (fdiv s8,s1,s0 at +0xe4) and hands the result to the time object (main+0x3b4e300: ratio at +0x10, 1 / ratio
+# at +0x14, ratio / 60 at +0x18, the step in seconds, round(60 / ratio) at +0x1c), which the game steps by; the frame's own time never enters it, so a frame that takes two
+# vsyncs at rate 60 plays at half speed. The stub gives the ratio the host's step instead: step × base / 60, and counts the vsyncs stepped. Until the host has decided a step,
+# and at fps_target 0, the division runs. s0 and x16 / x17 are free there (s0 is written again on every path before it is read; the function uses neither x16 nor x17); s1 keeps
+# the base rate and x21 the framework.
+# Why × base / 60 and not the step alone (PR #1996 read base 30 as a cutscene rate and took the step, twice the speed there): the ratio's unit is 1/60 s whatever the base
+# (the time object's +0x18 is ratio × 1/60, the constant at main+0x3e4066c). Base 30 is the framework's half rate: bit 0 of its +0x24f is that mode and bit 1 flips each pass of
+# its frame function (main+0x346c680); with both set the draw and the present return at once (main+0x2cb020, main+0x40cd20) while the calc tree runs (main+0x2cabd0). So it
+# calcs twice a drawn frame, this function among them, and each calc takes half the frame's step: 30 / 30 = 1 twice a 30 fps frame on the console, step / 2 twice here. The
+# vsyncs are counted once a drawn frame, at the calc that is drawn (bit 1 clear): counted at both, the host's game time read twice the real time in that mode.
+# The branch targets are computed from the words emitted, so a word added to the stub cannot leave one pointing into its middle (dsi-hub's HookLink met that on an iPhone,
+# a fault on the first frame, when a block was added between main's fixed offsets and their target).
 # Lichii (a GPL emulator; only the fact was taken) found the division (its notes: main+0x6E6CC4, 60 / [x21+0x2C8])
 def frame_step(ctx):
     here, emit, fs_site, fs_put, FS_STATE_OFF, base = ctx.here, ctx.emit, ctx.site, ctx.put, ctx.state, ctx.base
     site = base + 0xe4
     fs_site(site, '2818201e')   # fdiv s8,s1,s0
-    start = here(); emit(ADRP(16, here(), FS_STATE_OFF))
-    for w in (0xb9400211,   # ldr w17,[x16]          target fps (0 = off)
-              0x340001b1,   # cbz w17,orig (+13)
-              0xb9402211,   # ldr w17,[x16,#0x20]    step in vsyncs
-              0x34000171,   # cbz w17,orig (+11)     not decided yet
-              0x1e230220,   # ucvtf s0,w17
-              0xf9401a10,   # ldr x16,[x16,#0x30]
+    start = here()
+    ORIG, COUNTED, n = 18, 13, [0]   # the original division is word 18 of the stub, the ratio starts at word 13 (both checked below); n counts the words emitted
+    def put(w): emit(w); n[0] += 1
+    def cbz_w17_orig(): return 0x34000000 | (((ORIG - n[0]) & 0x7FFFF) << 5) | 17   # from this word to word ORIG
+    put(ADRP(16, here(), FS_STATE_OFF))
+    put(0xb9400211)             # ldr w17,[x16]          target fps (0 = off)
+    put(cbz_w17_orig())         # cbz w17,orig
+    put(0xb9402211)             # ldr w17,[x16,#0x20]    step in vsyncs
+    put(cbz_w17_orig())         # cbz w17,orig           not decided yet
+    put(0x1e230220)             # ucvtf s0,w17
+    put(0x39493eb0)             # ldrb w16,[x21,#0x24f]  the framework's half-rate bits
+    put(0x37000000 | 1 << 19 | ((COUNTED - n[0]) & 0x3FFF) << 5 | 16)   # tbnz w16,#1,ratio: the calc of a half-rate frame that is not drawn; its vsyncs are counted at the drawn one
+    put(ADRP(16, here(), FS_STATE_OFF))
+    for w in (0xf9401a10,   # ldr x16,[x16,#0x30]
               0x8b110210):  # add x16,x16,x17
-        emit(w)
-    emit(ADRP(17, here(), FS_STATE_OFF))
-    for w in (0xf9001a30,   # str x16,[x17,#0x30]    vsyncs stepped
-              0x1e210808,   # fmul s8,s0,s1          step × base rate
+        put(w)
+    put(ADRP(17, here(), FS_STATE_OFF))
+    put(0xf9001a30)             # str x16,[x17,#0x30]    vsyncs stepped
+    assert n[0] == COUNTED, f'frame_step: the ratio starts at word {n[0]}, the tbnz goes to word {COUNTED}'
+    for w in (0x1e210808,   # fmul s8,s0,s1          step × base rate
               0x52a84e10,   # mov w16,#0x42700000    60.0
               0x1e270200,   # fmov s0,w16
               0x1e201908):  # fdiv s8,s8,s0          / 60
-        emit(w)
-    emit(B(here(), site + 4))
+        put(w)
+    put(B(here(), site + 4))
+    assert n[0] == ORIG, f'frame_step: the original division is word {n[0]}, the cbz branches go to word {ORIG}'
     emit(0x1e201828); emit(B(here(), site + 4))   # orig: fdiv s8,s1,s0; back
     fs_put(site, [B(site, start)], 'frame ratio: the host\'s step × base rate / 60 instead of base rate / the game\'s frame rate (state page target fps; 0 = the game\'s ratio)')
     dynamic_resolution(ctx)

dm/tools/tests/test_oot_frame_step.py

@@ -0,0 +1,110 @@
+"""Execute Ocarina of Time's frame-step stub (patches.py frame_step): the host's step × base / 60.
+
+Runs the emitted code under Unicorn (an optional dependency). Base 30 is the framework's half rate, two calcs a drawn frame (bit 0
+of its +0x24f the mode, bit 1 the calc that is not drawn): each calc takes half the frame's step, and the frame's vsyncs are
+counted once. PR #1996 took the step alone there, twice the speed. In rewritten code x17 does not survive a store, so the
+`clobber_x17` runs zero it after every store, as the rewriter can: a stub that keeps something in it across one fails here.
+The harness is HookLink's (dsi-hub).
+"""
+import importlib
+import importlib.util
+from pathlib import Path
+import struct
+import sys
+import unittest
+
+REPO = Path(__file__).resolve().parents[3]
+sys.path.insert(0, str(REPO / 'dm/tools'))
+
+spec = importlib.util.spec_from_file_location('oot_patches', REPO / 'dm/games/0400486024DEC000/patches.py')
+assert spec is not None and spec.loader is not None
+profile = importlib.util.module_from_spec(spec)
+spec.loader.exec_module(profile)
+try:
+    unicorn = importlib.import_module('unicorn')
+    arm = importlib.import_module('unicorn.arm64_const')
+except ImportError:
+    unicorn = arm = None
+
+BASE, FUNC, AREA, STATE, FRAMEWORK = 0x4000000, 0x6e6be0, 0x800000, 0x900000, 0x700000
+SITE = FUNC + 0xe4
+
+
+class Ctx:
+    state = STATE
+    base = FUNC
+
+    def __init__(self, machine):
+        self.machine, self.cursor, self.sites, self.others, self.capabilities = machine, AREA, {}, {}, set()
+
+    def here(self):
+        return self.cursor
+
+    def emit(self, word):
+        self.machine.mem_write(BASE + self.cursor, struct.pack('<I', word))
+        self.cursor += 4
+
+    def site(self, offset, original):
+        self.sites[offset] = original
+
+    def put(self, offset, words, reason):
+        self.machine.mem_write(BASE + offset, b''.join(struct.pack('<I', w) for w in words))
+
+
+def f32(v):
+    return struct.unpack('<I', struct.pack('<f', v))[0]
+
+
+def run(base_rate, game_rate, target, step, clobber_x17=False, half_rate=0, stepped=0):
+    """One pass of the site: (ratio, vsyncs counted, pc). half_rate: the framework's +0x24f (0, or 3 / 1 for the two calcs of a half-rate frame)"""
+    assert unicorn is not None and arm is not None
+    m = unicorn.Uc(unicorn.UC_ARCH_ARM64, unicorn.UC_MODE_ARM)
+    m.mem_map(BASE, 0xa00000)
+    m.reg_write(arm.UC_ARM64_REG_CPACR_EL1, 3 << 20)   # the FP unit is off at reset
+    ctx = Ctx(m)
+    profile.frame_step(ctx)
+    m.mem_write(BASE + STATE + 0x00, struct.pack('<f', target))
+    m.mem_write(BASE + STATE + 0x20, struct.pack('<I', step))
+    m.mem_write(BASE + STATE + 0x30, struct.pack('<Q', stepped))
+    m.mem_write(BASE + FRAMEWORK + 0x24f, bytes([half_rate]))
+    m.reg_write(arm.UC_ARM64_REG_X21, BASE + FRAMEWORK)
+    m.reg_write(arm.UC_ARM64_REG_S1, f32(base_rate))
+    m.reg_write(arm.UC_ARM64_REG_S0, f32(game_rate))
+    if clobber_x17:
+        x17 = arm.UC_ARM64_REG_X17
+
+        def after_store(uc, access, address, size, value, data):   # the rewriter's store sequence may leave x17 = 0
+            uc.reg_write(x17, 0)
+        m.hook_add(unicorn.UC_HOOK_MEM_WRITE, after_store)
+    m.emu_start(BASE + SITE, BASE + SITE + 4, count=64)
+    ratio = struct.unpack('<f', struct.pack('<I', m.reg_read(arm.UC_ARM64_REG_S8) & 0xffffffff))[0]
+    return ratio, struct.unpack('<Q', m.mem_read(BASE + STATE + 0x30, 8))[0], m.reg_read(arm.UC_ARM64_REG_PC)
+
+
+@unittest.skipIf(unicorn is None, 'optional ARM64 execution dependency: unicorn')
+class FrameStep(unittest.TestCase):
+    def test_at_full_rate_the_ratio_is_the_hosts_step_and_every_calc_counts(self):
+        for step in (1, 2, 3):
+            self.assertEqual(run(60.0, 60.0, 60.0, step, stepped=7), (float(step), 7 + step, BASE + SITE + 4))
+
+    def test_half_rate_takes_half_the_step_at_each_of_its_two_calcs(self):
+        for step in (1, 2, 3):   # 30 / 30 = 1 twice a frame on the console; here the two calcs of a frame add up to its step
+            first, stepped, _ = run(30.0, 30.0, 60.0, step, half_rate=3)
+            self.assertEqual((first, stepped), (step / 2, 0))   # the calc that is not drawn does not count the frame's vsyncs
+            second, stepped, _ = run(30.0, 30.0, 60.0, step, half_rate=1, stepped=stepped)
+            self.assertEqual((first + second, stepped), (step, step))   # counted once, at the drawn calc
+
+    def test_x17_lost_after_a_store_is_survived(self):
+        for base_rate, bits, ratio in ((60.0, 0, 2.0), (30.0, 3, 1.0), (30.0, 1, 1.0)):
+            self.assertEqual(run(base_rate, base_rate, 60.0, 2, clobber_x17=True, half_rate=bits)[::2], (ratio, BASE + SITE + 4))
+
+    def test_target_zero_runs_the_games_division(self):
+        self.assertEqual(run(60.0, 30.0, 0.0, 0), (2.0, 0, BASE + SITE + 4))
+
+    def test_step_not_decided_yet_runs_the_games_division(self):   # the first frames
+        self.assertEqual(run(60.0, 30.0, 60.0, 0), (2.0, 0, BASE + SITE + 4))
+        self.assertEqual(run(30.0, 30.0, 60.0, 0, half_rate=3), (1.0, 0, BASE + SITE + 4))
+
+
+if __name__ == '__main__':
+    unittest.main()