From 170d255e8263a71ba2b03ad5bce9146b9cc40d05 Mon Sep 17 00:00:00 2001 From: Sylpheed port agent Date: Tue, 1 Sep 2026 18:15:38 +0000 Subject: [PATCH] port: the port never reported its own frame rate, and the menu draws at 9.7 fps MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit TEMPORAL-VERIFICATION ยง1 requires every instrument to state its achieved rate against its requested one. That has been applied to --film (which I fixed for exactly this), to the Decoder's harnesses and to the oracle. It had never once been applied to the thing being shipped. The port had no idea what rate it drew at and no way to say. It matters now because the splashes are the focus and the open complaint is that ours is LESS PRONOUNCED than the game's. A fade drawn in 45 frames and the same fade drawn in 12 are different animations, and nothing here could tell them apart. boot.gd now counts frames per screen and reports at every boot transition, at the end of the boot, and at every menu arrival. `worst gap` sits beside the mean because a hitch is what reads as wrong and a mean hides one by construction. Measured in this container, three boots: publisher_logo 17.3 / 19.6 / 25.0 fps worst gap 100-115 ms developer_logos 16.7 / 21.9 / 22.8 fps worst gap 103-138 ms title 17.2 / 14.2 / 12.7 fps worst gap 150 ms, all three main_menu 9.7 fps worst gap 150 ms ๐ŸŸก A LIVE CANDIDATE FOR PLAY-TEST FINDING 4, and the first one that is not dead. The timeline is delta-driven so durations stay correct at any rate; what changes is how many alphas the fade is DRAWN at. At the measured rates the 45-unit build-in gets 12-17 distinct alphas instead of 45, and the pre-blurred companion glow -- the thing that IS the splash's blur -- rises over 15 units and is drawn at FOUR TO SIX steps instead of fifteen. โš ๏ธ It is a candidate, not a cause: this is llvmpipe under Xvfb and not the human's hardware. The point is that the line now prints on every boot, so the next play-test answers it for free. Every other candidate for finding 4 is already dead -- keyframes vindicated against the vertex stream, companion quads drawn, blend space matching, settled pose at 0.01 % against the capture, no post-process pass to add. โœ… And nothing published is invalidated, which was worth checking rather than assuming: every timing result here comes from `_elapsed` (+= delta) or `time_units` (the same sum scaled), so all are correct at any frame rate. The splash dwells were measured across runs whose rates differed by 2x and agreed to ยฑ0.03 s. Had the timeline been frame-counted, every number in this corpus would have been wrong by a factor that changed between runs -- which is precisely the failure the Decoder found in the emulator's rate and withdrew a finding over. Two defects in the instrument itself, both caught and fixed before it was trusted: - its first version printed "-9223372036854775808 requested". DisplayServer.screen_get_refresh_rate() returns a FLOAT and is -1.0 when the display cannot say, which Xvfb cannot, and %d underflows to INT64_MIN. It now names the cap or says `uncapped`. - it was BOOT-ONLY and said so nowhere -- `--menu` arrives through _menu_arrive, not _advance, so the mode a human spends time in reported nothing. That is the shape this port keeps finding in other people's work, and it lasted one measurement here. Refutation attempt: I checked whether the port re-decodes PNGs per frame, which would have been a real defect. It does not -- _load_textures caches at load_screen. Hypothesis dead, cheaply, and recorded. Not settled: what rate the human's machine manages; whether 9.7 fps on the menu is llvmpipe or something in our draw path; H6's +0x04 exposure; H1 (the Decoder is taking it this iteration). Co-Authored-By: Claude Opus 5 (1M context) Claude-Session: https://claude.ai/code/session_018AHUQvXGyNcKonSEWsgWcX --- docs/port/BLOCKED.md | 20 ++++++ docs/port/port-frame-rate.md | 134 +++++++++++++++++++++++++++++++++++ port/scripts/boot.gd | 78 ++++++++++++++++++++ 3 files changed, 232 insertions(+) create mode 100644 docs/port/port-frame-rate.md diff --git a/docs/port/BLOCKED.md b/docs/port/BLOCKED.md index 602331be..7a970dab 100644 --- a/docs/port/BLOCKED.md +++ b/docs/port/BLOCKED.md @@ -108,6 +108,26 @@ method finding that applies to the Decoder's harness as much as this one: | **H2** | โœ… **ANSWERED 2026-09-01, and the port's own premise was wrong.** The Decoder found **no post-process pass** on either splash (`auto/frame-blend-draw-path` `3cc1b51`). The blur is **in the asset**: every logo ships a pre-blurred copy ~21ร—20 px larger and concentric, drawn alone first and crossfaded out as the sharp logo fades in โ€” which is the human's *"blurred to clear/sharp, in about a second"*, with no shader. | ๐Ÿ”ด **"The port applies no blur at all" was FALSE and this page said it.** The port draws all seven quads of the developer splash, the three companions included, and always has. Verified by a frozen sweep, 3 units a step: companions alone at u=3โ€“15, all seven at u=18โ€“42, sharp only from u=45. Writing down what the renderer was *believed* to do instead of running it is what produced the claim. What remains is the **extent**, and it is the same unit question as H3 โ€” asked there, once. See [`plate-arrival-halves.md`](plate-arrival-halves.md). | | **H3** | โœ… **CLOSED 2026-09-01. ALL FOUR NAMED CAUSES ARE DEAD AND THE HUMAN'S OBSERVATION IS NOT โ€” recorded that way deliberately rather than left green.** The rate is **56.8 units per guest second**, measured, control at 1.15 %, two elements agreeing at one clock (`units-per-second-measured.md`). 30 and 120 both excluded. At 56.8 the plate's t=236 lands at **4.15 s** against the port's 3.93 s โ€” the port is fractionally **early**. | Eliminated in order: `rest.t` (the arrival is a declared keyframe), the clock origin (85/85 filmed frames share one clock), the anchor (answered t=160, and `clock: "shared"` survives it), the unit constant (56.8). ๐Ÿ”ด **`units = 2 ร— frames` is dead as a route** โ€” the same animation takes 21 labels in one capture and 33 in another. โœ… Audited: this port never used it; `boot.gd` integrates `delta * units_per_second`, so the retirement cost a *justification* in `authored/timing.json` and not a behaviour, and that file's second leg (12 declared units against a 0.14โ€“0.30 s black plateau = 40โ€“86 units/s) has no frames in the chain. **60 units/s is KEPT** โ€” 56.8 is 5.6 % away against ~5 % quantisation and the Decoder did not ask for a move. โš ๏ธ Reach is the **title**; the splashes are a different `GamePart`. What the human saw is now unattributed โ€” see [`plate-arrival-halves.md`](plate-arrival-halves.md) for the two remaining candidates, of which the strongest is that **โ’ถ was unbound on the play-test build so that human could not skip the 137 s intro**, and the run they judged is not the run any of these measurements describes. | +๐ŸŸก **A LIVE CANDIDATE FOR FINDING 4, ADDED 2026-09-01, AND IT IS THE PORT'S NOT +THE DECODER'S.** Every named cause for *"the game's splash fade is more +pronounced"* is now dead โ€” the keyframes are vindicated against the vertex +stream, the pre-blurred companion quads **are** drawn, the blend space matches, +the settled pose scores 0.01 % against the capture, and there is no post-process +pass to add. What was never checked is **the rate the port draws at**. + +It does not report one, because nothing ever asked it to โ€” the rule that every +instrument state its achieved rate had been applied to `--film`, to the +Decoder's harnesses and to the oracle, and never to the thing being shipped. It +reports one now, and in this container it manages **13โ€“25 fps with 100โ€“150 ms +hitches**, which draws the splash's 45-unit build-in at **12โ€“17 distinct alphas +instead of 45** and the companion glow's 15-unit rise at **four to six instead +of fifteen**. + +โš ๏ธ That is `llvmpipe` under Xvfb and **not a measurement of the human's +hardware**, so it is a candidate and not a cause. The point is that the line +now prints on every boot, so **the next play-test answers it for free**. See +[`port-frame-rate.md`](port-frame-rate.md). + **On H2, three things the port can say that narrow it**, none of which settle it: * The port draws the splash from the declared keyframe alphas only. It applies diff --git a/docs/port/port-frame-rate.md b/docs/port/port-frame-rate.md new file mode 100644 index 00000000..678771ea --- /dev/null +++ b/docs/port/port-frame-rate.md @@ -0,0 +1,134 @@ +# The port never reported its own frame rate โ€” it does now, and it is 13โ€“25 fps here + +**Status:** โœ… **instrument added and measured.** ๐ŸŸก **The consequence is a live +candidate for play-test finding 4 and it is environment-dependent, so it is +recorded as a candidate and not as a cause.** Written 2026-09-01 by the Port at +`977965e`; HANDOFF on this branch answers `9ca1eb5`. + +## The gap this closes + +[`TEMPORAL-VERIFICATION.md`](../agents/TEMPORAL-VERIFICATION.md) ยง1 is +unambiguous: a capture that asked for one rate and delivered another *"is not a +slow capture, it is a **different** capture"*, and an instrument that cannot +report its own completeness may not be trusted. + +That rule has been applied to `--film` (which I fixed for exactly this), to the +Decoder's harnesses, and to the oracle. **It had never once been applied to the +thing being shipped.** The port had no idea what rate it drew at and no way to +say. + +It matters here specifically, because the splashes are the current focus and the +open complaint about them is that ours is *less pronounced* than the game's. +**A fade drawn in 45 frames and the same fade drawn in 12 are different +animations**, and nothing in this port could have told them apart. + +## The instrument + +`boot.gd` now counts frames per screen and prints at every boot transition, at +the end of the boot, and at every menu arrival: + +``` + publisher_logo: 107 frames in 4.29 s -- 25.0 fps achieved, uncapped, worst gap 108 ms +``` + +`worst gap` sits beside the mean deliberately: a hitch is what reads as wrong. A +screen averaging 55 fps with one 400 ms stall looks broken, and a mean hides that +by construction. + +๐Ÿ”ด **Its first version printed `-9223372036854775808 requested`.** +`DisplayServer.screen_get_refresh_rate()` returns a *float* and is `-1.0` when +the display cannot say โ€” which Xvfb cannot โ€” and `%d` on that underflows to +`INT64_MIN`. A rate line whose own denominator is nonsense is worse than no rate +line. It now names the cap or says `uncapped`. + +## What it measures, in this container + +Three boots, same command, nothing else running: + +| screen | run 1 | run 2 | run 3 | worst gap | +|---|---|---|---|---| +| `publisher_logo` | 17.3 fps | 19.6 | 25.0 | 100โ€“115 ms | +| `developer_logos` | 16.7 | 21.9 | 22.8 | 103โ€“138 ms | +| `title` | 17.2 | 14.2 | 12.7 | **150 ms**, all three | + +**13โ€“25 fps, varying by ~2ร— run to run, with hitches of 100โ€“150 ms.** The +title's 150 ms is identical across all three runs, which looks like a one-off +cost rather than load โ€” the video player is torn down immediately before it. + +### ๐Ÿ”ด And the menu is worse than any of them + +The report was **boot-only** on its first version and said so nowhere โ€” the boot +walks through `_advance`, while `--menu` arrives through `_menu_arrive`. So the +mode a human actually spends time in, and the one where a slow frame is *felt as +input lag* rather than seen as a coarse fade, reported nothing. An instrument +covering half the application while its own page claims "every boot" is exactly +the shape this port keeps finding in other people's work. Fixed in the same +commit: + +``` + main_menu: 20 frames in 2.05 s -- 9.7 fps achieved, uncapped, worst gap 150 ms +``` + +**9.7 fps.** The main menu is the heaviest screen in the port โ€” five additive +elements, five spinning focus rings, a full-screen background โ€” and it is the one +the play-test spent its time on. At 9.7 fps a press takes up to 103 ms to appear +and a spinning ring advances in ~10 visible steps per revolution. + +โš ๏ธ **This is `llvmpipe` software rasterisation under Xvfb in a loaded container. +It is not a measurement of the human's hardware and must not be quoted as one.** +What it establishes is that the port *can* run this slowly and never said so. + +## The consequence, and why it is a live candidate for finding 4 + +The port's timeline is driven by `time_units += delta * units_per_second`, so +**the durations stay correct at any frame rate** โ€” the fade still takes 0.75 s. +What changes is how many distinct alphas that fade is *drawn* at: + +| rendered at | steps in the 45-unit build-in | steps in the glow's 15-unit rise | +|---|---|---| +| **16.7 fps (measured)** | **12.5** | **4.2** | +| **22.8 fps (measured)** | **17.1** | **5.7** | +| 30 Hz | 22.5 | 7.5 | +| 60 Hz | 45.0 | 15.0 | + +The pre-blurred companion glow โ€” the thing that *is* the splash's blur โ€” rises +over 15 units. **In this container it is drawn at four to six distinct alphas.** +At 60 Hz it would be fifteen. + +A soft crossfade rendered in four steps, inside a 750 ms animation carrying a +100โ€“150 ms hitch, is a plausible mechanism for *"close, but not quite right"* and +for *"the game's is more pronounced"* โ€” and it is the **first candidate for +finding 4 that is not already dead.** Every other one is: the keyframes are +vindicated against the vertex stream, the companion quads are drawn, the blend +space matches, the settled pose scores 0.01 % against the capture, and there is +no post-process pass to add. + +๐Ÿ”ด **It is a candidate, not a cause.** It depends entirely on what the machine +running the port manages, and I cannot measure the human's. **The line now +prints on every boot**, so the next play-test answers it for free: if it says 60 +fps and the splash still looks wrong, this is dead too. + +## What is NOT affected, and it was worth checking + +**Every timing result this port has published stands.** They are all derived from +`_elapsed`, which is `+= delta` โ€” a sum of frame times, correct at any rate โ€” and +from `time_units`, which is the same sum scaled. So: + +* the splash dwells (4.270 s and 3.527 s) are unaffected โ€” measured across runs + whose frame rates differed by 2ร—, and they agreed to ยฑ0.03 s; +* the plate's arrival, the shared-clock check and the film's own index are all + `_elapsed`-based. + +That is the reassuring half of the same design: the port is *correct* at 13 fps +and merely *coarse*. Had the timeline been frame-counted, every number in this +corpus would have been wrong by a factor that changed between runs โ€” which is +precisely the failure the Decoder found in the emulator's own rate and withdrew a +finding over. + +## What this does not claim + +* That 13โ€“25 fps is what a player sees. It is what this container manages. +* That the port has a performance defect. Textures are cached at `load_screen` + and not decoded per frame โ€” that was checked and is not the cause. +* That capping or vsyncing would help. It would not raise the rate here, and + changing presentation behaviour on my own authority is not mine to do. diff --git a/port/scripts/boot.gd b/port/scripts/boot.gd index 27d9565d..b1e1f7dd 100644 --- a/port/scripts/boot.gd +++ b/port/scripts/boot.gd @@ -456,11 +456,65 @@ var _elapsed := 0.0 var _boot_done := false +## Frames rendered on the current screen, and the worst gap between two of them. +## +## ๐Ÿ”ด THIS PORT REQUIRED EVERY MEASUREMENT TO REPORT ITS ACHIEVED RATE AND NEVER +## REPORTED ITS OWN. `TEMPORAL-VERIFICATION.md` ยง1 -- a capture that asked for one +## rate and delivered another "is not a slow capture, it is a different capture" +## -- was applied to `--film`, to the Decoder's harnesses and to the oracle, and +## not once to the thing actually being shipped. +## +## It matters here specifically. The splashes are the current focus, the +## developer splash's whole build-in is 45 units = 0.75 s, and the human's +## complaint about it is that ours is *less pronounced* than the game's. A fade +## drawn in 45 frames and the same fade drawn in 11 are different animations, and +## nothing in this port could have told the difference. Every timing check so far +## has measured `_elapsed`, which is the sum of the deltas -- it is exactly as +## correct at 8 fps as at 60 and says nothing about what a person sees. +## +## `worst` is kept beside the mean because a hitch is what reads as wrong: a +## screen averaging 55 fps with one 400 ms stall looks broken, and a mean hides +## that by construction. +var _screen_frames := 0 +var _screen_t0 := 0.0 +var _worst_gap := 0.0 + + +## What the port managed on the screen just finishing, in the form this project +## demands of everyone else: achieved against requested, plus the worst hitch. +func _rate_report(name: String) -> String: + var span := _elapsed - _screen_t0 + if span <= 0.0 or _screen_frames == 0: + return "" + # ๐Ÿ”ด THE "REQUESTED" HALF PRINTED -9223372036854775808 ON ITS FIRST RUN. + # `DisplayServer.screen_get_refresh_rate()` returns a float and is -1.0 when + # the display cannot say -- which Xvfb cannot -- and `%d` on that underflows + # to INT64_MIN. A rate line whose own denominator is nonsense is worse than + # no rate line, so it now names the cap or says plainly that there is none. + var cap := "uncapped" + if Engine.max_fps > 0: + cap = "%d requested" % Engine.max_fps + else: + var hz := DisplayServer.screen_get_refresh_rate() + if hz > 0.0: + cap = "%.0f Hz display" % hz + return " %s: %d frames in %.2f s -- %.1f fps achieved, %s, worst gap %.0f ms" % [ + name, _screen_frames, span, _screen_frames / span, cap, _worst_gap * 1000.0] + + +func _rate_reset() -> void: + _screen_frames = 0 + _screen_t0 = _elapsed + _worst_gap = 0.0 + + func _process(delta: float) -> void: if _frozen or view == null: return view.time_units += delta * view.units_per_second _elapsed += delta + _screen_frames += 1 + _worst_gap = maxf(_worst_gap, delta) view.queue_redraw() _overlay_process(delta) @@ -554,6 +608,12 @@ func _process(delta: float) -> void: elif not _boot_done: _boot_done = true print("boot sequence complete after %.2f s, holding on %s" % [_elapsed, _sequence[_step].get("screen", _sequence[_step])]) + # The LAST screen never reaches `_advance`, so without this the one + # screen the boot ends on -- the title, where the plate lands -- was + # the only one with no rate reported. + var last := _rate_report(String(view.screen.get("name", "?"))) + if last != "": + print(last) # The plate is timed from HERE -- the moment the screen reaches its # own hold -- and not from the frame it first appeared. That is the # finding, not a detail: measured from first-draw the two oracle @@ -588,6 +648,13 @@ func _process(delta: float) -> void: func _advance() -> void: + # Before the step changes, say what the screen that is leaving managed. + if view != null: + var leaving := String(view.screen.get("name", "?")) + var line := _rate_report(leaving) + if line != "": + print(line) + _rate_reset() _drop_overlay() _step += 1 var next: Dictionary = _sequence[_step] @@ -958,6 +1025,17 @@ func _menu_enter(name: String, fresh: bool) -> void: ## The moment a screen has finished fading out and the next one takes over. func _menu_arrive() -> void: + # ๐Ÿ”ด THE RATE REPORT WAS BOOT-ONLY ON ITS FIRST VERSION, AND SAID SO NOWHERE. + # `_advance` walks the boot; the MENU arrives through here, so `--menu` -- + # the mode a human actually spends time in, and the one where a slow frame is + # felt as input lag rather than seen as a coarse fade -- reported nothing. An + # instrument covering half the application while its own page claimed "every + # boot" is the shape this port keeps finding in other people's work. + if view != null: + var line := _rate_report(String(view.screen.get("name", "?"))) + if line != "": + print(line) + _rate_reset() # The plate goes with the screen it was measured on. See `_drop_overlay`. _drop_overlay() var action: Dictionary = _pending