Capture actionable STEP-LIMIT diagnostics

This commit is contained in:
gamer147
2026-07-29 18:51:06 -04:00
parent 32c5d1e901
commit f7751c2b93
7 changed files with 146 additions and 16 deletions

View File

@@ -928,6 +928,19 @@ installed-A1215 regressions prove the exact prefix and unchanged PCM payload. Va
tests, a zero-warning Godot build, and the Himegari-targeted threaded selftest, which loads the real A1215
buffer through Godot and reports `first-riff-boundary=ok` without seek spam.
**Stage 01-01 STEP-LIMIT diagnostics added (2026-07-29):** after a reveal-zone event, the persistent
SYSTEM4 run reached its artificial 20,000,000-instruction cap. `SYSTEM4 P592` correctly identifies the last
ADV boundary (`SC0600@0x33fd`, followed by cleanup and return), but the page map cannot identify code that
runs after that page. The final page was recorded about 29 seconds before the halt, so the existing report
cannot distinguish an SC0600 cleanup loop from resumed FIELD processing.
Godot now retains the deepest frame chain before a halted frame unwinds and automatically emits a bounded
STEP-LIMIT report: exact script/offset/opcode, nested frame chain, hottest sites in the final 128 instructions,
and the final 16-instruction sequence. It also writes the ordinary full stall snapshot as
`user://diagnostics/step-limit-<timestamp>.json` and copies its coordinate/path. Focused formatter/stack
regressions and all 530 engine tests pass; the Godot build is warning-free and the Himegari-targeted threaded
selftest passes. No loop behavior or safety limit has been changed pending one instrumented reproduction.
**Cyclic reset implemented (2026-07-29):** `0x230(handle)` now gets or creates the retained object,
disables the four looping channels represented by the compositor, and clears the complete native
start/period block—including the preserved raw state for the currently unmodeled second cyclic matrix.

View File

@@ -213,6 +213,13 @@ and pending movie records include `first_frame_source_pts_ms`; the ordinary `mov
the same source PTS alongside the render frame, which distinguishes encoded stream lead-in from decode/presentation
latency.
If the interactive VM reaches its `STEP-LIMIT` safety cap, Godot now captures the same diagnostic
automatically as `user://diagnostics/step-limit-<timestamp>.json` and copies its coordinate/path to the
clipboard. Before nested frames unwind, the trace sink preserves the deepest active script stack. The console
also prints the exact final script/offset/opcode, that frame chain, the hottest sites in the bounded final
128-instruction window, and the final 16-instruction sequence. This makes the last ADV locator unnecessary for
identifying a post-dialogue loop; send either the `step-limit` console block or the generated JSON.
## Native FFmpeg movie shim (Windows x64)
These PowerShell tools build the selected Windows-x64 live movie backend. The dependency manifest pins an

View File

@@ -30,6 +30,7 @@
<Compile Include="..\..\godot\PageLocatorState.cs" Link="PageLocatorState.cs" />
<Compile Include="..\..\godot\GodotTimelineLog.cs" Link="GodotTimelineLog.cs" />
<Compile Include="..\..\godot\GodotTraceSink.cs" Link="GodotTraceSink.cs" />
<Compile Include="..\..\godot\StepLimitDiagnosticFormatter.cs" Link="StepLimitDiagnosticFormatter.cs" />
<Compile Include="..\..\godot\PerformanceFrameLog.cs" Link="PerformanceFrameLog.cs" />
<Compile Include="..\..\godot\MovieSurfaceRegistry.cs" Link="MovieSurfaceRegistry.cs" />
<Compile Include="..\..\godot\RiffWaveSanitizer.cs" Link="RiffWaveSanitizer.cs" />

View File

@@ -1,5 +1,6 @@
using Age.Engine.Diagnostics;
using Age.Engine.Model;
using Age.Engine.Sys4;
public class GodotTraceSinkTests
{
@@ -28,4 +29,48 @@ public class GodotTraceSinkTests
Assert.Equal(0x2400 + 12, snapshot.RecentSteps[0].Offset);
Assert.Equal(0x2400 + 139, snapshot.RecentSteps[^1].Offset);
}
[Fact]
public void HaltSnapshotRetainsDeepestStackBeforeFramesUnwind()
{
using var locator = new PageLocatorState("SYSTEM4", null);
var sink = new GodotTraceSink(locator);
sink.Emit(TraceEvent.FrameEnter("SYSTEM4.BIN", 0, FrameCause.TopScene));
sink.Emit(TraceEvent.FrameEnter("FIELD.BIN", 1, FrameCause.CallScript, 0x337d));
sink.Emit(TraceEvent.FrameEnter("SC0600.BIN", 2, FrameCause.CallScript, 0x1202));
sink.Emit(TraceEvent.Step(10,
new Instruction(0x3403, 0x8f, new[] { new Operand(0, 0x6f28) }), 2));
sink.Emit(TraceEvent.FrameExit("SC0600.BIN", 2, "Halted"));
sink.Emit(TraceEvent.FrameExit("FIELD.BIN", 1, "Halted"));
sink.Emit(TraceEvent.FrameExit("SYSTEM4.BIN", 0, "Halted"));
GodotTraceSnapshot snapshot = Assert.IsType<GodotTraceSnapshot>(sink.HaltSnapshot);
Assert.Equal("SC0600.BIN", snapshot.CurrentScript);
Assert.Equal(0x3403, snapshot.CurrentOffset);
Assert.Equal(new[] { "SYSTEM4.BIN", "FIELD.BIN", "SC0600.BIN" }, snapshot.CallStack);
}
[Fact]
public void StepLimitReportShowsCoordinateFramesHotSitesAndTail()
{
OpcodeTable table = OpcodeTableJson.Load(Paths.OpcodesJson);
var recent = new[]
{
new GodotTraceStepSnapshot("FIELD.BIN", 0x100, 0x55, 1),
new GodotTraceStepSnapshot("FIELD.BIN", 0x107, 0x8e, 1),
new GodotTraceStepSnapshot("FIELD.BIN", 0x100, 0x55, 1),
};
var snapshot = new GodotTraceSnapshot(
"FIELD.BIN", 0x100, 0x55, 1,
new[] { "SYSTEM4.BIN", "FIELD.BIN" }, recent);
string report = StepLimitDiagnosticFormatter.Format(snapshot, table, topSites: 2, tailSteps: 2);
Assert.Contains("[step-limit] last: FIELD@0x100 op=0x055 mov depth=1", report);
Assert.Contains("[step-limit] frames: SYSTEM4 > FIELD", report);
Assert.Contains("2x FIELD@0x100 op=0x055 mov", report);
Assert.DoesNotContain("SYSTEM4@0x", report);
Assert.EndsWith("[step-limit] FIELD@0x100 op=0x055 mov", report);
}
}

View File

@@ -15,6 +15,7 @@ public sealed class GodotTraceSink : ITraceSink
private readonly Stack<string> _scripts = new();
private readonly Queue<GodotTraceStepSnapshot> _recentSteps = new();
private GodotTraceStepSnapshot? _latestStep;
private GodotTraceSnapshot? _haltSnapshot;
public GodotTraceSink(PageLocatorState locator, GodotTimelineLog? timeline = null)
{ _locator = locator; _timeline = timeline; }
// The page locator needs the exact script/offset even when the heavier timeline log is disabled.
@@ -54,6 +55,8 @@ public sealed class GodotTraceSink : ITraceSink
string[] callStack;
lock (_snapshotLock)
{
if (e.Text == "Halted" && _haltSnapshot == null)
_haltSnapshot = SnapshotLocked();
if (_scripts.Count > 0) _scripts.Pop();
callStack = CurrentCallStackLocked();
}
@@ -84,17 +87,13 @@ public sealed class GodotTraceSink : ITraceSink
public GodotTraceSnapshot Snapshot()
{
lock (_snapshotLock)
{
GodotTraceStepSnapshot? current = _latestStep;
return new GodotTraceSnapshot(
current?.Script ?? (_scripts.Count > 0 ? _scripts.Peek() : "<unknown>"),
current?.Offset ?? -1,
current?.Opcode ?? -1,
current?.Depth ?? System.Math.Max(0, _scripts.Count - 1),
CurrentCallStackLocked(),
_recentSteps.ToArray());
}
lock (_snapshotLock) return SnapshotLocked();
}
/// <summary>The deepest still-active script stack captured before a halted frame unwinds.</summary>
public GodotTraceSnapshot? HaltSnapshot
{
get { lock (_snapshotLock) return _haltSnapshot; }
}
/// <summary>Allocation-free current coordinate for once-per-frame diagnostics.</summary>
@@ -109,6 +108,18 @@ public sealed class GodotTraceSink : ITraceSink
System.Array.Reverse(stack);
return stack;
}
private GodotTraceSnapshot SnapshotLocked()
{
GodotTraceStepSnapshot? current = _latestStep;
return new GodotTraceSnapshot(
current?.Script ?? (_scripts.Count > 0 ? _scripts.Peek() : "<unknown>"),
current?.Offset ?? -1,
current?.Opcode ?? -1,
current?.Depth ?? System.Math.Max(0, _scripts.Count - 1),
CurrentCallStackLocked(),
_recentSteps.ToArray());
}
}
public sealed record GodotTraceStepSnapshot(string Script, int Offset, int Opcode, int Depth);

View File

@@ -580,6 +580,12 @@ public partial class Main : Godot.Control
GD.Print($"[vm] ended: {_vm!.HaltReason ?? "unknown"} after {_vm.Steps} steps");
ReportSubroutines();
ShowEnd();
if (_vm.HaltReason == "STEP-LIMIT")
{
GodotTraceSnapshot haltTrace = _trace.HaltSnapshot ?? _trace.Snapshot();
GD.Print(StepLimitDiagnosticFormatter.Format(haltTrace, _table!));
CaptureStallDiagnostic(haltTrace, "step-limit");
}
if (_selftest) RunSelfTest();
}
}
@@ -742,12 +748,13 @@ public partial class Main : Godot.Control
private static bool IsAdvanceAction(int action) => action is 4 or 5;
private static bool HasAdvanceAction(int mask) => (mask & ((1 << 4) | (1 << 5))) != 0;
private void CaptureStallDiagnostic()
private void CaptureStallDiagnostic(GodotTraceSnapshot? traceOverride = null,
string snapshotKind = "stall")
{
try
{
long nowMs = _clock.NowMs;
GodotTraceSnapshot trace = _trace.Snapshot();
GodotTraceSnapshot trace = traceOverride ?? _trace.Snapshot();
var activeMovies = _movies
.OrderBy(pair => pair.Key)
.Select(pair =>
@@ -815,7 +822,7 @@ public partial class Main : Godot.Control
string directory = ProjectSettings.GlobalizePath("user://diagnostics");
System.IO.Directory.CreateDirectory(directory);
string path = System.IO.Path.Combine(directory,
$"stall-{System.DateTimeOffset.Now:yyyyMMdd-HHmmss-fff}.json");
$"{snapshotKind}-{System.DateTimeOffset.Now:yyyyMMdd-HHmmss-fff}.json");
var jsonOptions = new JsonSerializerOptions
{
WriteIndented = true,
@@ -825,10 +832,10 @@ public partial class Main : Godot.Control
string coordinate = trace.CurrentOffset >= 0
? $"{System.IO.Path.GetFileNameWithoutExtension(trace.CurrentScript).ToUpperInvariant()}@0x{trace.CurrentOffset:x}"
: trace.CurrentScript;
string clipboard = $"{coordinate} · stall snapshot {path}";
string clipboard = $"{coordinate} · {snapshotKind} snapshot {path}";
DisplayServer.ClipboardSet(clipboard);
_status.Text = $"Diagnostic saved: {coordinate} (path copied)";
GD.Print($"[diagnostic] stall snapshot {coordinate} -> {path}");
GD.Print($"[diagnostic] {snapshotKind} snapshot {coordinate} -> {path}");
}
catch (System.Exception exception)
{

View File

@@ -0,0 +1,46 @@
using System;
using System.IO;
using System.Linq;
using System.Text;
using Age.Engine.Model;
/// <summary>Formats the bounded trace retained by the Godot frontend when the VM safety cap fires.</summary>
public static class StepLimitDiagnosticFormatter
{
public static string Format(GodotTraceSnapshot snapshot, OpcodeTable table,
int topSites = 8, int tailSteps = 16)
{
string Location(GodotTraceStepSnapshot step)
{
string script = Path.GetFileNameWithoutExtension(step.Script).ToUpperInvariant();
string mnemonic = table.Label(step.Opcode);
if (string.IsNullOrEmpty(mnemonic)) mnemonic = "unknown";
return $"{script}@0x{step.Offset:x} op=0x{step.Opcode:x3} {mnemonic}";
}
var output = new StringBuilder();
var current = new GodotTraceStepSnapshot(
snapshot.CurrentScript, snapshot.CurrentOffset, snapshot.CurrentOpcode, snapshot.CurrentDepth);
output.AppendLine($"[step-limit] last: {Location(current)} depth={snapshot.CurrentDepth}");
output.AppendLine($"[step-limit] frames: {string.Join(" > ",
snapshot.CallStack.Select(name => Path.GetFileNameWithoutExtension(name).ToUpperInvariant()))}");
output.AppendLine($"[step-limit] hot sites in final {snapshot.RecentSteps.Count} steps:");
foreach (var site in snapshot.RecentSteps
.GroupBy(step => (step.Script, step.Offset, step.Opcode))
.OrderByDescending(group => group.Count())
.ThenBy(group => group.Key.Script, StringComparer.Ordinal)
.ThenBy(group => group.Key.Offset)
.Take(Math.Max(0, topSites)))
{
var sample = new GodotTraceStepSnapshot(
site.Key.Script, site.Key.Offset, site.Key.Opcode, 0);
output.AppendLine($"[step-limit] {site.Count(),4}x {Location(sample)}");
}
int tailStart = Math.Max(0, snapshot.RecentSteps.Count - Math.Max(0, tailSteps));
output.AppendLine($"[step-limit] final {snapshot.RecentSteps.Count - tailStart} steps:");
for (int index = tailStart; index < snapshot.RecentSteps.Count; index++)
output.AppendLine($"[step-limit] {Location(snapshot.RecentSteps[index])}");
return output.ToString().TrimEnd();
}
}