Profiler: automated /s3bench harness and hitch probe capture

Four-pass stationary/motion A/B plus per-frame hitch attribution
(GC, camera, streaming, car/scenery probes). Writes frames.csv,
hitches.jsonl, probes.csv, and an optional Unity binary log.
This commit is contained in:
Seton Carmichael 2026-09-11 15:19:22 -04:00
parent e8aeb2d6a3
commit 290211e9e8
8 changed files with 1520 additions and 3 deletions

View file

@ -20,7 +20,7 @@ I originally planned on releasing individual mods, but considering my workflow o
| Physics Optimizer | Cuts CPU spent on train physics (LOD fast-path + auto-freeze), with debug car tinting. Console: `/rpf` |
| Mesh LOD | Adds level-of-detail to rolling stock: distant cars progressively shed detail and finally collapse to a cheap proxy box, cutting triangle count on large saves. |
| Base Game Performance | Smooths Unity's incremental garbage collector and Nature Renderer grass streaming to reduce camera-motion hitches without lowering visual quality. |
| Profiler | Unified in-game performance overlay: a frame-time graph plus live readouts that adapt to whichever optimization modules are enabled. Console: `/rpf overlay` |
| Profiler | Unified in-game performance overlay with hitch attribution captures. Console: `/rpf overlay`, `/s3bench` |
All modules are disabled by default; enable them per-module from the S³ settings page. A game restart is required for enable/disable to take effect. More modules will follow; S³ is designed to grow.
@ -176,12 +176,16 @@ the same. The original runtime values are restored immediately when the module i
## Profiler
A unified in-game performance overlay. It always shows a render + physics frame-time graph (render, FixedUpdate, Tick, and PosCars times) and a timing report, and it grows extra sections for whichever optimization modules are enabled:
A unified in-game performance overlay. It shows a render + physics frame-time graph and now
supports automated hitch-attribution captures with per-frame GC, camera, render-pipeline,
car/scenery/culling, and streaming timings. Benchmark output includes `frames.csv`,
`hitches.jsonl`, `probes.csv`, and an optional Unity binary-profiler log.
- **Physics Optimizer**: LOD fast-path and auto-freeze quick-toggles with live fast/full and frozen counts.
- **Mesh LOD**: total tracked cars, the locomotive/freight split, and how many cars sit at each LOD level right now.
Toggle the overlay with `/rpf overlay`, or from the Profiler settings page.
Toggle the overlay with `/rpf overlay`, or from the Profiler settings page. Run
`/s3bench start` for a four-pass stationary/motion A/B capture.
![Profiler settings](img/profiler/umm_settings.png)

File diff suppressed because it is too large Load diff

View file

@ -0,0 +1,63 @@
using System.Diagnostics;
using UnityEngine;
using UnityEngine.Rendering;
namespace S3.Modules.Profiler;
[DefaultExecutionOrder(-32000)]
public sealed class HitchFrameDriver : MonoBehaviour
{
internal static long FrameStartTicks;
internal static long LateTicks;
long _renderStartTicks;
void OnEnable()
{
RenderPipelineManager.beginFrameRendering += BeginFrameRendering;
RenderPipelineManager.endFrameRendering += EndFrameRendering;
}
void OnDisable()
{
RenderPipelineManager.beginFrameRendering -= BeginFrameRendering;
RenderPipelineManager.endFrameRendering -= EndFrameRendering;
}
void Update()
{
HitchSampler.AdvanceFrame(Time.unscaledDeltaTime * 1000f);
FrameStartTicks = Stopwatch.GetTimestamp();
LateTicks = 0;
}
void BeginFrameRendering(ScriptableRenderContext _, Camera[] __)
{
if (!HitchSampler.Active) return;
long now = Stopwatch.GetTimestamp();
long boundary = LateTicks != 0 ? LateTicks : FrameStartTicks;
if (boundary != 0)
HitchSampler.Record("phase.pre_render_gap", now - boundary);
_renderStartTicks = now;
}
void EndFrameRendering(ScriptableRenderContext _, Camera[] __)
{
if (!HitchSampler.Active || _renderStartTicks == 0) return;
HitchSampler.Record(
"phase.render_pipeline",
Stopwatch.GetTimestamp() - _renderStartTicks);
_renderStartTicks = 0;
}
}
[DefaultExecutionOrder(32000)]
public sealed class HitchLateFrameDriver : MonoBehaviour
{
void LateUpdate()
{
if (!HitchSampler.Active || HitchFrameDriver.FrameStartTicks == 0) return;
long now = Stopwatch.GetTimestamp();
HitchSampler.Record("phase.scripts_to_late", now - HitchFrameDriver.FrameStartTicks);
HitchFrameDriver.LateTicks = now;
}
}

View file

@ -0,0 +1,140 @@
using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Reflection;
using HarmonyLib;
using S3.Core;
namespace S3.Modules.Profiler;
/// <summary>
/// Resolves vanilla targets at runtime so game-version method drift degrades telemetry rather
/// than preventing the Profiler module from loading.
/// </summary>
public static class HitchProbePatches
{
readonly struct Target
{
public readonly string Type;
public readonly string Method;
public readonly string Id;
public Target(string type, string method, string id)
{
Type = type;
Method = method;
Id = id;
}
}
static readonly Target[] Targets =
{
new("RollingStock.CarCuller", "Update", "cars.culler_update"),
new("RollingStock.CarCuller", "ProcessPending", "cars.process_pending"),
new("RollingStock.CarCuller", "OnCarCullingGroupStateChanged", "cars.cull_transition"),
new("Model.Car", "ModelLoadRetain", "cars.model_retain"),
new("Model.Car", "HandleModelsLoaded", "cars.model_loaded"),
new("Model.Car", "UnloadModels", "cars.model_unload"),
new("Model.Car", "SetCullerDistanceBand", "cars.distance_band"),
new("Model.Car", "PositionWheelBoundsFront", "cars.position_wheels"),
new("Helpers.SceneryAssetInstance", "SetLoaded", "scenery.set_loaded"),
new("Helpers.SceneryAssetInstance", "DidLoadModel", "scenery.did_load_model"),
new("Helpers.SceneryAssetInstance", "CullingSphereStateChanged", "scenery.cull_transition"),
new("Helpers.Culling.CullingManager", "Update", "culling.update"),
new("Helpers.Culling.CullingManager", "FixedUpdate", "culling.fixed_update"),
new("Cameras.StrategyCameraController", "Update", "camera.strategy_update"),
new("Cameras.StrategyCameraController", "UpdateCameraPosition", "camera.update_position"),
new("Cameras.StrategyCameraController", "FindGround", "camera.find_ground"),
new("TrainController", "FixedUpdate", "train.fixed_update"),
new("TrainController", "CarDidPosition", "train.car_did_position"),
new("WorldStreamer2.Streamer", "Update", "streamer.update"),
new("WorldStreamer2.Streamer", "CheckPositionTiles", "streamer.check_tiles"),
new("WorldStreamer2.Streamer", "LoadLevelAsyncManage", "streamer.load_pump"),
new("WorldStreamer2.Streamer", "SceneLoading", "streamer.scene_loading"),
new("WorldStreamer2.Streamer", "SceneUnloading", "streamer.scene_unloading"),
new("WorldStreamer2.StreamerLoadingManager", "Update", "streamer.manager_update"),
new("WorldStreamer2.TerrainCullingSystem", "Update", "terrain.culling_update"),
new("WorldStreamer2.TerrainCullingSystem", "CheckVisibility", "terrain.check_visibility"),
new("WorldStreamer2.PhysicCullingSystem", "Update", "physics_culling.update"),
new("WorldStreamer2.PhysicCullingSystem", "CheckVisibility", "physics_culling.check_visibility"),
};
static readonly Dictionary<MethodBase, string> ProbeIds = new();
public static void Install(Harmony harmony)
{
ProbeIds.Clear();
var prefix = new HarmonyMethod(typeof(HitchProbePatches), nameof(Prefix));
var postfix = new HarmonyMethod(typeof(HitchProbePatches), nameof(Postfix));
int patched = 0;
int missed = 0;
foreach (Target target in Targets)
{
Type? type = FindType(target.Type);
if (type == null)
{
Log.Warn($"[profiler] Hitch probe type missing: {target.Type}");
missed++;
continue;
}
bool found = false;
foreach (MethodInfo method in AccessTools.GetDeclaredMethods(type))
{
if (method.Name != target.Method || method.IsAbstract || method.ContainsGenericParameters)
continue;
found = true;
if (ProbeIds.ContainsKey(method)) continue;
try
{
ProbeIds[method] = target.Id;
harmony.Patch(method, prefix, postfix);
patched++;
}
catch (Exception e)
{
ProbeIds.Remove(method);
Log.Warn($"[profiler] Hitch probe failed: {type.FullName}.{method.Name}: {e.Message}");
missed++;
}
}
if (!found)
{
Log.Warn($"[profiler] Hitch probe method missing: {target.Type}.{target.Method}");
missed++;
}
}
Log.Info($"[profiler] Hitch probes installed: {patched}; unavailable: {missed}.");
}
public static void Prefix(MethodBase __originalMethod, out long __state)
{
__state = HitchSampler.Active && ProbeIds.ContainsKey(__originalMethod)
? Stopwatch.GetTimestamp()
: 0;
}
public static void Postfix(MethodBase __originalMethod, long __state)
{
if (__state == 0 || !HitchSampler.Active) return;
if (ProbeIds.TryGetValue(__originalMethod, out string? id))
HitchSampler.Record(id, Stopwatch.GetTimestamp() - __state);
}
static Type? FindType(string fullName)
{
foreach (Assembly assembly in AppDomain.CurrentDomain.GetAssemblies())
{
try
{
Type? type = assembly.GetType(fullName, false);
if (type != null) return type;
}
catch { }
}
return null;
}
}

View file

@ -0,0 +1,163 @@
using System;
using System.Collections.Generic;
using System.Diagnostics;
using UnityEngine;
namespace S3.Modules.Profiler;
public sealed class HitchProbeSample
{
public int Calls;
public long Ticks;
public long MaxTicks;
public double TotalMs => HitchSampler.TicksToMs(Ticks);
public double MaxMs => HitchSampler.TicksToMs(MaxTicks);
}
public sealed class HitchFrameRecord
{
public string Phase = "";
public int Frame;
public float FrameMs;
public int Gc0;
public int Gc1;
public int Gc2;
public long MonoDelta;
public Vector3 CameraPosition;
public readonly Dictionary<string, HitchProbeSample> Probes =
new(StringComparer.Ordinal);
public bool IsHitch(float thresholdMs) => FrameMs >= thresholdMs;
}
/// <summary>
/// Low-overhead, main-thread frame aggregator for direct Harmony and render-pipeline timings.
/// Accumulators are committed at the beginning of the following Unity frame so LateUpdate and
/// render callbacks are included in the frame whose unscaled delta is being reported.
/// </summary>
public static class HitchSampler
{
static readonly Dictionary<string, HitchProbeSample> Current =
new(StringComparer.Ordinal);
static readonly List<HitchFrameRecord> Frames = new(1024);
static string _phase = "";
static int _frame;
static int _gc0;
static int _gc1;
static int _gc2;
static long _mono;
static bool _hasPendingFrame;
public static bool Active { get; private set; }
public static float HitchThresholdMs { get; private set; } = 100f;
public static void BeginCapture(string phase, float hitchThresholdMs)
{
Current.Clear();
Frames.Clear();
_phase = phase;
_frame = 0;
HitchThresholdMs = Mathf.Clamp(hitchThresholdMs, 16.7f, 1000f);
SnapshotGc();
_hasPendingFrame = false;
Active = true;
}
public static List<HitchFrameRecord> EndCapture()
{
Active = false;
_hasPendingFrame = false;
Current.Clear();
return new List<HitchFrameRecord>(Frames);
}
public static void CancelCapture()
{
Active = false;
_hasPendingFrame = false;
Current.Clear();
Frames.Clear();
}
public static void Record(string id, long ticks, int calls = 1)
{
if (!Active || ticks < 0) return;
if (!Current.TryGetValue(id, out HitchProbeSample? sample))
{
sample = new HitchProbeSample();
Current[id] = sample;
}
sample.Calls += calls;
sample.Ticks += ticks;
if (ticks > sample.MaxTicks) sample.MaxTicks = ticks;
}
public static void Count(string id, int calls = 1)
{
if (!Active || calls <= 0) return;
if (!Current.TryGetValue(id, out HitchProbeSample? sample))
{
sample = new HitchProbeSample();
Current[id] = sample;
}
sample.Calls += calls;
}
/// <summary>Called at the first Update of each frame by <see cref="HitchFrameDriver"/>.</summary>
public static void AdvanceFrame(float frameMs)
{
if (!Active) return;
int gc0 = GC.CollectionCount(0);
int gc1 = GC.CollectionCount(1);
int gc2 = GC.CollectionCount(2);
long mono = UnityEngine.Profiling.Profiler.GetMonoUsedSizeLong();
if (_hasPendingFrame && frameMs > 0f && frameMs < 2000f)
{
var record = new HitchFrameRecord
{
Phase = _phase,
Frame = _frame++,
FrameMs = frameMs,
Gc0 = gc0 - _gc0,
Gc1 = gc1 - _gc1,
Gc2 = gc2 - _gc2,
MonoDelta = mono - _mono,
CameraPosition = Camera.main != null
? Camera.main.transform.position
: Vector3.zero,
};
foreach (var pair in Current)
{
record.Probes[pair.Key] = new HitchProbeSample
{
Calls = pair.Value.Calls,
Ticks = pair.Value.Ticks,
MaxTicks = pair.Value.MaxTicks,
};
}
Frames.Add(record);
}
Current.Clear();
_gc0 = gc0;
_gc1 = gc1;
_gc2 = gc2;
_mono = mono;
_hasPendingFrame = true;
}
static void SnapshotGc()
{
_gc0 = GC.CollectionCount(0);
_gc1 = GC.CollectionCount(1);
_gc2 = GC.CollectionCount(2);
_mono = UnityEngine.Profiling.Profiler.GetMonoUsedSizeLong();
}
internal static double TicksToMs(long ticks) =>
ticks * 1000.0 / Stopwatch.Frequency;
}

View file

@ -1,3 +1,4 @@
using HarmonyLib;
using S3.Core;
using UnityEngine;
@ -10,6 +11,7 @@ public sealed class ProfilerModule : IModule
public static ProfilerSettings Settings { get; private set; } = new();
private static GameObject? _hostGo;
private static Harmony? _harmony;
public ProfilerModule() => Settings = SettingsStore.Load<ProfilerSettings>(SettingsFile);
@ -28,15 +30,24 @@ public sealed class ProfilerModule : IModule
public void OnEnable()
{
_harmony = new Harmony("S3.profiler");
_harmony.CreateClassProcessor(typeof(BenchmarkCommandPatch)).Patch();
HitchProbePatches.Install(_harmony);
_hostGo = new GameObject("[S3] ProfilerHost");
UnityEngine.Object.DontDestroyOnLoad(_hostGo);
var overlay = _hostGo.AddComponent<ProfilerOverlayGUI>();
overlay.Visible = Settings.visible;
overlay.Opacity = Settings.opacity;
_hostGo.AddComponent<AutomatedBenchmark>();
_hostGo.AddComponent<HitchFrameDriver>();
_hostGo.AddComponent<HitchLateFrameDriver>();
}
public void OnDisable()
{
HitchSampler.CancelCapture();
_harmony?.UnpatchAll(_harmony.Id);
_harmony = null;
if (_hostGo != null) UnityEngine.Object.Destroy(_hostGo);
_hostGo = null;
}

View file

@ -10,4 +10,7 @@ public class ProfilerSettings
public float opacity = 0.85f;
public bool showPhysicsSection = true;
public bool showMeshLodSection = true;
public bool captureHitchProbes = true;
public float hitchThresholdMs = 100f;
public bool captureUnityBinaryLog = false;
}

View file

@ -69,6 +69,39 @@ static class ProfilerSettingsUI
if (newMesh != s.showMeshLodSection && meshAvail)
{ s.showMeshLodSection = newMesh; changed = true; }
GUILayout.Space(10f);
GUILayout.Label("<b>Benchmark hitch capture</b>");
GUILayout.Space(4f);
bool newCapture = GUILayout.Toggle(
s.captureHitchProbes,
" Attribute base-game work on every benchmark frame");
if (newCapture != s.captureHitchProbes)
{
s.captureHitchProbes = newCapture;
changed = true;
}
GUILayout.BeginHorizontal();
GUILayout.Label($"Hitch threshold: {s.hitchThresholdMs:F0}ms", GUILayout.Width(160f));
float newThreshold = GUILayout.HorizontalSlider(
s.hitchThresholdMs, 33f, 250f, GUILayout.Width(200f));
GUILayout.EndHorizontal();
if (Mathf.Abs(newThreshold - s.hitchThresholdMs) > 0.5f)
{
s.hitchThresholdMs = newThreshold;
changed = true;
}
bool newBinary = GUILayout.Toggle(
s.captureUnityBinaryLog,
" Write Unity binary profiler data (high overhead)");
if (newBinary != s.captureUnityBinaryLog)
{
s.captureUnityBinaryLog = newBinary;
changed = true;
}
GUILayout.EndVertical();
if (changed) ProfilerModule.Persist();