6 Performance and Profiling
John McCardle edited this page 2026-07-12 00:52:15 +00:00

Performance and Profiling

mcrf-meta -- objects: none | type: system | status: rewrite-pending | verified: none

This page is queued for a full rewrite (post-#332/#345/#354 architecture: SoA grid data, make profile/callgrind rig, Crucible benchmark, get_metrics() counters are all missing below). The optimization methodology below was merged in from the retired "Performance Optimization Workflow" page and remains accurate.

Performance monitoring and optimization infrastructure for McRogueFace. Press F3 in-game to see real-time metrics, or use the benchmark API to capture detailed timing data to disk.

Quick Reference

Related Issues:

  • #104 - Basic Profiling/Metrics (Closed - Implemented)
  • #148 - Dirty Flag RenderTexture Caching (Closed - Implemented)
  • #123 - Chunk-based Grid Rendering (Closed - Implemented)
  • #115 - SpatialHash Implementation (Closed - Implemented)
  • #113 - Batch Operations for Grid (Open)

Key Files:

  • src/Profiler.h - ScopedTimer RAII helper
  • src/ProfilerOverlay.cpp - F3 overlay visualization
  • src/GameEngine.h - ProfilingMetrics struct

Benchmark API

The benchmark API captures per-frame timing data to JSON files. C++ handles all timing; Python processes results afterward.

Basic Usage

import mcrfpy

# Start capturing benchmark data
mcrfpy.start_benchmark()

# ... run your test scenario ...

# Stop and get the output filename
filename = mcrfpy.end_benchmark()
print(f"Benchmark saved to: {filename}")

Adding Log Messages

Mark specific events within the benchmark:

mcrfpy.start_benchmark()

# Your code...
mcrfpy.log_benchmark("Player spawned")

# More code...
mcrfpy.log_benchmark("Combat started")

filename = mcrfpy.end_benchmark()

Headless Mode Note

In --headless mode with step(), the benchmark API warns that step-based simulation bypasses the game loop. For headless performance measurement, use Python's time module:

import time

start = time.perf_counter()
# ... operation to measure ...
elapsed = time.perf_counter() - start
print(f"Operation took {elapsed*1000:.2f}ms")

The benchmark API works best with the normal game loop (non-headless mode).

Output Format

The JSON file contains per-frame data:

{
  "frames": [
    {
      "frame_number": 1,
      "frame_time_ms": 12.5,
      "grid_render_time_ms": 8.2,
      "entity_render_time_ms": 2.1,
      "python_time_ms": 1.8,
      "logs": ["Player spawned"]
    }
  ],
  "summary": {
    "total_frames": 1000,
    "avg_frame_time_ms": 14.2,
    "max_frame_time_ms": 28.5,
    "min_frame_time_ms": 8.1
  }
}

Processing Results

import json

def analyze_benchmark(filename):
    with open(filename) as f:
        data = json.load(f)

    frames = data["frames"]
    slow_frames = [f for f in frames if f["frame_time_ms"] > 16.67]

    print(f"Total frames: {len(frames)}")
    print(f"Slow frames (>16.67ms): {len(slow_frames)}")
    print(f"Average: {data['summary']['avg_frame_time_ms']:.2f}ms")

    for frame in slow_frames[:5]:
        print(f"  Frame {frame['frame_number']}: {frame['frame_time_ms']:.1f}ms")
        if frame.get("logs"):
            print(f"    Logs: {frame['logs']}")

F3 Profiler Overlay

Activation: Press F3 during gameplay

Displays:

  • Frame time (ms) with color coding:
    • Green: < 16ms (60+ FPS)
    • Yellow: 16-33ms (30-60 FPS)
    • Red: > 33ms (< 30 FPS)
  • FPS (averaged over 60 frames)
  • Detailed breakdowns:
    • Grid rendering time
    • Entity rendering time
    • Python script time
    • Animation update time
  • Per-frame counts:
    • Grid cells rendered
    • Entities rendered (visible/total)

Implementation: src/ProfilerOverlay.cpp


The Optimization Cycle

(merged in from the retired "Performance Optimization Workflow" page)

1. PROFILE -> 2. IDENTIFY -> 3. INSTRUMENT -> 4. OPTIMIZE -> 5. VERIFY
     ^                                                         |
     +---------------------------------------------------------+

Step 1: Profile - Find the Bottleneck

Press F3 for the live overlay, or capture detailed data with mcrfpy.start_benchmark() / mcrfpy.end_benchmark() (see above). Watch for red (>33ms) or yellow (16-33ms) frame times, and check which subsystem breakdown (grid / entity / python / animation) is high.

Step 2: Identify - Understand the Problem

Common categories:

  • Slow bulk grid updates from Python -- many individual layer.set() calls cross the Python/C++ boundary per-cell. Use layer.fill() for uniform data, or the with layer.edit() as view: buffer-protocol view for bulk numpy-style writes.
  • High Python script time -- heavy computation in Python update loops; move hot paths to C++ or optimize the Python.
  • Entity-heavy scenes -- use grid.entities_in_radius() for proximity queries instead of iterating all entities (SpatialHash-backed, O(k)).

Step 3: Instrument - Measure Precisely

C++: wrap slow functions with ScopedTimer (src/Profiler.h); add a field to ProfilingMetrics in src/GameEngine.h, reset it in resetPerFrame(), display it in ProfilerOverlay.cpp::update().

Native/deterministic: for A/B validating C++ hot-path changes, use the dedicated profiling build (make profile, make callgrind SCRIPT=...) -- see docs/profiling.md and the Crucible benchmark harness (tests/benchmarks/crucible.py) for headless, deterministic wall-clock comparisons.

Python benchmarks (headless): use time.perf_counter() directly -- step() bypasses the game loop, so the Timer-based benchmark pattern doesn't fire in headless mode.

Step 4: Optimize - Make It Faster

  • Reduce work: rely on dirty-flag/generation-counter invalidation (the grid view only re-renders when its content generation, camera, or perspective state actually changed) rather than redrawing unconditionally.
  • Reduce complexity: prefer spatial queries (entities_in_radius) and cached Dijkstra maps over brute-force iteration.
  • Batch operations: minimize Python/C++ boundary crossings -- prefer layer.fill() / layer.edit() over many individual layer.set() calls.
  • Cache results: memoize expensive per-target computations (e.g. paths) that don't need to be recomputed every frame.

Checklist before optimizing: profiled and identified the real bottleneck; measured a baseline. After: measured the improvement; verified correctness; updated/added tests.

Step 5: Verify - Measure Improvement

Re-run the benchmark and compare. For engine-level (C++) changes prefer the deterministic Crucible/Callgrind path over wall-clock A/B, which is noisy under load. Document baseline vs. optimized numbers, improvement factor, test/benchmark script name, and commit hash on the relevant Gitea issue.

When NOT to Optimize

Don't optimize if performance is already acceptable (<16ms frame time), the change would meaningfully complicate the code, you haven't profiled yet, or the bottleneck is actually somewhere else. Correctness first; profile to find real bottlenecks; optimize only the hot paths.