Capture actionable STEP-LIMIT diagnostics
This commit is contained in:
@@ -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
|
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.
|
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,
|
**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
|
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.
|
start/period block—including the preserved raw state for the currently unmodeled second cyclic matrix.
|
||||||
|
|||||||
@@ -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
|
the same source PTS alongside the render frame, which distinguishes encoded stream lead-in from decode/presentation
|
||||||
latency.
|
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)
|
## Native FFmpeg movie shim (Windows x64)
|
||||||
|
|
||||||
These PowerShell tools build the selected Windows-x64 live movie backend. The dependency manifest pins an
|
These PowerShell tools build the selected Windows-x64 live movie backend. The dependency manifest pins an
|
||||||
|
|||||||
@@ -30,6 +30,7 @@
|
|||||||
<Compile Include="..\..\godot\PageLocatorState.cs" Link="PageLocatorState.cs" />
|
<Compile Include="..\..\godot\PageLocatorState.cs" Link="PageLocatorState.cs" />
|
||||||
<Compile Include="..\..\godot\GodotTimelineLog.cs" Link="GodotTimelineLog.cs" />
|
<Compile Include="..\..\godot\GodotTimelineLog.cs" Link="GodotTimelineLog.cs" />
|
||||||
<Compile Include="..\..\godot\GodotTraceSink.cs" Link="GodotTraceSink.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\PerformanceFrameLog.cs" Link="PerformanceFrameLog.cs" />
|
||||||
<Compile Include="..\..\godot\MovieSurfaceRegistry.cs" Link="MovieSurfaceRegistry.cs" />
|
<Compile Include="..\..\godot\MovieSurfaceRegistry.cs" Link="MovieSurfaceRegistry.cs" />
|
||||||
<Compile Include="..\..\godot\RiffWaveSanitizer.cs" Link="RiffWaveSanitizer.cs" />
|
<Compile Include="..\..\godot\RiffWaveSanitizer.cs" Link="RiffWaveSanitizer.cs" />
|
||||||
|
|||||||
@@ -1,5 +1,6 @@
|
|||||||
using Age.Engine.Diagnostics;
|
using Age.Engine.Diagnostics;
|
||||||
using Age.Engine.Model;
|
using Age.Engine.Model;
|
||||||
|
using Age.Engine.Sys4;
|
||||||
|
|
||||||
public class GodotTraceSinkTests
|
public class GodotTraceSinkTests
|
||||||
{
|
{
|
||||||
@@ -28,4 +29,48 @@ public class GodotTraceSinkTests
|
|||||||
Assert.Equal(0x2400 + 12, snapshot.RecentSteps[0].Offset);
|
Assert.Equal(0x2400 + 12, snapshot.RecentSteps[0].Offset);
|
||||||
Assert.Equal(0x2400 + 139, snapshot.RecentSteps[^1].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);
|
||||||
|
}
|
||||||
}
|
}
|
||||||
|
|||||||
@@ -15,6 +15,7 @@ public sealed class GodotTraceSink : ITraceSink
|
|||||||
private readonly Stack<string> _scripts = new();
|
private readonly Stack<string> _scripts = new();
|
||||||
private readonly Queue<GodotTraceStepSnapshot> _recentSteps = new();
|
private readonly Queue<GodotTraceStepSnapshot> _recentSteps = new();
|
||||||
private GodotTraceStepSnapshot? _latestStep;
|
private GodotTraceStepSnapshot? _latestStep;
|
||||||
|
private GodotTraceSnapshot? _haltSnapshot;
|
||||||
public GodotTraceSink(PageLocatorState locator, GodotTimelineLog? timeline = null)
|
public GodotTraceSink(PageLocatorState locator, GodotTimelineLog? timeline = null)
|
||||||
{ _locator = locator; _timeline = timeline; }
|
{ _locator = locator; _timeline = timeline; }
|
||||||
// The page locator needs the exact script/offset even when the heavier timeline log is disabled.
|
// 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;
|
string[] callStack;
|
||||||
lock (_snapshotLock)
|
lock (_snapshotLock)
|
||||||
{
|
{
|
||||||
|
if (e.Text == "Halted" && _haltSnapshot == null)
|
||||||
|
_haltSnapshot = SnapshotLocked();
|
||||||
if (_scripts.Count > 0) _scripts.Pop();
|
if (_scripts.Count > 0) _scripts.Pop();
|
||||||
callStack = CurrentCallStackLocked();
|
callStack = CurrentCallStackLocked();
|
||||||
}
|
}
|
||||||
@@ -84,17 +87,13 @@ public sealed class GodotTraceSink : ITraceSink
|
|||||||
|
|
||||||
public GodotTraceSnapshot Snapshot()
|
public GodotTraceSnapshot Snapshot()
|
||||||
{
|
{
|
||||||
lock (_snapshotLock)
|
lock (_snapshotLock) return SnapshotLocked();
|
||||||
{
|
}
|
||||||
GodotTraceStepSnapshot? current = _latestStep;
|
|
||||||
return new GodotTraceSnapshot(
|
/// <summary>The deepest still-active script stack captured before a halted frame unwinds.</summary>
|
||||||
current?.Script ?? (_scripts.Count > 0 ? _scripts.Peek() : "<unknown>"),
|
public GodotTraceSnapshot? HaltSnapshot
|
||||||
current?.Offset ?? -1,
|
{
|
||||||
current?.Opcode ?? -1,
|
get { lock (_snapshotLock) return _haltSnapshot; }
|
||||||
current?.Depth ?? System.Math.Max(0, _scripts.Count - 1),
|
|
||||||
CurrentCallStackLocked(),
|
|
||||||
_recentSteps.ToArray());
|
|
||||||
}
|
|
||||||
}
|
}
|
||||||
|
|
||||||
/// <summary>Allocation-free current coordinate for once-per-frame diagnostics.</summary>
|
/// <summary>Allocation-free current coordinate for once-per-frame diagnostics.</summary>
|
||||||
@@ -109,6 +108,18 @@ public sealed class GodotTraceSink : ITraceSink
|
|||||||
System.Array.Reverse(stack);
|
System.Array.Reverse(stack);
|
||||||
return 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);
|
public sealed record GodotTraceStepSnapshot(string Script, int Offset, int Opcode, int Depth);
|
||||||
|
|||||||
@@ -580,6 +580,12 @@ public partial class Main : Godot.Control
|
|||||||
GD.Print($"[vm] ended: {_vm!.HaltReason ?? "unknown"} after {_vm.Steps} steps");
|
GD.Print($"[vm] ended: {_vm!.HaltReason ?? "unknown"} after {_vm.Steps} steps");
|
||||||
ReportSubroutines();
|
ReportSubroutines();
|
||||||
ShowEnd();
|
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();
|
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 IsAdvanceAction(int action) => action is 4 or 5;
|
||||||
private static bool HasAdvanceAction(int mask) => (mask & ((1 << 4) | (1 << 5))) != 0;
|
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
|
try
|
||||||
{
|
{
|
||||||
long nowMs = _clock.NowMs;
|
long nowMs = _clock.NowMs;
|
||||||
GodotTraceSnapshot trace = _trace.Snapshot();
|
GodotTraceSnapshot trace = traceOverride ?? _trace.Snapshot();
|
||||||
var activeMovies = _movies
|
var activeMovies = _movies
|
||||||
.OrderBy(pair => pair.Key)
|
.OrderBy(pair => pair.Key)
|
||||||
.Select(pair =>
|
.Select(pair =>
|
||||||
@@ -815,7 +822,7 @@ public partial class Main : Godot.Control
|
|||||||
string directory = ProjectSettings.GlobalizePath("user://diagnostics");
|
string directory = ProjectSettings.GlobalizePath("user://diagnostics");
|
||||||
System.IO.Directory.CreateDirectory(directory);
|
System.IO.Directory.CreateDirectory(directory);
|
||||||
string path = System.IO.Path.Combine(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
|
var jsonOptions = new JsonSerializerOptions
|
||||||
{
|
{
|
||||||
WriteIndented = true,
|
WriteIndented = true,
|
||||||
@@ -825,10 +832,10 @@ public partial class Main : Godot.Control
|
|||||||
string coordinate = trace.CurrentOffset >= 0
|
string coordinate = trace.CurrentOffset >= 0
|
||||||
? $"{System.IO.Path.GetFileNameWithoutExtension(trace.CurrentScript).ToUpperInvariant()}@0x{trace.CurrentOffset:x}"
|
? $"{System.IO.Path.GetFileNameWithoutExtension(trace.CurrentScript).ToUpperInvariant()}@0x{trace.CurrentOffset:x}"
|
||||||
: trace.CurrentScript;
|
: trace.CurrentScript;
|
||||||
string clipboard = $"{coordinate} · stall snapshot {path}";
|
string clipboard = $"{coordinate} · {snapshotKind} snapshot {path}";
|
||||||
DisplayServer.ClipboardSet(clipboard);
|
DisplayServer.ClipboardSet(clipboard);
|
||||||
_status.Text = $"Diagnostic saved: {coordinate} (path copied)";
|
_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)
|
catch (System.Exception exception)
|
||||||
{
|
{
|
||||||
|
|||||||
46
godot/StepLimitDiagnosticFormatter.cs
Normal file
46
godot/StepLimitDiagnosticFormatter.cs
Normal 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();
|
||||||
|
}
|
||||||
|
}
|
||||||
Reference in New Issue
Block a user