From 4c9719c5dc52177578113e9b8452dc56c09c29d9 Mon Sep 17 00:00:00 2001 From: gamer147 Date: Wed, 22 Jul 2026 12:06:54 -0400 Subject: [PATCH] Document performance baselines and native animation cadence --- docs/engine-ctx-reference.md | 7 +- docs/engine-re.md | 37 ++++++- docs/opcode-reference.md | 11 +- docs/phase-a-slice-plan.md | 202 ++++++++++++++++++++++++++++++++++ docs/tools-reference.md | 21 ++++ tools/age_opcodes_himegari.py | 2 +- vm-map/engine-ctx.toml | 15 ++- vm-map/opcodes.toml | 12 +- 8 files changed, 286 insertions(+), 21 deletions(-) diff --git a/docs/engine-ctx-reference.md b/docs/engine-ctx-reference.md index 8ee4d9a..7909c93 100644 --- a/docs/engine-ctx-reference.md +++ b/docs/engine-ctx-reference.md @@ -31,11 +31,12 @@ Struct `EngineCtx`, size `0xa1000`. Applied to the Ghidra `/v2` image (dispatch- | `0x46d14` | `query_table_46d14` | `void*` | stride-0x14 table read by op 0x216 | | `0x50ba4` | `gfx_render_target_table` | `void*` | retained_gfx_manager+0xa590 array of per-slot D3D texture wrappers selected by op 0x20d | | `0x51b44` | `gfx_current_render_target` | `int` | retained_gfx_manager+0xb530 selected surface slot; -1 denotes device backbuffer | -| `0x51b64` | `frame_timer` | `int` | frame timer at retained_gfx_manager+0xb550; present updates 0x51b64/0x51b68 and object animation samples it | -| `0x51b6c` | `gfx_dirty_a` | `int` | retained_gfx_manager+0xb558 redraw-dirty flag; active finite object channels set it even when detached by 0x242; op 0x1f6 clears it | +| `0x51b64` | `frame_timer_current` | `int` | current shared millisecond presentation timestamp at retained_gfx_manager+0xb550; active outer-engine ticks and op 0x23c sample timeGetTime, and every retained animation channel samples it | +| `0x51b68` | `frame_timer_previous` | `int` | previous shared presentation timestamp at retained_gfx_manager+0xb554; shifted from current before each new sample, and op 0x231 compares current/previous source cells to raise redraw dirty only at cell changes | +| `0x51b6c` | `gfx_dirty_a` | `int` | retained_gfx_manager+0xb558 redraw-dirty flag; retained mutations and continuous channels set it, while op 0x231 sets it only when the sampled source cell differs across the shared current/previous frame timestamps; op 0x1f6 clears it | | `0x51b70` | `gfx_force_complete` | `int` | retained_gfx_manager+0xb55c requests forced completion of one-shot channels; op 0x1f6 clears it | | `0x51b74` | `gfx_dirty_b` | `int` | retained_gfx_manager+0xb560 blocking-presentation dirty flag; active finite object channels set it unless obj+0x2d0 bit 0 detaches them | -| `0x51b78` | `anim_clock_elapsed` | `int` | global anim clock elapsed at retained_gfx_manager+0xb564; op 0x238 and object reset 0x1f6 zero it | +| `0x51b78` | `anim_clock_start` | `int` | start timestamp for the separate finite-animation service window at retained_gfx_manager+0xb564; seeded from frame_timer_current by gfx_animation_service_poll, while op 0x238, op 0x243, and object reset 0x1f6 zero it | | `0x51b7c` | `anim_clock_duration` | `int` | global anim clock duration at retained_gfx_manager+0xb568; op 0x238 sets and object reset 0x1f6 zeroes it | | `0x51b80` | `gfx_animation_service_flags` | `uint` | retained_gfx_manager+0xb56c service flags; bit 1 suppresses op 0x243 force-complete/clock-reset request | | `0x52bd4` | `surfaces` | `void*` | surface array base [~1000 slots]; create/set-texture (0x1f8/0x1f9) allocate | diff --git a/docs/engine-re.md b/docs/engine-re.md index 439e27d..ad70957 100644 --- a/docs/engine-re.md +++ b/docs/engine-re.md @@ -701,6 +701,41 @@ both annotated) and grepping the SC0000 opening settles the animation model and Op `0x234` is the independent rotation cycle above. Op `0x238` still configures the separate `ctx+0x51b78/+0x51b7c` animation service used by its own family. +##### Shared frame clock and cyclic source-cell cadence (2026-07-22) + +The native scheduler confirms the shared-clock recollection, with one important distinction between a +shared **timebase** and universal phase. `engine_main_tick_with_exception_policy@0x411840` samples +`timeGetTime()` once per active outer presentation tick, first shifting retained-gfx manager current time +`+0xb550` (`EngineCtx+0x51b64`) into previous time `+0xb554` (`EngineCtx+0x51b68`). Opcode `0x23c` +explicitly performs the same shift/sample; it does not create another timer or impose a fixed frame rate. +Every cyclic object channel reads that shared pair, but each channel owns a start timestamp and period in +its retained object record. `gfx_animation_service_poll@0x407640` and op `0x238`'s +manager `+0xb564/+0xb568` start/duration window are separate finite-animation service state, not the cyclic +spritesheet clock. + +Op `0x231` is already natively cell-change-driven. `gfx_worker_anim_srcrect@0x47eec0` resets object start +`+0x21c` and stores period `+0x230`, frame count `+0x238`, and columns `+0x23c`. +`gfx_object_anim_interpolate@0x473ed0` seeds that start from the shared current timestamp on the first +sample and selects `floor((current-start)/period) % frame_count`. It performs the same calculation with the +shared previous timestamp and raises manager redraw-dirty `+0xb558` only when the selected cells differ. +Other retained mutations raise dirty directly; continuously varying cyclic channels keep it raised. The +outer loop renders only for retained dirty state or a new movie frame. Merely completing an opcode `0xc8` +sleep/poll interval is not itself a native graphics-dirty request. + +FIELD's DEBUGMAP unit family is more tightly synchronized than the general model permits. At +`FIELD@0x924a`, the script configures prototype handle `0x9c40` as `(period=200 ms, frames=4, columns=2)`. +The following loop calls `DRAWCH`, whose `0x21d` clones that complete retained record from `0x9c40` to +`0x9c40+entity_index`. Ordinary bytecode executes burst-fast and there is no render between prototype setup +and those clones, so every copied start remains zero and their first render seeds the same shared timestamp. +Those unit sprites are therefore phase-locked at one cell change every 200 ms (5 Hz), even though the +engine generally permits different object-local starts and periods. + +**Port implication:** replace the current “any spritesheet is active” redraw predicate with native-style +shared current/previous sampling and request a composition only when at least one visible sampled cell +changes. The FIELD `sleep(1)` input-poll loop must also stop requesting a redraw when no retained mutation +occurred. This is a fidelity correction as well as an optimization; it preserves phase-locking for cloned +records and does not invent 51 independent timers. + ##### `label_1235a` animation-section boundary (2026-07-10) The section helper computes the maximum configured duration and arms it with `0x238`, then reads @@ -1061,7 +1096,7 @@ visible glow on the ordinary interactive path. This glow is a retained scaled/ro fade animates so smooth ramping could join slice A. Findings (Ghidra `gfx_object_anim_interpolate` `0x473ed0`, annotated+saved): the bit-2 anim family (op `0x234`) interpolates **5 independent sub-channels** (color `obj+0x240`/period `obj+0x220`, two matrices, rotation `0x168`=360°, src-rect scroll), each on the -**global frame clock `retained-gfx owner+0xb550` (`EngineCtx+0x51b64`)** (advanced per present, NOT the +**global frame clock `retained-gfx owner+0xb550` (`EngineCtx+0x51b64`)** (sampled by the active outer engine tick, NOT the op-`0x238` clock `ctx+0x51b7c`), and each **ping-pongs** (triangle wave, folded at period/2) — i.e. these are *oscillating/pulsing* effects, not one-shot fades. The `0x202`/`0x203` color (`obj+0x60` static / `obj+0x64` animated, sets diff --git a/docs/opcode-reference.md b/docs/opcode-reference.md index 8b4f95e..3c986db 100644 --- a/docs/opcode-reference.md +++ b/docs/opcode-reference.md @@ -730,9 +730,9 @@ Implemented through IHost.PlayModalMovieToSurface. Its operand uses the same nat - **evidence:** Ghidra /v2: gfx_op_0x22f_set_position_anim@0x423b00 fetches x/y/z as floats and passes all five operands to gfx_worker_set_translation@0x472e90. The worker builds the current translation matrix with x/y/z and stores operand 2 in the channel record. This is distinct from the shared range transform at 0x229. The C# handler sets V24 directly and is therefore position-correct but does not yet model operand 2. ### 0x231 `animate-gfx-srcrect-loop` (u00421EA0, argc 4) -- **summary:** (handle)(frame_period_ms)(frame_count)(column_count) — loop row-major through the spritesheet. Every frame preserves draw-texture's source-rectangle width/height; frame=floor(elapsed/frame_period)%frame_count, src offset=(frame%columns*width, frame/columns*height). Worker gfx_worker_anim_srcrect @0x47eec0; consumer gfx_object_anim_interpolate @0x473ed0. +- **summary:** (handle)(frame_period_ms)(frame_count)(column_count) — loop row-major through the spritesheet. Every sample preserves draw-texture's source-rectangle width/height; frame=floor((shared_frame_time-object_start)/frame_period)%frame_count, src offset=(frame%columns*width, frame/columns*height). All objects use the retained manager's shared current/previous millisecond timestamps but retain their own start and period. The native consumer raises redraw dirty only when the current and previous samples select different cells. Worker gfx_worker_anim_srcrect @0x47eec0; consumer gfx_object_anim_interpolate @0x473ed0. - **grounding:** source=investigation, confidence=high -- **evidence:** Native /v2 decompile: worker stores period at obj+0x230, frame_count at +0x238, columns at +0x23c. Interpolator computes ((now-start)/period)%frame_count, then offsets both source-rect X bounds by rect_width*(frame%columns) and Y bounds by rect_height*(frame/columns). SC0000 uses (100,8,4) with AE001H's eight 200x200 cells in a 4x2 800x400 sheet. +- **evidence:** Native /v2 decompile: worker stores/reset start at obj+0x21c, period at +0x230, frame_count at +0x238, and columns at +0x23c. Interpolator seeds the object start from manager+0xb550, computes ((current-start)/period)%frame_count, then offsets both source-rect X bounds by rect_width*(frame%columns) and Y bounds by rect_height*(frame/columns). It repeats the cell calculation with manager+0xb554 and sets manager+0xb558 dirty only when the two cells differ. engine_main_tick_with_exception_policy shifts current to previous and samples timeGetTime once per active outer tick. SC0000 uses (100,8,4) with AE001H's eight 200x200 cells in a 4x2 800x400 sheet. FIELD configures prototype 0x9c40 with (200,4,2), then DRAWCH clones its complete zero-start record to the entity handles before the first render, phase-locking that family. ### 0x232 `animate-gfx-color-loop` (u00421EF0, argc 4) - **summary:** 0x232 anim-color (handle)(period)(alpha)(color): ping-pong the temporary packed ARGB passed to the normal object blit. Handler resolves negative alpha/RGB from static color obj+0x60 and clamps alpha above 255. Blend selector obj+0x30 is unchanged: mode 0 keeps default blending (animated alpha is inert; RGB is vertex modulation), while mode 1 uses sampled ARGB alpha as the SRCALPHA scale for additive composition. Fresh static color is 0xffffffff. The C# VM resolves sentinels and consumes sampled ARGB through the unchanged mode-specific path. See docs/engine-re.md §SC0000 anim cluster. @@ -752,8 +752,9 @@ Implemented through IHost.PlayModalMovieToSurface. Its operand uses the same nat The handler requires an existing destination texture, allocates/reuses a 0x478-byte movie-to-texture object for the surface, opens operand 1 through the native universal packed-id reader, builds FilterGraph/IGraphBuilder/IMediaControl/IMediaPosition/IMediaEvent/IBasicAudio, and presents bottom-up RGB samples through the movie texture renderer. Operand 3 selects movie/sound routing policy: bits 0x10000/0x20000/0x40000/0x80000 force sound route 0/1/2/3, otherwise set:DependMovieSound is used; SC0000's low value 2 is retained as native movie mode state. Operand 4 is the movie sync/device mask. Static layer preparation after 0x236 does not terminate the retained movie; 0x21c services it through EOF and subsequent surface cleanup stops/detaches it. The port type-checks the selected ResolvePacked record as MPEG without adding a scene base or fallback. ### 0x238 `set-anim-clock` (set-anim-clock, argc 1) -- **summary:** (duration) — set the GLOBAL animation clock: native ctx+0x51b78=0 (elapsed), +0x51b7c=duration. The generic instruction length is 3 dwords. NON-BLOCKING: only configures; the render loop advances it and interpolates all animating objects. SC0000 opening @0x123bd/@0x13858. Handler 0x4240e0; Kelebek VA 0x422390 is drift. +- **summary:** (duration) — configure the separate global finite-animation service window: native ctx+0x51b78=0 (start), +0x51b7c=duration. The generic instruction length is 3 dwords. NON-BLOCKING: gfx_animation_service_poll seeds the start from the shared frame timestamp and keeps redraw active through the duration. This is not the time source or cadence for cyclic object channels, which sample ctx+0x51b64/+0x51b68 with object-local starts and periods. SC0000 opening @0x123bd/@0x13858. Handler 0x4240e0; Kelebek VA 0x422390 is drift. - **grounding:** source=investigation, confidence=high +- **evidence:** Ghidra /v2: op_0x238_handler@0x4240e0 zeros retained-gfx manager+0xb564 and stores the duration at +0xb568. gfx_animation_service_poll@0x407640 seeds +0xb564 from manager+0xb550, marks redraw dirty while current<=start+duration, then clears the window. Cyclic worker gfx_object_anim_interpolate@0x473ed0 instead uses shared frame current/previous +0xb550/+0xb554 and per-channel object start/period fields. ### 0x239 `animate-gfx-srcrect-target` (u004223C0, argc 6) - **summary:** (handle)(delay_ms)(duration_ms)(frame_count)(column_count)(target_frame) — one-shot row-major source-rectangle cell channel. Worker gfx_worker_set_srcrect_cell @0x47ed90 stores timing at obj+0x48/+0x5c, layout at +0x238/+0x23c, and target at +0x234. C# currently retains the endpoint cell immediately. @@ -774,9 +775,9 @@ The handler requires an existing destination texture, allocates/reuses a 0x478-b First erase digit_capacity objects beginning at base_handle. Then split value by signed division/modulo 10 and bind at most digit_capacity retained objects using adjacent digit-width cells from the registered atlas. Flags bit 0 zero-pads, bit 1 centers the used digits, and bit 2 left-aligns them; with no alignment bit the value is right-aligned in the capacity. Invalid or unregistered style indices raise the engine's script error. ### 0x23c `sample-frame-time` (sample-frame-time, argc 0) -- **summary:** Shift the current retained-presentation timestamp to the previous-frame field, then sample the native monotonic millisecond clock as the new current timestamp. +- **summary:** Explicitly shift the shared current retained-presentation timestamp to the previous field, then sample the native monotonic millisecond clock as the new current timestamp. The active outer engine tick normally performs the same update; this opcode does not create a distinct timer or fixed-rate animation cadence. - **grounding:** source=investigation, confidence=high -- **evidence:** Ghidra /v2: op_0x23c_handler@0x417580 copies EngineCtx frame_timer at +0x51b64 to +0x51b68, then stores imp_winmm_timeGetTime() at +0x51b64. BTL, ADDEXP, SHOWGROW, USEMAGIC, and FIELD place it at presentation/present-frame boundaries. +- **evidence:** Ghidra /v2: op_0x23c_handler@0x417580 copies EngineCtx frame_timer_current at +0x51b64 to frame_timer_previous at +0x51b68, then stores imp_winmm_timeGetTime() at +0x51b64. engine_main_tick_with_exception_policy@0x411840 performs the same shift/sample once per active outer presentation tick before dirty/movie rendering. BTL, ADDEXP, SHOWGROW, USEMAGIC, and FIELD place the explicit opcode at presentation/present-frame boundaries. ### 0x23d `release-transient-surfaces` (release-transient-surfaces, argc 0) - **summary:** Stop movie bindings and release transient gfx surface slots 42 through 999 inclusive, preserving system-owned slots 0 through 41. diff --git a/docs/phase-a-slice-plan.md b/docs/phase-a-slice-plan.md index b7d1683..82acc20 100644 --- a/docs/phase-a-slice-plan.md +++ b/docs/phase-a-slice-plan.md @@ -2270,3 +2270,205 @@ Godot selftest. produced no `movie stop-time unavailable` warning, confirming the ordinary DirectShow timing handoff. **Next:** continue with the next concrete discrepancy reached by manual testing. + +## Performance tuning sidebar (started 2026-07-22) + +This bounded effort addresses frame-time collapse during simultaneous retained effects (first observed in +SC0000 immediately before the CHAPTER movie) and in unit-heavy dungeon presentation. Earlier work already +removed redraws during static waits, batched the CPU backbuffer, cached decoded source pixels, and added an +integer-translation raster path. The remaining architecture still rebuilds an 800x600 RGBA backbuffer in +C# and uploads the complete image whenever any visual channel is active. Effect bursts multiply full-screen +and general-affine pixel work; a single ambient spritesheet channel also keeps that path active every Godot +frame even when its discrete source cell has not changed. + +The effort will keep `GfxState` as the backend-neutral AGE truth and retain the current software renderer as +a fidelity oracle. Optimization claims require repeatable frame-time evidence from the real interactive +path, not screenshot-sequence runs whose PNG I/O dominates timing. + +### Target workloads and success measures + +Use three fixed workloads: a static ADV wait (control), the SC0000 pre-CHAPTER burst, and the +DEBUGMAP/FIELD camera-pan stress case as the current dungeon proxy. Save loading is not yet available, so +reaching a reproducibly unit-heavy story dungeon is disproportionate to this sidebar; add that validation +later when save loading or progression makes it practical. Capture the exact script/offset alongside each +frame. Compare equivalent Release/windowed runs by median, p95, and p99 frame time, recomposition time, +raster time, upload time, allocation rate, visible/time-varying object count, raster path, and candidate +pixel count. Track both presentation cadence and the cost of each recomposed frame: reducing how often an +unchanged discrete animation is drawn must not disguise an over-budget frame when it does change. The +immediate target is sustained 60 FPS where the native presentation has no intentional lower cadence; p95 +must remain under 16.67 ms on the development machine, with no screenshot or behavioral regression at the +sampled coordinates. + +### Execution slices + +- [x] **P0 - frame/compositor performance log.** Add an opt-in `--perf-log ` diagnostic. Record bounded, + buffered per-frame phase timings, compositor workload counters, managed allocations/GC deltas, and the + current VM script/offset/opcode. Document the schema and validate the writer independently of Godot. +- [x] **P1 - capture and attribution.** Record the static ADV control, SC0000 burst, and DEBUGMAP/FIELD + dungeon proxy without `--gfx-log`, `--timeline-log`, or frame PNG capture. Use controlled compose/upload + ablations only if the phase timings do not isolate the cost. Commit the baseline percentiles and exact + canonical runtime coordinates here. A real unit-heavy story dungeon is deferred until it is practical + to reach reproducibly. +- [ ] **P2 - fidelity-neutral CPU wins.** Remove normal-path diagnostic allocation and refine the ambiguous + presentation/affine counters, then avoid recomposition between discrete spritesheet cell changes and + benchmark translation, affine, and safe opaque raster fast paths. Land only changes with measured wins + and focused differential raster/presentation coverage. +- [ ] **P3 - GPU retained-renderer prototype.** Upload decoded/color-key texture variants once and mirror + ordinary retained objects into GPU-native Godot drawing while preserving handle z-order, atlas regions, + transforms, opacity/tint, and blend mode. Begin with dungeon sprites and ordinary translated textures; + compare selected frames against the software oracle behind a backend switch. +- [ ] **P4 - GPU special paths and backend decision.** Extend the prototype through affine effects, + additive/tint channels, created surfaces, transitions, and movie surfaces. Adopt it as the default only + after target-workload frame evidence and visual equivalence; otherwise retain documented CPU fallbacks + for unsupported paths. + +Do not optimize VM dispatch or investigate GPU stalls without evidence from P0/P1. `--trace-histogram` +remains the opcode-frequency tool; it is not a frame profiler. Godot's generic frame monitor is useful +corroboration, but the project log owns the AGE-object and raster-work attribution required by these slices. + +### P0 frame/compositor performance log implemented (2026-07-22) + +Godot now accepts `--perf-log `. The buffered writer records one row per `_Process` frame with the +VM script/offset/opcode at frame entry and the actual presentation boundary, Godot delta, measured main-loop +phases, managed allocations/GC deltas, and +the retained compositor's clear/snapshot/resolve/source-prep/raster/SetData/texture-upload split. Its workload counters +include actual object/layer visits, sampled time-varying objects, transition and blend categories, integer +versus affine paths, dynamic sources, source-pixel area, and clipped destination bounding-box candidates. +The writer and affine clipping calculation are Godot-independent and directly unit tested. `RenderObject` +now exposes whether its sampled object still has an active finite, spritesheet, color, rotation, surface, or +range-transform channel; this is observation only and does not alter scheduling. + +The threaded selftest wrote 101 coordinate-bearing rows and remained `SELFTEST OK`. A five-frame headless +SC0000 schema smoke used isolated output paths and exercised one real recomposition, producing populated +snapshot/resolve/object/skip counters; its dummy-renderer viewport warnings are why headless numbers are not +performance evidence. Validation: 337 engine tests pass, including the new CSV/clipping and time-varying +object regressions, and the Godot build has zero warnings/errors. **Next:** P1 must capture windowed, speed-1 +control/pre-CHAPTER/quiet-dungeon/unit-heavy-dungeon runs without the high-volume diagnostics, then record +their exact coordinates and percentile attribution here before selecting P2 changes. + +For the duration of P1/P2 collection, `run-godot.cmd` now opts into timestamped performance capture on every +windowed run. The launcher creates `build/perf/run-yyyyMMdd-HHmmss-fff.csv` and prints its path, allowing a +normal play session to cover multiple reported passages without restarting solely for instrumentation. +Direct PowerShell launches remain opt-in through `-PerfLog`, and selftests remain unprofiled. Remove this +temporary batch-file default when the performance effort closes. + +### P1 capture 1 - SC0000 through the pre-CHAPTER burst (2026-07-22) + +`build/perf/run-20260722-105708-610.csv` is the first controlled interactive capture: 3,307 frames over +55.1 seconds, including 2,836 SC0000 frames and 1,273 SC0000 recompositions. Static SC0000 frames establish +the control inside the same run: across 1,563 non-recomposited frames, measured main-loop p50/p95/p99 was +0.014/0.024/0.032 ms. The active renderer is the problem: SC0000 recompositions measured main-loop +p50/p95/p99 21.80/55.35/82.69 ms; raster p95 was 54.57 ms, while snapshot p95 was 0.017 ms, +`Image.SetData` p95 0.456 ms, and texture upload p95 0.215 ms. + +The reported simultaneous-effect lag is one contiguous 83-frame plateau (frames 1618-1700, virtual time +20,727-26,306 ms) parked at presentation boundary `SC0000@0x123de` (`0x21c`). Its main-loop p50/p95/max was +64.28/87.82/91.54 ms, equivalent to roughly 15.6 FPS at the median and 11.4 FPS at p95. Rasterization was +98.4% of mean main-loop time. The workload grows from 8 to 12 drawn layers and averages 3.85 million clipped +candidate pixels per frame (4.98 million maximum), with as many as three general-affine layers, five +additive layers, and ten viewport-covering layers. The worst frame spent 90.82 of 91.54 ms rasterizing +11 layers; snapshot, resolution, source prep, SetData, and upload together remained below one millisecond. + +A secondary lead appears outside the severe plateau: recomposited allocation p95 is 1,961,448 bytes and +source-prep p95 is 2.81 ms, with 0.991 correlation between the two. The size closely matches one 800x600 +RGBA clone, and the affected rows have three dynamic layers; this is strong evidence for the existing +dynamic-color-key clone path, but it is not the cause of the 80-90 ms plateau (whose source prep is about +0.003 ms). Treat clone removal as a later independent P2 win. + +This capture confirms the CPU rasterizer as the SC0000 bottleneck and makes upload/snapshot optimization a +low priority. P1 remains open until quiet- and unit-heavy-dungeon captures establish whether discrete +spritesheet scheduling is enough for dungeons or whether their pixel workload independently requires the +GPU retained-renderer path. + +### P1 capture 2 - DEBUGMAP/FIELD camera pan (2026-07-22) + +`build/perf/run-20260722-112100-189.csv` is a 1,381-frame interactive DEBUGMAP stress run. The map portion +contains 800 recomposited frames over 39.8 seconds. It measured main-loop p50/p95/p99 +49.17/64.59/68.39 ms and raster p50/p95 45.58/59.36 ms. Snapshot, resolution, source preparation, +`Image.SetData`, and texture upload again remain small in steady state; raster time correlates 0.987 with +main-loop time. The dominant idle/pan boundary is `FIELD.BIN@0x1029` (`0xc8`): 438 samples average roughly +962 visited objects, 961 submitted layers, 51 time-varying objects, and 2.16 million clipped candidate +pixels. Its main-loop p50/p95 is 49.05/59.03 ms. + +Camera position materially changes work rather than eliminating the bottleneck. Across representative +50-frame windows, candidate pixels range from 1.12 to 3.10 million and average main-loop time from 28.1 to +63.8 ms; candidate count correlates 0.858 with main time. Object count alone is not enough to explain the +range. At the same approximately 962-object FIELD boundary, unusually light frames with 953 integer and +only seven affine layers render 1.20 million candidates in about 10.3 ms, while typical frames with roughly +432 integer and 526 affine layers render 1.6-2.5 million candidates in about 26-60 ms. General-affine pixel +sampling is therefore a major dungeon cost in addition to the persistent layer traversal. + +The run exposes two independent secondary issues. Recomposited FIELD frames allocate about 3.59 MB at the +median and trigger 32 gen-0, ten gen-1, and five gen-2 collections. The compositor currently formats a +verbose outcome string for every visited object even when neither `--gfx-log` nor `--timeline-log` created +the decisions dictionary; gating that diagnostic formatting is the first low-risk P2 allocation fix. One +outlier (frame 1065) spends 37.99 ms resolving a resource and 48.69 ms rasterizing for a 90.53 ms total; +the following steady frames return to raster dominance, so resource-resolution/GC stalls should be tracked +separately from the continuous map cost. + +DEBUGMAP is sufficient as an intentionally heavy retained-map stress case: it confirms that discrete-cell +scheduling can remove unnecessary frames from the 51 animated objects, but cannot make a recomposed frame +with hundreds of mostly affine layers fit a 16.67 ms budget by itself. P2 should gate unused diagnostic +strings, add discrete-cell scheduling, and benchmark affine/opaque fast paths. A representative real +unit-heavy dungeon remains a later validation workload once save loading or progression makes it practical; +DEBUGMAP is the accepted P1/P3 stress proxy for now. + +### Evidence-driven performance action plan (2026-07-22) + +The save-loading limitation makes DEBUGMAP/FIELD the accepted dungeon proxy for this effort, so P1 is +closed. The SC0000 plateau and DEBUGMAP steady map load exercise complementary failure modes: SC0000 has +few layers but extreme full-screen/additive pixel work, while DEBUGMAP has hundreds of retained layers, +many sampled through the affine path, and discrete animation that currently requests a recomposition every +Godot frame. Execute the following in order, retaining the software compositor as the pixel oracle. + +1. **P2a - remove diagnostic-only allocation from normal rendering.** Construct per-object outcome strings + and final `z` decision strings only when `--gfx-log` or `--timeline-log` actually supplied a decisions + dictionary. Preserve byte-for-byte diagnostic output when enabled. Re-run DEBUGMAP and require a large + reduction from its approximately 3.59 MB median allocation per recomposition without worsening raster + time; if less than 70% disappears, use an allocation trace to identify the remaining owners before + doing speculative collection tuning. +2. **P2b - measure the two ambiguous dirty/raster categories.** Extend the low-overhead counters only as + needed to distinguish VM-requested, continuous-channel, and discrete-cell presentation, and to split + pure fractional translation from scale/rotation/general affine work. The current log proves that the + broad categories matter but cannot tell whether DEBUGMAP's roughly 526 apparent affine layers are + camera-induced fractional translations or genuine scale/rotation. Do not change sampling semantics on + that assumption alone. +3. **P2c - reproduce the native shared dirty/cell cadence.** Native does not give each visible sprite a + host-frame redraw timer. One shared current/previous millisecond frame-time pair feeds every channel; + op `0x231` compares the source cell selected at those two samples and raises graphics dirty only when it + changes. Retained mutations and genuinely continuous channels still redraw as required, while an + opcode-`0xc8` poll iteration alone does not. Track retained mutation publication so FIELD's `sleep(1)` + input loop stops forcing unchanged compositions, and replace “any spritesheet is active” with shared + cell-change detection. FIELD's prototype `0x9c40` is configured once at 200 ms/four cells and cloned + before first presentation, so the unit family is phase-locked at 5 Hz rather than 51 independent + deadlines. Cover clone-before/after-first-sample, reconfiguration, differing periods, wraparound, and + exact boundary cases. The DEBUGMAP acceptance metric is recompositions per second and total delivered + frame time; the separately reported p50/p95 cost of frames that do recompose must remain visible. +4. **P2d - turn translation-like affine work into a verified fast path.** If P2b confirms pure unit-matrix + fractional translations, implement the nearest-neighbor-equivalent translated raster path and prove it + byte-for-byte against the existing inverse-mapped oracle across positive/negative coordinates, + half-pixel boundaries, clipping, opacity/tint, and every blend mode. This is the highest-potential + DEBUGMAP per-compose CPU win because the existing translated loop is much cheaper than a general matrix + inverse and transform per destination pixel. +5. **P2e - specialize the remaining hot pixel loops.** In descending evidence value, benchmark: + incremental inverse coordinates across an affine scanline; axis-aligned scale specialization; and + opaque/full-opacity/unmodulated translated row copies or alpha-run copies where source transparency + permits. Use randomized differential raster tests against the current implementation plus the SC0000 + and DEBUGMAP captures. Address the dynamic color-key full-frame clone separately because it explains an + allocation/source-prep spike but neither primary raster plateau. Do not spend time on snapshot, clear, + `Image.SetData`, texture upload, VM dispatch, or parallel rasterization while their measured contribution is + small or a retained GPU renderer is the cleaner boundary. +6. **P2 exit gate and P3 trigger.** After the safe CPU batch, repeat equivalent SC0000 and DEBUGMAP runs. + Report both end-to-end cadence and recomposed-frame p50/p95/p99. If either workload's required + recompositions remain above 16.67 ms p95, begin P3 rather than accumulating increasingly complex CPU + special cases. The expected P3 prototype mirrors ordinary translated/atlas dungeon objects into Godot + canvas items behind a backend switch, uploads decoded/color-key variants once, and updates retained + items only when their state changes. It must preserve handle order, transforms, tint/opacity, and blend + behavior and compare selected output against the software oracle before expanding to SC0000's affine, + additive, transition, created-surface, and movie special paths in P4. + +Each landed optimization gets a before/after row in this document with capture path, canonical runtime +coordinate, p50/p95/p99, allocation, recomposition rate, and raster-work counters. Revert or leave behind a +disabled experiment when it does not produce a repeatable real-path improvement. The immediate +implementation slice is P2a followed by P2b; those make the next user capture cheaper and sufficiently +specific to choose the correct P2c/P2d implementation without another story-progression dependency. diff --git a/docs/tools-reference.md b/docs/tools-reference.md index 231c770..5776b9d 100644 --- a/docs/tools-reference.md +++ b/docs/tools-reference.md @@ -210,6 +210,27 @@ use the last `input-wait` event in `timeline.jsonl` as the authoritative manual `--scene SC0000 --boot --shot-sequence ... --gfx-log ...` to distinguish control-flow stalls from retained-object/compositor failures at an exact bytecode boundary. Relative output paths are project-relative (`godot/`). +**Godot performance frame log:** `--perf-log ` enables a buffered, diagnostic-only capture of the real +Godot path. Each row carries VM `script`/`offset`/`opcode` at frame entry and again at the actual presentation +boundary (`present_*`), Godot `delta_ms`, measured main-loop +time, pulse/movie/UI time, and a compositor breakdown: recomposition, clear, retained snapshot, texture +resolution/decode, color-key/source preparation, raster, `Image.SetData`, and `ImageTexture.Update`. Workload columns report transition +state, retained object visits, time-varying object visits, drawn/fill/transition/skipped layers, integer/ +affine/singular raster paths, dynamic/opaque/alpha/additive layers, source pixels, clipped affine bounding- +box candidate pixels, full-screen layers, main-thread managed allocations, and GC collection deltas. The +writer replaces the target, buffers 120 rows between flushes, and prints its frame/recomposition counts on +normal shutdown. Use a windowed Release-equivalent run at speed 1 for performance evidence; headless runs +validate the schema only. Do not combine baseline captures with `--shot-sequence`, `--gfx-log`, or +`--timeline-log`, whose diagnostics add substantial or differently shaped work. Example from `age-reimpl/`: +`godot --path godot -- --scene SC0000 --boot --perf-log ../build/perf/sc0000.csv`. + +During the tracked performance-tuning effort, `run-godot.cmd` passes the launcher's `-PerfLog` switch by +default. Every windowed batch-file launch creates `build/perf/run-yyyyMMdd-HHmmss-fff.csv` and prints the +absolute target before Godot starts; normal shutdown flushes it and prints the captured frame/recomposition +counts. This temporary batch-file default does not affect direct `run-godot.ps1` launches, whose `-PerfLog` +switch remains explicit, and it does not add a log to `-SelfTest`. Remove the batch-file opt-in after the +performance effort is accepted. + **Godot debug scene launcher:** press **F4** while the natural boot is showing TITLE. TITLE's visible menu is a live 1 ms sleep/input-poll loop rather than an ADV `wait-for-input`; the launcher identifies that exact active child frame and returns it cooperatively at the next completed opcode boundary. The overlay enumerates diff --git a/tools/age_opcodes_himegari.py b/tools/age_opcodes_himegari.py index 99c59b4..b2e7c01 100644 --- a/tools/age_opcodes_himegari.py +++ b/tools/age_opcodes_himegari.py @@ -71,7 +71,7 @@ INFERRED: dict[int, dict] = { 0x21b: dict(name='line-id?', category='marker', noop=True, confidence='med', source='harness', summary='1 imm; mov->0x21b->stmt-end; near save/load-messkip — likely line/stmt id, verify not msg-control'), 0x228: dict(name='query-gfx-translation-target', category='draw', noop=False, confidence='high', source='investigation', summary='0x228 query translation target (succ)(handle)(outX)(outY)(outZ): clone the retained object, decompose its target translation matrix at obj+0x17c, and return matrix translation obj+0x1ac/+0x1b0/+0x1b4. Returns succ=0 when found; when absent, writes succ=1 and leaves outputs untouched. The C# VM queries TranslationTarget independently of V24. See docs/engine-re.md §SC0000 anim cluster.'), 0x22f: dict(name='set-gfx-position-current', category='draw', noop=False, confidence='high', source='investigation', summary="(handle)(control)(x)(y)(z) — set the object's current/base translation matrix. The native worker also retains operand 2 as channel control state; the port currently applies x/y/z but ignores that control operand."), - 0x231: dict(name='animate-gfx-srcrect-loop', category='draw', noop=False, confidence='high', source='investigation', summary="(handle)(frame_period_ms)(frame_count)(column_count) — loop row-major through the spritesheet. Every frame preserves draw-texture's source-rectangle width/height; frame=floor(elapsed/frame_period)%frame_count, src offset=(frame%columns*width, frame/columns*height). Worker gfx_worker_anim_srcrect @0x47eec0; consumer gfx_object_anim_interpolate @0x473ed0."), + 0x231: dict(name='animate-gfx-srcrect-loop', category='draw', noop=False, confidence='high', source='investigation', summary="(handle)(frame_period_ms)(frame_count)(column_count) — loop row-major through the spritesheet. Every sample preserves draw-texture's source-rectangle width/height; frame=floor((shared_frame_time-object_start)/frame_period)%frame_count, src offset=(frame%columns*width, frame/columns*height). All objects use the retained manager's shared current/previous millisecond timestamps but retain their own start and period. The native consumer raises redraw dirty only when the current and previous samples select different cells. Worker gfx_worker_anim_srcrect @0x47eec0; consumer gfx_object_anim_interpolate @0x473ed0."), 0x232: dict(name='animate-gfx-color-loop', category='draw', noop=False, confidence='high', source='investigation', summary='0x232 anim-color (handle)(period)(alpha)(color): ping-pong the temporary packed ARGB passed to the normal object blit. Handler resolves negative alpha/RGB from static color obj+0x60 and clamps alpha above 255. Blend selector obj+0x30 is unchanged: mode 0 keeps default blending (animated alpha is inert; RGB is vertex modulation), while mode 1 uses sampled ARGB alpha as the SRCALPHA scale for additive composition. Fresh static color is 0xffffffff. The C# VM resolves sentinels and consumes sampled ARGB through the unchanged mode-specific path. See docs/engine-re.md §SC0000 anim cluster.'), 0x239: dict(name='animate-gfx-srcrect-target', category='draw', noop=False, confidence='high', source='investigation', summary='(handle)(delay_ms)(duration_ms)(frame_count)(column_count)(target_frame) — one-shot row-major source-rectangle cell channel. Worker gfx_worker_set_srcrect_cell @0x47ed90 stores timing at obj+0x48/+0x5c, layout at +0x238/+0x23c, and target at +0x234. C# currently retains the endpoint cell immediately.'), 0x23b: dict(name='draw-decimal-glyphs', category='draw', noop=False, confidence='high', source='investigation', summary='Draw an integer as decimal glyph objects from a style registered by opcode 0x13a.'), diff --git a/vm-map/engine-ctx.toml b/vm-map/engine-ctx.toml index 4e3af07..a840982 100644 --- a/vm-map/engine-ctx.toml +++ b/vm-map/engine-ctx.toml @@ -129,14 +129,19 @@ type = "void*" note = "retained_gfx_manager+0xa590 array of per-slot D3D texture wrappers selected by op 0x20d" [[field]] offset = 0x51b64 -name = "frame_timer" +name = "frame_timer_current" type = "int" -note = "frame timer at retained_gfx_manager+0xb550; present updates 0x51b64/0x51b68 and object animation samples it" +note = "current shared millisecond presentation timestamp at retained_gfx_manager+0xb550; active outer-engine ticks and op 0x23c sample timeGetTime, and every retained animation channel samples it" +[[field]] +offset = 0x51b68 +name = "frame_timer_previous" +type = "int" +note = "previous shared presentation timestamp at retained_gfx_manager+0xb554; shifted from current before each new sample, and op 0x231 compares current/previous source cells to raise redraw dirty only at cell changes" [[field]] offset = 0x51b78 -name = "anim_clock_elapsed" +name = "anim_clock_start" type = "int" -note = "global anim clock elapsed at retained_gfx_manager+0xb564; op 0x238 and object reset 0x1f6 zero it" +note = "start timestamp for the separate finite-animation service window at retained_gfx_manager+0xb564; seeded from frame_timer_current by gfx_animation_service_poll, while op 0x238, op 0x243, and object reset 0x1f6 zero it" [[field]] offset = 0x51b7c name = "anim_clock_duration" @@ -151,7 +156,7 @@ note = "retained_gfx_manager+0xb530 selected surface slot; -1 denotes device bac offset = 0x51b6c name = "gfx_dirty_a" type = "int" -note = "retained_gfx_manager+0xb558 redraw-dirty flag; active finite object channels set it even when detached by 0x242; op 0x1f6 clears it" +note = "retained_gfx_manager+0xb558 redraw-dirty flag; retained mutations and continuous channels set it, while op 0x231 sets it only when the sampled source cell differs across the shared current/previous frame timestamps; op 0x1f6 clears it" [[field]] offset = 0x51b70 name = "gfx_force_complete" diff --git a/vm-map/opcodes.toml b/vm-map/opcodes.toml index de1522f..b4b46bd 100644 --- a/vm-map/opcodes.toml +++ b/vm-map/opcodes.toml @@ -6027,12 +6027,12 @@ abi_source = "kelebek+decode-validated" [opcode.semantics] name = "animate-gfx-srcrect-loop" category = "draw" -summary = "(handle)(frame_period_ms)(frame_count)(column_count) — loop row-major through the spritesheet. Every frame preserves draw-texture's source-rectangle width/height; frame=floor(elapsed/frame_period)%frame_count, src offset=(frame%columns*width, frame/columns*height). Worker gfx_worker_anim_srcrect @0x47eec0; consumer gfx_object_anim_interpolate @0x473ed0." +summary = "(handle)(frame_period_ms)(frame_count)(column_count) — loop row-major through the spritesheet. Every sample preserves draw-texture's source-rectangle width/height; frame=floor((shared_frame_time-object_start)/frame_period)%frame_count, src offset=(frame%columns*width, frame/columns*height). All objects use the retained manager's shared current/previous millisecond timestamps but retain their own start and period. The native consumer raises redraw dirty only when the current and previous samples select different cells. Worker gfx_worker_anim_srcrect @0x47eec0; consumer gfx_object_anim_interpolate @0x473ed0." noop_headless = false source = "investigation" confidence = "high" depends_on = [] -evidence = "Native /v2 decompile: worker stores period at obj+0x230, frame_count at +0x238, columns at +0x23c. Interpolator computes ((now-start)/period)%frame_count, then offsets both source-rect X bounds by rect_width*(frame%columns) and Y bounds by rect_height*(frame/columns). SC0000 uses (100,8,4) with AE001H's eight 200x200 cells in a 4x2 800x400 sheet." +evidence = "Native /v2 decompile: worker stores/reset start at obj+0x21c, period at +0x230, frame_count at +0x238, and columns at +0x23c. Interpolator seeds the object start from manager+0xb550, computes ((current-start)/period)%frame_count, then offsets both source-rect X bounds by rect_width*(frame%columns) and Y bounds by rect_height*(frame/columns). It repeats the cell calculation with manager+0xb554 and sets manager+0xb558 dirty only when the two cells differ. engine_main_tick_with_exception_policy shifts current to previous and samples timeGetTime once per active outer tick. SC0000 uses (100,8,4) with AE001H's eight 200x200 cells in a 4x2 800x400 sheet. FIELD configures prototype 0x9c40 with (200,4,2), then DRAWCH clones its complete zero-start record to the entity handles before the first render, phase-locking that family." [[opcode.semantics.args]] i = 1 @@ -6218,12 +6218,12 @@ abi_source = "kelebek+decode-validated" [opcode.semantics] name = "set-anim-clock" category = "draw" -summary = "(duration) — set the GLOBAL animation clock: native ctx+0x51b78=0 (elapsed), +0x51b7c=duration. The generic instruction length is 3 dwords. NON-BLOCKING: only configures; the render loop advances it and interpolates all animating objects. SC0000 opening @0x123bd/@0x13858. Handler 0x4240e0; Kelebek VA 0x422390 is drift." +summary = "(duration) — configure the separate global finite-animation service window: native ctx+0x51b78=0 (start), +0x51b7c=duration. The generic instruction length is 3 dwords. NON-BLOCKING: gfx_animation_service_poll seeds the start from the shared frame timestamp and keeps redraw active through the duration. This is not the time source or cadence for cyclic object channels, which sample ctx+0x51b64/+0x51b68 with object-local starts and periods. SC0000 opening @0x123bd/@0x13858. Handler 0x4240e0; Kelebek VA 0x422390 is drift." noop_headless = false source = "investigation" confidence = "high" depends_on = [] -evidence = "" +evidence = "Ghidra /v2: op_0x238_handler@0x4240e0 zeros retained-gfx manager+0xb564 and stores the duration at +0xb568. gfx_animation_service_poll@0x407640 seeds +0xb564 from manager+0xb550, marks redraw dirty while current<=start+duration, then clears the window. Cyclic worker gfx_object_anim_interpolate@0x473ed0 instead uses shared frame current/previous +0xb550/+0xb554 and per-channel object start/period fields." [[opcode.semantics.args]] i = 1 @@ -6363,12 +6363,12 @@ abi_source = "kelebek+decode-validated" [opcode.semantics] name = "sample-frame-time" category = "draw" -summary = "Shift the current retained-presentation timestamp to the previous-frame field, then sample the native monotonic millisecond clock as the new current timestamp." +summary = "Explicitly shift the shared current retained-presentation timestamp to the previous field, then sample the native monotonic millisecond clock as the new current timestamp. The active outer engine tick normally performs the same update; this opcode does not create a distinct timer or fixed-rate animation cadence." noop_headless = false source = "investigation" confidence = "high" depends_on = [] -evidence = "Ghidra /v2: op_0x23c_handler@0x417580 copies EngineCtx frame_timer at +0x51b64 to +0x51b68, then stores imp_winmm_timeGetTime() at +0x51b64. BTL, ADDEXP, SHOWGROW, USEMAGIC, and FIELD place it at presentation/present-frame boundaries." +evidence = "Ghidra /v2: op_0x23c_handler@0x417580 copies EngineCtx frame_timer_current at +0x51b64 to frame_timer_previous at +0x51b68, then stores imp_winmm_timeGetTime() at +0x51b64. engine_main_tick_with_exception_policy@0x411840 performs the same shift/sample once per active outer presentation tick before dirty/movie rendering. BTL, ADDEXP, SHOWGROW, USEMAGIC, and FIELD place the explicit opcode at presentation/present-frame boundaries." [[opcode]] op = 0x23d