Diagnostics/PerfProbe.cs

A static diagnostics helper for the gamemode that reads engine performance counters and prints human-friendly reports. It samples frame time, GPU time, memory, GC, and GPU profiler scopes, and exposes two console commands nz_perf and nz_perf_gpu to report and toggle detailed GPU profiling.

NetworkingFile Access
using Sandbox;
using Sandbox.Diagnostics;
using System;
using System.Collections.Generic;
using System.Linq;

namespace NZombies;

/// <summary>
/// WHERE THE FRAMES ARE GOING — frame cost, memory, and what the gamemode put in the world.
///
/// ⛔ IT MEASURES, IT DOES NOT GUESS. The prompt for this was concrete: canyon runs ~51 fps with no
/// config and ~31 with one, and the number moves with which way the camera points. That last part
/// is the whole clue — a cost that depends on VIEW DIRECTION is drawing, not logic — and it is also
/// why guessing at the cause was never going to work. Every number here comes from
/// Sandbox.Diagnostics, and the census counts real components rather than estimating.
///
/// ⚠️ THERE IS NO "CPU %" IN THE ENGINE API, and asking for one is the wrong question anyway.
/// `PerformanceStats.FrameTime` is the whole frame and `GpuFrametime` is the GPU's part of it, so
/// the actionable fact — am I CPU-bound or GPU-bound — is the comparison between them. A percentage
/// of a core would not tell you which.
/// </summary>
public static class PerfProbe
{
	/// <summary>
	/// One frame's cost, in the units a human wants.
	///
	/// ⚠️ THE ENGINE'S OWN TYPES, not convenient ones. FrameTime and GpuFrametime are `double` and
	/// every memory counter is `ulong`; narrowing them to float/long here would mean a cast at
	/// every read and a silent wrap on a machine with more than 8 exabytes of nothing to worry
	/// about — but the casts are the real cost, because one of them would eventually be wrong.
	/// </summary>
	public readonly record struct Sample(
		double Fps, double FrameMs, double GpuMs, ulong RamBytes, ulong VramBytes,
		float VramFraction, long AllocBytes, int Gen0, int Gen1, int Gen2, float GcPauseMs );

	/// <summary>Read the engine's counters right now.</summary>
	public static Sample Read()
	{
		// ⚠️ FrameTime IS SECONDS, GpuFrametime IS MILLISECONDS. The engine documents them in
		// different units on adjacent properties, which is exactly the kind of thing that produces
		// a report claiming a 16-second frame.
		var frameSec = PerformanceStats.FrameTime;
		var frameMs = frameSec * 1000.0;
		var fps = frameSec > 0.00001 ? 1.0 / frameSec : 0.0;

		return new Sample(
			Fps: fps,
			FrameMs: frameMs,
			GpuMs: PerformanceStats.GpuFrametime,
			RamBytes: PerformanceStats.ApproximateProcessMemoryUsage,
			VramBytes: GpuProfilerStats.VideoMemoryUsed,
			VramFraction: GpuProfilerStats.VideoMemoryUsageFraction,
			AllocBytes: PerformanceStats.BytesAllocated,
			Gen0: PerformanceStats.Gen0Collections,
			Gen1: PerformanceStats.Gen1Collections,
			Gen2: PerformanceStats.Gen2Collections,
			GcPauseMs: PerformanceStats.GcPause );
	}

	// ⚠️ TAKES double SO IT ACCEPTS BOTH. The engine mixes them on adjacent properties —
	// BytesAllocated is `long` while every VideoMemory* and ApproximateProcessMemoryUsage is
	// `ulong` — and two overloads would just be two places to change the format.
	static string Mb( double bytes ) => $"{bytes / 1048576.0:0.#} MB";

	/// <summary>
	/// `nz_perf` — frame cost, memory, and which side is the bottleneck.
	/// </summary>
	[ConCmd( "nz_perf" )]
	public static void Report()
	{
		var s = Read();

		Log.Info( $"[nz-perf] {s.Fps:0.#} fps   frame {s.FrameMs:0.##} ms   gpu {s.GpuMs:0.##} ms" );

		// ⛔ THE VERDICT IS THE POINT OF THE LINE. "31 fps" is a symptom; "GPU-bound" is the only
		// thing that says whether to cut draw calls or cut per-frame logic, and getting that
		// backwards wastes a whole optimisation pass.
		//
		// ⚠️ A MARGIN, NOT AN EXACT COMPARE. GPU time is sampled a frame or two behind, so the two
		// numbers are never equal even on a perfectly balanced frame.
		var verdict = s.GpuMs <= 0.01
			? "gpu timing unavailable — nz_perf_gpu 1 turns the GPU profiler on"
			: s.GpuMs > s.FrameMs * 0.85
				? "GPU-BOUND — cut draw calls, lights, overdraw"
				: s.GpuMs < s.FrameMs * 0.5
					? "CPU-BOUND — cut per-frame logic, physics, allocations"
					: "balanced — neither side is clearly the wall";
		Log.Info( $"[nz-perf] {verdict}" );

		Log.Info( $"[nz-perf] ram {Mb( s.RamBytes )}   vram {Mb( s.VramBytes )}"
			+ $" ({s.VramFraction * 100f:0.#}% of budget)" );

		// ⚠️ ALLOCATION IS REPORTED EVEN WHEN GPU-BOUND. A gamemode allocating every frame shows up
		// as GC pauses that read as stutter rather than as a low average — and an average fps hides
		// exactly that.
		Log.Info( $"[nz-perf] alloc {Mb( s.AllocBytes )}   gc {s.Gen0}/{s.Gen1}/{s.Gen2}"
			+ $" (gen0/1/2)   last pause {s.GcPauseMs:0.##} ms" );
	}

	/// <summary>
	/// `nz_perf_gpu [0|1]` — the GPU's own per-pass breakdown, or toggle the profiler.
	///
	/// ⚠️ THE PROFILER IS OFF BY DEFAULT and costs something to run, which is why this both toggles
	/// and reports. Entries are '/'-separated scope paths; the durations only exist while it is on.
	/// </summary>
	[ConCmd( "nz_perf_gpu" )]
	public static void Gpu( int on = -1 )
	{
		if ( on >= 0 ) GpuProfilerStats.Enabled = on != 0;

		Log.Info( $"[nz-perf] gpu profiler {(GpuProfilerStats.Enabled ? "on" : "off")}"
			+ $"   vram {Mb( GpuProfilerStats.VideoMemoryUsed )}"
			+ $" / {Mb( GpuProfilerStats.VideoMemoryBudget )}"
			+ $"   free {Mb( GpuProfilerStats.VideoMemoryFree )}" );

		if ( !GpuProfilerStats.Enabled )
		{
			Log.Info( "[nz-perf] nz_perf_gpu 1 to turn it on, then run this again" );
			return;
		}

		var entries = GpuProfilerStats.Entries?.ToList() ?? new List<string>();
		if ( entries.Count == 0 )
		{
			Log.Info( "[nz-perf] no scopes yet — give it a frame and run it again" );
			return;
		}

		// ⚠️ SORTED BY COST, TRUNCATED, AND IT SAYS SO. There are dozens of scopes and the answer
		// is always in the top few; a silent top-N would read as "that is all there is".
		var timed = entries
			.Select( e => (path: e, ms: GpuProfilerStats.GetSmoothedDuration( e )) )
			.OrderByDescending( x => x.ms )
			.ToList();

		Log.Info( $"[nz-perf] {timed.Count} gpu scope(s), dearest first:" );
		foreach ( var (path, ms) in timed.Take( 15 ) )
			Log.Info( $"[nz-perf]   {ms,8:0.###} ms  {path}" );

		if ( timed.Count > 15 )
			Log.Info( $"[nz-perf]   ... and {timed.Count - 15} more, all cheaper" );
	}
}