Engine Tooling: Dev UI & Profiling

01Seeing the engine

An NPC walks into a wall, but only after the level has been running for ten minutes. Rebuilding with print statements and replaying ten minutes per guess is slow. Tooling replaces guessing about the running game with looking at it. Game Engine Architecture gives these tools a chapter of their own: logging and tracing, debug drawing, in-game menus, an in-game console and in-game profiling^[1]. Before any GUI, the cheapest tools give the most value for the effort:

• Logging / tracing: timestamped, categorized, filterable; the first thing you reach for.
• Asserts: an invariant written as executable code; a failed assert stops the program where the broken assumption is first checked, usually much closer to the bug than the crash it would have caused.
• Debug draw: "printf for geometry". Draw the navmesh, the AI paths, the collision shapes and the light bounds right in the world. For the NPC above, drawing its planned path shows at a glance whether the path goes through the wall or the steering ignores it.

The rest of this module is the next tier: an in-engine UI to tweak live state, profilers (tools that measure where the time goes) to measure, and frame capture to dissect the GPU.

02Immediate vs retained

You add a "wireframe" checkbox to a tools panel. Click it, and the box shows a tick, but the renderer still draws solid triangles, because the code that should copy the box's value into the renderer's flag never ran. That bug comes from one of the two ways to build a UI. Retained-mode keeps a persistent tree of widget objects you mutate through callbacks, and you must keep that tree in sync with your application's own state. Immediate-mode (IMGUI, a term coined by Casey Muratori; Dear ImGui, by Omar Cornut, is a widely used C++ library for it) re-issues the whole UI every frame straight from your live data, with no widget objects for the application to keep: the if (Button()) doThing() model^[2].

Toggle the modes and click. Retained keeps two stores you must sync (forget to, and they drift); immediate rebuilds the UI from one store, so there's no second copy to go stale:

03Dear ImGui & panels

You want a slider for the sun angle and a button that reloads shaders, without writing a UI framework first. Dear ImGui "outputs optimized vertex buffers that you can render anytime in your 3D-pipeline-enabled application"^[4]. It produces draw data, and you render it with your own backend. The architecture is three layers: a platform backend (window/input: GLFW, SDL), the core (API-agnostic), and a renderer backend (Vulkan, D3D, Metal). ImGui's draw data is just another set of draw calls in your command buffer.

Debug panels are sliders bound to live variables, an in-game console, and entity inspectors (iterate an entity's components, draw a widget per field):

ImGui_ImplVulkan_NewFrame();                   // renderer backend first,
ImGui_ImplGlfw_NewFrame();                     // then platform backend (feeds input, display size)
ImGui::NewFrame();                              // begin the UI frame
ImGui::Begin("Debug");                          // a panel
ImGui::SliderFloat("Sun angle", &sunAngle, 0.0f, 3.14159f);  // bound to the live variable
ImGui::Checkbox("Wireframe", &showWireframe);   // edits write through now
if (ImGui::Button("Reload shaders"))             // the if(Button()) action model
    reloadShaders();                          // fires this frame, no callback to register
ImGui::Text("Frame: %.2f ms", frameTimeMs);    // a watch value
ImGui::End();

ImGui::Render();                               // build the vertex/index buffers (ImDrawData)
ImGui_ImplVulkan_RenderDrawData(ImGui::GetDrawData(), cmd);  // you draw it, in your render pass

// egui: the idiomatic Rust immediate-mode GUI (imgui-rs is the Dear ImGui binding)
egui::Window::new("Debug").show(ctx, |ui| {        // a panel
    ui.add(egui::Slider::new(&mut sun_angle, 0.0..=PI).text("Sun angle"));  // bound live
    ui.checkbox(&mut show_wireframe, "Wireframe");
    if ui.button("Reload shaders").clicked() {       // same if(Button()) model
        reload_shaders();
    }
    ui.label(format!("Frame: {:.2} ms", frame_time_ms));
});  // egui outputs shapes; ctx.tessellate() turns them into meshes your backend draws

04Frame time, not FPS

QA files a bug: "the game runs at 60 fps but feels choppy." Both halves can be true. An FPS number is an average over many frames, and an average can't show one slow frame among forty fast ones. Players see individual frames, so profiling starts by recording how long each one took in milliseconds, its frame time.

Milliseconds are also the unit that costs add up in. FPS is the reciprocal of frame time, so the same change in FPS means a different amount of work depending on where you start.

To describe thousands of frames in a few numbers without hiding the slow ones, sort them and read the slow end. The 99th-percentile frame time (P99) is the frame time that 99% of frames beat. A percentile counts frames, not time, and the developers of the CapFrameX benchmarking tool give an example: in a 20-second run, four 500 ms stalls are under 1% of the frames, so a P99 can look fine while the screen was frozen for 2 of the 20 seconds^[5]. The measure that counts time is the share of wall-clock time spent inside frames slower than a threshold. The same source points out that a "min FPS" averaged over one second can't show micro-stutter at all, and that the "1% low" figure quoted in benchmark videos has no agreed definition, so compare it only between runs of the same tool^[5].

Three runs with nearly the same average. Switch between them and compare the average with the slow-end numbers:

Take the frame time at one fixed point in the loop, such as the top of each frame, from a monotonic clock (the Game Loop page covers which clock). To measure a build without touching its code on Windows, Intel's PresentMon reads the operating system's presentation events and logs, for every frame, the time since the previous Present() call (MsBetweenPresents) and how long the CPU and GPU were busy on it^[6].

05CPU profiling

A frame that should take 12 ms sometimes takes 21, and you need to know which system ate the other 9. There are two ways to find where CPU time goes, and they're a real tradeoff^[7]:

• Sampling: interrupt the program periodically and record the call stack. Low overhead, statistical, but can miss short rare events and gives no exact call counts (perf, VTune).
• Instrumentation: explicit scope markers in code give exact per-scope timing, but you only see what you marked and the markers add overhead (Tracy, Optick).

A sampling profiler needs no changes to your code. The operating system interrupts the program at a fixed rate and records the call stack of the running thread. Linux perf record defaults to 4,000 samples a second^[8]; Tracy samples at 8 kHz on Windows and 10 kHz on Linux^[9]. To record a stack, the profiler has to find each function's caller. The cheap way follows the chain of saved frame pointers, but GCC omits them by default at -O1 and above^[10], and perf's documentation warns that its default frame-pointer unwinding then "will produce bogus call graphs". Build profiling binaries with -fno-omit-frame-pointer, or switch perf to DWARF unwinding with --call-graph dwarf^[11].

Sampling is a poll, so its answers carry error bars. If a function really takes a share of the time, the share of samples that land in it scatters around the true value by a predictable amount:

In words: the margin shrinks with the square root of the number of samples, so four times as many samples halve it. Small shares get small absolute margins but large relative ones.

Each catches what the other misses, and modern tools blend both (Tracy is "a hybrid frame and sampling profiler")^[12]. Tracy's manual describes the split: statistical sampling "may show you the hot spots in your code, but it cannot accurately pinpoint the underlying cause for semi-random frame stutter"^[9]. Instrumentation records a named scope's begin and end timestamps into a per-thread buffer, drawn as a flame chart (nested bars on a time axis: width = duration, stacking = call depth), one track per worker thread. The next section builds one.

A simulated frame's scopes as a flame chart. Trigger a spike and the physics scope dominates; compare sampling to exact instrumentation:

06A tiny profiler

You want every thread's scopes on one timeline today, without integrating a profiler library first. The pieces fit in under 150 lines: a scoped timer, a buffer per thread, and an exporter that writes the Chrome Trace Event Format, a JSON array of events that Chrome's trace viewer (chrome://tracing) reads^[13]. The Perfetto UI at ui.perfetto.dev opens the same file directly and draws a named track per thread^[14]. The Bevy engine works the same way: its built-in spans start a timer when entered and stop it when dropped, and its trace_chrome feature writes this JSON for Perfetto^[15].

• Recording takes no lock. Each thread appends zones to its own thread_local buffer. The lock is taken once per thread, when the thread finishes and hands its buffer to the profiler.
• A zone is 24 bytes. A pointer to a string literal, a start time and a duration (32 bytes in Rust, where a &str also carries its length). After the up-front reserve, recording a zone doesn't allocate.
• The scope does the timing. The constructor reads the clock and the destructor reads it again, so an early return or an exception still closes the zone. That's RAII; in Rust it's Drop.
• The export is two event types. One "X" (complete) event per zone with a start ts and a dur, both in microseconds, and one "M" (metadata) event per thread that names its track^[13].

// tiny_profiler.cpp: scoped zones on every thread, written as a Chrome trace.
// Build: g++ -std=c++20 -O2 -pthread tiny_profiler.cpp   Open trace.json at ui.perfetto.dev
#include <chrono>
#include <cmath>
#include <cstdint>
#include <cstdio>
#include <mutex>
#include <string>
#include <thread>
#include <utility>
#include <vector>

using ProfileClock = std::chrono::steady_clock;          // monotonic: never jumps backwards

struct ZoneEvent {                                       // one finished zone, 24 bytes
    const char* name;                                    // a string literal, so nothing is copied
    std::int64_t startNs;                                // nanoseconds since the profiler started
    std::int64_t durationNs;
};

struct ThreadBuffer {
    std::string threadName;
    std::vector<ZoneEvent> events;
};

// Each thread records into its own buffer, so recording a zone takes no lock.
thread_local ThreadBuffer currentThreadBuffer;

class Profiler {
public:
    static Profiler& instance() {
        static Profiler profiler;                        // thread-safe initialization since C++11
        return profiler;
    }

    std::int64_t nowNs() const {
        return std::chrono::duration_cast<std::chrono::nanoseconds>(ProfileClock::now() - epoch).count();
    }

    // Called once per thread when it finishes: the only place that takes the lock.
    void flushThisThread() {
        std::lock_guard<std::mutex> lock(finishedMutex);
        finishedThreads.push_back(std::move(currentThreadBuffer));
        currentThreadBuffer = ThreadBuffer{};
    }

    // Chrome Trace Event Format: a JSON array that Perfetto and chrome://tracing open.
    bool writeChromeTrace(const char* path) {
        std::FILE* file = std::fopen(path, "w");
        if (file == nullptr) return false;
        std::lock_guard<std::mutex> lock(finishedMutex);
        std::fputs("[\n", file);
        for (std::size_t threadIndex = 0; threadIndex < finishedThreads.size(); ++threadIndex) {
            const ThreadBuffer& buffer = finishedThreads[threadIndex];
            // "M" metadata event: names this thread's track in the viewer.
            std::fprintf(file, "%s{\"name\":\"thread_name\",\"ph\":\"M\",\"pid\":1,\"tid\":%zu,\"args\":{\"name\":\"%s\"}}",
                         threadIndex == 0 ? "" : ",\n", threadIndex, buffer.threadName.c_str());
            for (const ZoneEvent& zone : buffer.events) {
                // "X" complete event: ts and dur are microseconds, so three decimals keep whole nanoseconds.
                std::fprintf(file, ",\n{\"name\":\"%s\",\"ph\":\"X\",\"pid\":1,\"tid\":%zu,\"ts\":%.3f,\"dur\":%.3f}",
                             zone.name, threadIndex, static_cast<double>(zone.startNs) / 1000.0,
                             static_cast<double>(zone.durationNs) / 1000.0);
            }
        }
        std::fputs("\n]\n", file);
        return std::fclose(file) == 0;
    }

private:
    ProfileClock::time_point epoch = ProfileClock::now();
    std::mutex finishedMutex;
    std::vector<ThreadBuffer> finishedThreads;
};

void nameThisThread(const char* threadName) {
    currentThreadBuffer.threadName = threadName;
    currentThreadBuffer.events.reserve(1 << 16);         // grow once up front, not in the middle of a frame
}

class ScopedZone {                                       // RAII: the destructor closes the zone
public:
    explicit ScopedZone(const char* zoneName) : name(zoneName), startNs(Profiler::instance().nowNs()) {}
    ~ScopedZone() {
        const std::int64_t endNs = Profiler::instance().nowNs();
        currentThreadBuffer.events.push_back({name, startNs, endNs - startNs});
    }
    ScopedZone(const ScopedZone&) = delete;
    ScopedZone& operator=(const ScopedZone&) = delete;

private:
    const char* name;
    std::int64_t startNs;
};

// Paste in two steps so __LINE__ expands first (zone_118, say), not the literal zone___LINE__,
// which would collide when two zones share a scope.
#define ZONE_CONCAT_INNER(a, b) a##b
#define ZONE_CONCAT(a, b) ZONE_CONCAT_INNER(a, b)
#define ZONE_SCOPED(zoneName) ScopedZone ZONE_CONCAT(zone_, __LINE__)(zoneName)

// A volatile store keeps the work from being optimized away; thread_local so the threads don't race on it.
thread_local volatile double workSink = 0.0;

void busyWork(int iterations) {
    double total = 0.0;
    for (int i = 0; i < iterations; ++i) total += std::sqrt(static_cast<double>(i));
    workSink = total;
}

void updatePhysics() {
    ZONE_SCOPED("updatePhysics");
    { ZONE_SCOPED("broadPhase"); busyWork(200000); }
    { ZONE_SCOPED("solveContacts"); busyWork(600000); }
}

int main() {
    nameThisThread("main");
    std::thread streamingThread([] {
        nameThisThread("streaming");
        for (int request = 0; request < 3; ++request) {
            ZONE_SCOPED("decompressChunk");
            busyWork(900000);
        }
        Profiler::instance().flushThisThread();
    });
    for (int frame = 0; frame < 3; ++frame) {
        ZONE_SCOPED("frame");
        updatePhysics();
        { ZONE_SCOPED("render"); busyWork(500000); }
    }
    streamingThread.join();
    Profiler::instance().flushThisThread();              // main's zones have all closed by now
    if (!Profiler::instance().writeChromeTrace("trace.json")) {
        std::fputs("could not write trace.json\n", stderr);
        return 1;
    }
    std::puts("wrote trace.json");
    return 0;
}

// tiny_profiler.rs: scoped zones on every thread, written as a Chrome trace.
// Build: rustc -O --edition 2021 tiny_profiler.rs   Open trace.json at ui.perfetto.dev
use std::cell::RefCell;
use std::fs::File;
use std::io::{self, BufWriter, Write};
use std::sync::{Mutex, OnceLock};
use std::thread;
use std::time::Instant;                                   // monotonic: never jumps backwards

struct ZoneEvent {                                        // one finished zone, 32 bytes (a &str is a pointer plus a length)
    name: &'static str,                                   // a string literal, so nothing is copied
    start_ns: u64,                                        // nanoseconds since the profiler started
    duration_ns: u64,
}

#[derive(Default)]
struct ThreadBuffer {
    thread_name: String,
    events: Vec<ZoneEvent>,
}

thread_local! {
    // Each thread records into its own buffer, so recording a zone takes no lock.
    static CURRENT_THREAD_BUFFER: RefCell<ThreadBuffer> = RefCell::new(ThreadBuffer::default());
}

struct Profiler {
    epoch: Instant,
    finished_threads: Mutex<Vec<ThreadBuffer>>,
}

impl Profiler {
    fn instance() -> &'static Profiler {
        static PROFILER: OnceLock<Profiler> = OnceLock::new();   // initialized once, thread-safe
        PROFILER.get_or_init(|| Profiler { epoch: Instant::now(), finished_threads: Mutex::new(Vec::new()) })
    }

    fn now_ns(&self) -> u64 {
        self.epoch.elapsed().as_nanos() as u64
    }

    // Called once per thread when it finishes: the only place that takes the lock.
    fn flush_this_thread(&self) {
        let buffer = CURRENT_THREAD_BUFFER.with(|cell| std::mem::take(&mut *cell.borrow_mut()));
        self.finished_threads.lock().unwrap().push(buffer);
    }

    // Chrome Trace Event Format: a JSON array that Perfetto and chrome://tracing open.
    fn write_chrome_trace(&self, path: &str) -> io::Result<()> {
        let mut file = BufWriter::new(File::create(path)?);
        let finished_threads = self.finished_threads.lock().unwrap();
        writeln!(file, "[")?;
        for (thread_index, buffer) in finished_threads.iter().enumerate() {
            // "M" metadata event: names this thread's track in the viewer.
            write!(file, "{}{{\"name\":\"thread_name\",\"ph\":\"M\",\"pid\":1,\"tid\":{},\"args\":{{\"name\":\"{}\"}}}}",
                   if thread_index == 0 { "" } else { ",\n" }, thread_index, buffer.thread_name)?;
            for zone in &buffer.events {
                // "X" complete event: ts and dur are microseconds, so three decimals keep whole nanoseconds.
                write!(file, ",\n{{\"name\":\"{}\",\"ph\":\"X\",\"pid\":1,\"tid\":{},\"ts\":{:.3},\"dur\":{:.3}}}",
                       zone.name, thread_index, zone.start_ns as f64 / 1000.0, zone.duration_ns as f64 / 1000.0)?;
            }
        }
        writeln!(file, "\n]")?;
        file.flush()
    }
}

fn name_this_thread(thread_name: &str) {
    CURRENT_THREAD_BUFFER.with(|cell| {
        let mut buffer = cell.borrow_mut();
        buffer.thread_name = thread_name.to_string();
        buffer.events.reserve(1 << 16);                   // grow once up front, not in the middle of a frame
    });
}

struct ScopedZone {                                       // RAII: Drop closes the zone
    name: &'static str,
    start_ns: u64,
}

impl ScopedZone {
    fn new(zone_name: &'static str) -> ScopedZone {
        ScopedZone { name: zone_name, start_ns: Profiler::instance().now_ns() }
    }
}

impl Drop for ScopedZone {
    fn drop(&mut self) {
        let end_ns = Profiler::instance().now_ns();
        let zone = ZoneEvent { name: self.name, start_ns: self.start_ns, duration_ns: end_ns - self.start_ns };
        CURRENT_THREAD_BUFFER.with(|cell| cell.borrow_mut().events.push(zone));
    }
}

// A named binding (not `_`, which drops at once) keeps the zone open to the end of the scope.
macro_rules! zone_scoped {
    ($zone_name:expr) => {
        let _zone = ScopedZone::new($zone_name);
    };
}

fn busy_work(iterations: u32) {
    let mut total = 0.0f64;
    for i in 0..iterations {
        total += (i as f64).sqrt();
    }
    std::hint::black_box(total);                          // keeps the work from being optimized away
}

fn update_physics() {
    zone_scoped!("updatePhysics");
    {
        zone_scoped!("broadPhase");
        busy_work(200_000);
    }
    {
        zone_scoped!("solveContacts");
        busy_work(600_000);
    }
}

fn main() {
    name_this_thread("main");
    let streaming_thread = thread::spawn(|| {
        name_this_thread("streaming");
        for _request in 0..3 {
            zone_scoped!("decompressChunk");
            busy_work(900_000);
        }
        Profiler::instance().flush_this_thread();
    });
    for _frame in 0..3 {
        zone_scoped!("frame");
        update_physics();
        {
            zone_scoped!("render");
            busy_work(500_000);
        }
    }
    streaming_thread.join().unwrap();
    Profiler::instance().flush_this_thread();             // main's zones have all closed by now
    match Profiler::instance().write_chrome_trace("trace.json") {
        Ok(()) => println!("wrote trace.json"),
        Err(error) => {
            eprintln!("could not write trace.json: {error}");
            std::process::exit(1);
        }
    }
}

Run either program and it writes trace.json; drop the file on ui.perfetto.dev and you get a main track with three frame zones, each holding updatePhysics (with broadPhase and solveContacts inside) and render, and a streaming track with three decompressChunk zones running alongside.

Every zone costs time on the thread it measures, so the profiler changes what it measures. Tracy's manual measures its own cost on a texture-compression run spread over 12 threads: 37.7 ms of extra wall-clock time across 16.8 million zones, 2.25 ns per zone^[9]. The 12 threads shared that cost, so if they stayed busy throughout, each zone cost about 12 × 2.25 ≈ 27 ns on the thread that recorded it. A zone built from two steady_clock reads and a push_back, like the one above, costs more than Tracy's tuned path, so the same arithmetic applies with a bigger number.

07Reading a profile

The profile says update takes 6 ms, and a teammate starts rewriting it. That number doesn't say the code in update is slow. A function's total (inclusive) time counts everything it calls; its self time (exclusive) counts only its own instructions. Tracy's statistics view offers both, as "With children" and "Self only"^[9]. A function that only calls other functions can have a large total and almost no self time. Optimize where self time piles up.

The same profile data can be drawn two ways. A flame chart puts time on the x-axis, so it shows what ran in what order and lets you find the one slow frame. Brendan Gregg's flame graph merges identical call stacks: its x-axis is "sorted alphabetically (it is not the passage of time)", a box's width is how often that function was on the sampled stacks, and the top edge shows what was running^[16]. Merging is what makes it useful: a thousand short calls from the same caller become one wide box.

Merging only joins identical stacks, though. A function called from six places still shows up as six separate boxes, each one narrow. To see its whole cost, list functions by self time; most profilers have this "by function" (or bottom-up) view.

08From where to why

The profile says the contact solver takes 1.4 ms. It doesn't say why. The CPU can tell you: its performance counters count cycles, instructions retired, cache misses and branch mispredictions while the code runs. perf stat prints the counts with IPC (instructions per cycle) next to them^[17].

Raw counts are hard to weigh against each other, so Intel's top-down method sorts the core's pipeline slots, its capacity to issue work each cycle, into four bins. Retiring is useful work. Bad Speculation is work thrown away, mostly after mispredicted branches. Front-End Bound means the core couldn't fetch and decode instructions fast enough. Back-End Bound means decoded work was waiting on the back end, and it splits into Memory Bound (cache misses and memory accesses) and Core Bound (execution units used poorly, such as several divides in a row competing for the divide units)^[18]. On CPUs that support it, perf stat --topdown prints the four top-level numbers^[17].

09GPU profiling

You wrap the G-buffer pass in a CPU timer and it reports the same tiny number every frame, even when you double the scene. The classic trap: you can't time GPU work with a CPU clock. GPU work is asynchronous: recording and submitting a command buffer returns to the CPU immediately, and the GPU executes later (the GPU Pipeline async model). Wrapping vkCmdDraw in a CPU timer measures recording the command, not executing it.

unsafe {
    device.cmd_reset_query_pool(cmd, pool, base, 2);   // MUST reset before writing
    device.cmd_write_timestamp(cmd, vk::PipelineStageFlags::TOP_OF_PIPE,    pool, base);
    // ...begin rendering, draw the pass (e.g. the deferred G-buffer)...
    device.cmd_write_timestamp(cmd, vk::PipelineStageFlags::BOTTOM_OF_PIPE, pool, base + 1);
}
// A FEW FRAMES LATER (not this frame): read without stalling.
let mut ticks = [0u64; 2];
let read = unsafe { device.get_query_pool_results(pool, old_base, &mut ticks, vk::QueryResultFlags::TYPE_64) };
if read.is_ok() {                                     // Err(NOT_READY): GPU not there yet, try next frame
    let mask = if valid_bits == 64 { u64::MAX } else { (1u64 << valid_bits) - 1 };
    let elapsed_ticks = ticks[1].wrapping_sub(ticks[0]) & mask;   // survives a counter wrap
    let gpu_ms = elapsed_ticks as f64 * timestamp_period as f64 / 1.0e6;
}

vkCmdResetQueryPool(cmd, pool, base, 2);              // MUST reset before writing
vkCmdWriteTimestamp(cmd, VK_PIPELINE_STAGE_TOP_OF_PIPE_BIT,    pool, base);
// ...draw the pass...
vkCmdWriteTimestamp(cmd, VK_PIPELINE_STAGE_BOTTOM_OF_PIPE_BIT, pool, base + 1);

// A FEW FRAMES LATER: read without stalling.
uint64_t ticks[2];
VkResult read = vkGetQueryPoolResults(device, pool, oldBase, 2, sizeof(ticks), ticks,
                      sizeof(uint64_t), VK_QUERY_RESULT_64_BIT);  // 32-bit overflows in ~4.3 s at a 1 ns tick
if (read == VK_SUCCESS) {                             // VK_NOT_READY: GPU not there yet, try next frame
    uint64_t mask = validBits == 64 ? ~0ull : ((1ull << validBits) - 1);
    uint64_t elapsedTicks = (ticks[1] - ticks[0]) & mask;   // unsigned wrap + mask survives a counter wrap
    double gpuMs = elapsedTicks * double(timestampPeriod) / 1e6;
}

Reading a few frames late isn't a nicety. If the CPU reads this frame's timestamps with WAIT_BIT, it sits idle until the GPU finishes the frame, and then the GPU sits idle while the CPU records the next one. The two processors stop working in parallel, so the profiler slows down the frame it's measuring.

Per-pass GPU times also don't add up to the frame. A timestamp waits for earlier commands to finish the stage you name, but nothing recorded after it waits for the timestamp, and the implementation may write it at a later stage than the one you asked for^[19]. Without a barrier between two passes, the second can start while the first is finishing, so their measured intervals overlap; work on an async compute queue overlaps on purpose. Add up the passes and you count the overlap twice. Time the whole frame with its own pair of timestamps.

10CPU- vs GPU-bound

You spend a week speeding up game logic and the frame rate doesn't move, because the GPU was the slow side all along. The CPU and GPU work in parallel, with the CPU usually recording a frame or more ahead of the GPU, so the slower of the two sets the frame time. Bound-ness is about which timeline is the critical path. If the GPU's queue has visible gaps, idle waiting on CPU submission, you're CPU-bound; if the CPU blocks at present/fence waiting for the GPU, you're GPU-bound^[24]. A quick test: halve the render resolution. If the frame rate jumps, you were GPU-bound on fragment/fill work (fewer pixels to shade); if it barely moves, you're CPU-bound or bound on GPU geometry/draw submission, which fewer pixels don't change.

Drag the CPU and GPU work; see which is the critical path and who waits. Toggle vsync and both lanes idle to the next refresh:

For a build you can't instrument, PresentMon gives the same diagnosis from outside on Windows: alongside each frame's time it reports how long the CPU and the GPU were busy on that frame (MsCPUBusy and MsGPUBusy) and how long each waited^[6]. A GPU that stays busy for nearly the whole frame time points to GPU-bound; long GPU waits point to the CPU.

11Measure, then prove it

Two engineers argue about whether the particle system or the AI is slowing the game down. Measure, don't guess. Intuition about hotspots is often wrong: profile first, then optimize the actual bottleneck. Amdahl's law caps the payoff: speeding up a function that's 2% of the frame can't help much, so find the part that dominates. Knuth, in full (the truncated version is routinely misused)^[25]:

"We should forget about small efficiencies, say about 97% of the time: premature optimization is the root of all evil. Yet we should not pass up our opportunities in that critical 3%."

Once you've changed something, show that it helped. A 0.3 ms win can be smaller than the gap between two runs of the same build. Google Benchmark's documentation lists the usual sources of that noise: CPU frequency scaling and turbo boost, cores that run at different speeds, the scheduler moving threads around, a hyperthread sibling sharing the core, other programs, and cache effects from code on other cores. On Linux its suggested remedies are the performance frequency governor, turning boost off, and pinning the program to one core^[26]. On a game you usually can't remove all of it, so run the same scene several times per build and compare the spreads.

12Hot reload

You're tuning the fog in a shader: change a number, rebuild, relaunch, walk back to the spot, look, repeat. Hot reload, swapping the edited file into the running game, closes that loop: a file-watcher detects an edit, the asset is re-cooked and re-read, and the live handle is swapped (the Asset Pipeline owns the cook/swap machinery). For a renderer, shader hot-reload (recompile to SPIR-V, rebuild the pipeline object, swap it in) is often the highest-value reload: you tune a shader and see the result without restarting.

Wrong answers, and why: immediate vs retained is about where state lives (retained has the sync burden; immediate still caches internally); CPU timers can't measure async GPU work (use timestamp queries read back later, not a same-frame WAIT stall); an average FPS hides hitches that P99 catches; and total time includes callees, so look for self time.

13Pitfalls

14What's next

That's the last engine subsystem: you can render, animate, simulate, network, and now see and tune the whole thing. Next in the series is the finale that assembles it: the 3D-game capstone, a small but complete game that ties every module together, with this profiler overlay watching its own frame. The full path is on the series hub.

1. Jason Gregory. Game Engine Architecture, 3rd ed., chapter 10, "Tools for Debugging and Development." gameenginebook.com. The chapter's sections: logging and tracing, debug drawing, in-game menus, the in-game console, debug cameras, cheats, screenshots, in-game profiling, and memory stats.
2. Casey Muratori. "Immediate-Mode Graphical User Interfaces" (2005). caseymuratori.com. The origin of the IMGUI concept and the retained-graphics-drawbacks motivation.
3. Dear ImGui wiki. "About the IMGUI paradigm." github.com/ocornut/imgui. Quotes a March 2022 Hacker News write-up by "modeless": "immediate mode" is "a statement about the interface of the library, not the internals"; internal state is normal; Casey Muratori coined the term.
4. Omar Cornut. Dear ImGui (README). github.com/ocornut/imgui. Battle-tested in the game industry; targets content-creation and debug tools; outputs vertex buffers you render; the platform/renderer backend split.
5. CapFrameX. "Explanation of different performance metrics." capframex.com. Percentiles count frames, not time (the four 500 ms stalls in a 20 s run); a min FPS averaged over one second hides micro-stutter; "x% low" figures have no agreed definition.
6. Intel GameTechDev. PresentMon, console application README. github.com/GameTechDev/PresentMon. Per-frame metrics from presentation events: MsBetweenPresents, MsCPUBusy, MsGPUBusy and the matching wait times.
7. HPC Wiki. "Runtime profiling." hpc-wiki.info. Sampling vs instrumentation: instrumentation gives more accurate results at more overhead, sampling less overhead and less accurate results.
8. Linux kernel source, tools/perf/builtin-record.c. github.com/torvalds/linux. The default record options set .freq = 4000: 4,000 samples per second unless you pass -F.
9. Bartosz Taudul. Tracy Profiler: The user manual (August 2026). github.com/wolfpld/tracy. Sampling at 8 kHz on Windows and 10 kHz on Linux; sampling can't pinpoint semi-random stutter; single-digit-ns resolution from rdtsc; 2.25 ns of wall time per zone on a 12-thread etcpak run; "With children" vs "Self only" timing; calibrated GPU contexts.
10. GCC manual. "Options That Control Optimization," -fomit-frame-pointer. gcc.gnu.org. Omitting the frame pointer is "Enabled by default at -O1 and higher."
11. Linux perf documentation, perf-record. github.com/torvalds/linux. --call-graph defaults to frame pointers for user space, which "will produce bogus call graphs" for binaries built without them; dwarf unwinding is the alternative.
12. Bartosz Taudul. Tracy Profiler. github.com/wolfpld/tracy. A real-time, nanosecond-resolution hybrid frame and sampling profiler; CPU zones + automatic sampling + GPU zones (Vulkan/D3D/OpenGL).
13. Google. "Trace Event Format" (last updated October 2016). docs.google.com. The JSON array format; "X" complete events with ts and dur in microseconds; "M" metadata events such as thread_name.
14. Perfetto documentation. "Visualizing external trace formats with Perfetto." perfetto.dev. Chrome JSON traces open directly in the Perfetto UI; X events become slices and M events name processes and threads.
15. Bevy Engine. docs/profiling.md. github.com/bevyengine/bevy. Built-in tracing spans whose timer stops when the span is dropped; the trace_chrome feature writes a Chrome-format JSON to open at ui.perfetto.dev.
16. Brendan Gregg. "Flame Graphs." brendangregg.com; the full article is "The Flame Graph," Communications of the ACM 59(6), 2016. The x-axis is "sorted alphabetically (it is not the passage of time)"; width is how often a frame was on the sampled stacks; flame charts put time on the x-axis instead.
17. Linux perf documentation, perf-stat. github.com/torvalds/linux. Counter output with "insn per cycle"; --topdown splits cycles into frontend bound, backend bound, bad speculation and retiring.
18. Intel. VTune Profiler Performance Analysis Cookbook, "Top-Down Microarchitecture Analysis Method." intel.com. The four top-level categories and the split of Back-End Bound into Memory Bound and Core Bound.
19. The Khronos Group. Vulkan Specification, Queries. docs.vulkan.org. vkCmdWriteTimestamp waits only for earlier commands to finish the named stage and may write at a logically later stage; timestampPeriod (ns/tick), timestampValidBits, and queue support.
20. The Khronos Group. Vulkan Samples, "Timestamp queries." docs.vulkan.org/samples. Why GPU timing isn't CPU timing; TOP/BOTTOM_OF_PIPE pairs; the WAIT-stall vs availability readback; the 32-bit overflow; reset-before-write; vkCmdWriteTimestamp2 takes VkPipelineStageFlags2.
21. The Khronos Group. Vulkan Specification, "Calibrated Timestamps." docs.vulkan.org. vkGetCalibratedTimestampsKHR samples several time domains together and returns a maximum deviation in ns; applications are expected to re-calibrate regularly.
22. Microsoft. "ID3D12Device::SetStablePowerState." learn.microsoft.com. A development-time aid that fixes GPU clocks to avoid dynamic frequency scaling, typically well below the clocks players see; conclusions should be re-checked under real usage.
23. Baldur Karlsson. RenderDoc documentation. renderdoc.org. A free MIT stand-alone graphics debugger; single-frame capture, inspect every draw, resource, bound state, and shader with no code changes.
24. Intel. Graphics Performance Analyzers, "Identify GPU-CPU Bound Scenarios." intel.com. An idle hardware queue means CPU-bound; vsync can make an app appear bound when it isn't.
25. Donald Knuth. "Structured Programming with Go To Statements." ACM Computing Surveys 6:4 (1974), p. 268. dl.acm.org. The full "premature optimization is the root of all evil... yet we should not pass up our opportunities in that critical 3%."
26. Google Benchmark documentation. "Reducing Variance" and the user guide's "Preventing Optimization." github.com/google/benchmark; user guide. Sources of run-to-run variance (frequency scaling, turbo, scheduling, SMT, cache effects, NUMA) and Linux remedies; DoNotOptimize forces a result into a register or memory, but can't stop the compiler folding an expression it can compute.