feat: Add comprehensive profiling system with F3 overlay

Add real-time performance profiling infrastructure to monitor frame times,
render performance, and identify bottlenecks.

Features:
- Profiler.h: ScopedTimer RAII helper for automatic timing measurements
- ProfilerOverlay: F3-togglable overlay displaying real-time metrics
- Detailed timing breakdowns: grid rendering, entity rendering, FOV,
  Python callbacks, and animation updates
- Per-frame counters: cells rendered, entities rendered, draw calls
- Performance color coding: green (<16ms), yellow (<33ms), red (>33ms)
- Benchmark suite: static grid and moving entities performance tests

Integration:
- GameEngine: Integrated profiler overlay with F3 toggle
- UIGrid: Added timing instrumentation for grid and entity rendering
- Metrics tracked in ProfilingMetrics struct with 60-frame averaging

Usage:
- Press F3 in-game to toggle profiler overlay
- Run benchmarks with tests/benchmark_*.py scripts
- ScopedTimer automatically measures code block execution time

This addresses issue #104 (Basic profiling/metrics).

🤖 Generated with [Claude Code](https://claude.com/claude-code)

Co-Authored-By: Claude <noreply@anthropic.com>

src/GameEngine.cpp

@@ -42,8 +42,11 @@ GameEngine::GameEngine(const McRogueFaceConfig& cfg)
     updateViewport();
     scene = "uitest";
     scenes["uitest"] = new UITestScene(this);
-    
+
     McRFPy_API::game = this;
+
+    // Initialize profiler overlay
+    profilerOverlay = new ProfilerOverlay(Resources::font);
     
     // Only load game.py if no custom script/command/module/exec is specified
     bool should_load_game = config.script_path.empty() && 
@@ -85,6 +88,7 @@ GameEngine::~GameEngine()
     for (auto& [name, scene] : scenes) {
         delete scene;
     }
+    delete profilerOverlay;
 }
 
 void GameEngine::cleanup()
@@ -199,10 +203,14 @@ void GameEngine::run()
         testTimers();
         
         // Update Python scenes
-        McRFPy_API::updatePythonScenes(frameTime);
+        {
+            ScopedTimer pyTimer(metrics.pythonScriptTime);
+            McRFPy_API::updatePythonScenes(frameTime);
+        }
         
         // Update animations (only if frameTime is valid)
         if (frameTime > 0.0f && frameTime < 1.0f) {
+            ScopedTimer animTimer(metrics.animationTime);
             AnimationManager::getInstance().update(frameTime);
         }
         
@@ -240,6 +248,12 @@ void GameEngine::run()
             currentScene()->render();
         }
         
+        // Update and render profiler overlay (if enabled)
+        if (profilerOverlay && !headless) {
+            profilerOverlay->update(metrics);
+            profilerOverlay->render(*render_target);
+        }
+
         // Display the frame
         if (headless) {
             headless_renderer->display();
@@ -330,6 +344,14 @@ void GameEngine::processEvent(const sf::Event& event)
     int actionCode = 0;
 
     if (event.type == sf::Event::Closed) { running = false; return; }
+
+    // Handle F3 for profiler overlay toggle
+    if (event.type == sf::Event::KeyPressed && event.key.code == sf::Keyboard::F3) {
+        if (profilerOverlay) {
+            profilerOverlay->toggle();
+        }
+        return;
+    }
     // Handle window resize events
     else if (event.type == sf::Event::Resized) {
         // Update the viewport to handle the new window size

src/GameEngine.h

@@ -9,11 +9,16 @@
 #include "McRogueFaceConfig.h"
 #include "HeadlessRenderer.h"
 #include "SceneTransition.h"
+#include "Profiler.h"
 #include <memory>
+#include <sstream>
 
 class GameEngine
 {
 public:
+    // Forward declare nested class so private section can use it
+    class ProfilerOverlay;
+
     // Viewport modes (moved here so private section can use it)
     enum class ViewportMode {
         Center,     // 1:1 pixels, viewport centered in window
@@ -51,7 +56,12 @@ private:
     sf::Vector2u gameResolution{1024, 768};  // Fixed game resolution
     sf::View gameView;                        // View for the game content
     ViewportMode viewportMode = ViewportMode::Fit;
-    
+
+    // Profiling overlay
+    bool showProfilerOverlay = false;         // F3 key toggles this
+    int overlayUpdateCounter = 0;             // Only update overlay every N frames
+    ProfilerOverlay* profilerOverlay = nullptr; // The actual overlay renderer
+
     void updateViewport();
 
     void testTimers();
@@ -69,17 +79,29 @@ public:
         int drawCalls = 0;               // Draw calls per frame
         int uiElements = 0;              // Number of UI elements rendered
         int visibleElements = 0;         // Number of visible elements
-        
+
+        // Detailed timing breakdowns (added for profiling system)
+        float gridRenderTime = 0.0f;     // Time spent rendering grids (ms)
+        float entityRenderTime = 0.0f;   // Time spent rendering entities (ms)
+        float fovOverlayTime = 0.0f;     // Time spent rendering FOV overlays (ms)
+        float pythonScriptTime = 0.0f;   // Time spent in Python callbacks (ms)
+        float animationTime = 0.0f;      // Time spent updating animations (ms)
+
+        // Grid-specific metrics
+        int gridCellsRendered = 0;       // Number of grid cells drawn this frame
+        int entitiesRendered = 0;        // Number of entities drawn this frame
+        int totalEntities = 0;           // Total entities in scene
+
         // Frame time history for averaging
         static constexpr int HISTORY_SIZE = 60;
         float frameTimeHistory[HISTORY_SIZE] = {0};
         int historyIndex = 0;
-        
+
         void updateFrameTime(float deltaMs) {
             frameTime = deltaMs;
             frameTimeHistory[historyIndex] = deltaMs;
             historyIndex = (historyIndex + 1) % HISTORY_SIZE;
-            
+
             // Calculate average
             float sum = 0.0f;
             for (int i = 0; i < HISTORY_SIZE; ++i) {
@@ -88,13 +110,26 @@ public:
             avgFrameTime = sum / HISTORY_SIZE;
             fps = avgFrameTime > 0 ? static_cast<int>(1000.0f / avgFrameTime) : 0;
         }
-        
+
         void resetPerFrame() {
             drawCalls = 0;
             uiElements = 0;
             visibleElements = 0;
+
+            // Reset per-frame timing metrics
+            gridRenderTime = 0.0f;
+            entityRenderTime = 0.0f;
+            fovOverlayTime = 0.0f;
+            pythonScriptTime = 0.0f;
+            animationTime = 0.0f;
+
+            // Reset per-frame counters
+            gridCellsRendered = 0;
+            entitiesRendered = 0;
+            totalEntities = 0;
         }
     } metrics;
+
     GameEngine();
     GameEngine(const McRogueFaceConfig& cfg);
     ~GameEngine();
@@ -144,5 +179,30 @@ public:
     sf::Music music;
     sf::Sound sfx;
     std::shared_ptr<std::vector<std::shared_ptr<UIDrawable>>> scene_ui(std::string scene);
-    
+
+};
+
+/**
+ * @brief Visual overlay that displays real-time profiling metrics
+ */
+class GameEngine::ProfilerOverlay {
+private:
+    sf::Font& font;
+    sf::Text text;
+    sf::RectangleShape background;
+    bool visible;
+    int updateInterval;
+    int frameCounter;
+
+    sf::Color getPerformanceColor(float frameTimeMs);
+    std::string formatFloat(float value, int precision = 1);
+    std::string formatPercentage(float part, float total);
+
+public:
+    ProfilerOverlay(sf::Font& fontRef);
+    void toggle();
+    void setVisible(bool vis);
+    bool isVisible() const;
+    void update(const ProfilingMetrics& metrics);
+    void render(sf::RenderTarget& target);
 };

src/Profiler.cpp

@@ -0,0 +1,61 @@
+#include "Profiler.h"
+#include <iostream>
+
+ProfilingLogger::ProfilingLogger()
+    : headers_written(false)
+{
+}
+
+ProfilingLogger::~ProfilingLogger() {
+    close();
+}
+
+bool ProfilingLogger::open(const std::string& filename, const std::vector<std::string>& columns) {
+    column_names = columns;
+    file.open(filename);
+
+    if (!file.is_open()) {
+        std::cerr << "Failed to open profiling log file: " << filename << std::endl;
+        return false;
+    }
+
+    // Write CSV header
+    for (size_t i = 0; i < columns.size(); ++i) {
+        file << columns[i];
+        if (i < columns.size() - 1) {
+            file << ",";
+        }
+    }
+    file << "\n";
+    file.flush();
+
+    headers_written = true;
+    return true;
+}
+
+void ProfilingLogger::writeRow(const std::vector<float>& values) {
+    if (!file.is_open()) {
+        return;
+    }
+
+    if (values.size() != column_names.size()) {
+        std::cerr << "ProfilingLogger: value count (" << values.size()
+                  << ") doesn't match column count (" << column_names.size() << ")" << std::endl;
+        return;
+    }
+
+    for (size_t i = 0; i < values.size(); ++i) {
+        file << values[i];
+        if (i < values.size() - 1) {
+            file << ",";
+        }
+    }
+    file << "\n";
+}
+
+void ProfilingLogger::close() {
+    if (file.is_open()) {
+        file.flush();
+        file.close();
+    }
+}

src/Profiler.h

@@ -0,0 +1,111 @@
+#pragma once
+
+#include <chrono>
+#include <string>
+#include <vector>
+#include <fstream>
+
+/**
+ * @brief Simple RAII-based profiling timer for measuring code execution time
+ *
+ * Usage:
+ *   float timing = 0.0f;
+ *   {
+ *       ScopedTimer timer(timing);
+ *       // ... code to profile ...
+ *   } // timing now contains elapsed milliseconds
+ */
+class ScopedTimer {
+private:
+    std::chrono::high_resolution_clock::time_point start;
+    float& target_ms;
+
+public:
+    /**
+     * @brief Construct a new Scoped Timer and start timing
+     * @param target Reference to float that will receive elapsed time in milliseconds
+     */
+    explicit ScopedTimer(float& target)
+        : target_ms(target)
+    {
+        start = std::chrono::high_resolution_clock::now();
+    }
+
+    /**
+     * @brief Destructor automatically records elapsed time
+     */
+    ~ScopedTimer() {
+        auto end = std::chrono::high_resolution_clock::now();
+        target_ms = std::chrono::duration<float, std::milli>(end - start).count();
+    }
+
+    // Prevent copying
+    ScopedTimer(const ScopedTimer&) = delete;
+    ScopedTimer& operator=(const ScopedTimer&) = delete;
+};
+
+/**
+ * @brief Accumulating timer that adds elapsed time to existing value
+ *
+ * Useful for measuring total time across multiple calls in a single frame
+ */
+class AccumulatingTimer {
+private:
+    std::chrono::high_resolution_clock::time_point start;
+    float& target_ms;
+
+public:
+    explicit AccumulatingTimer(float& target)
+        : target_ms(target)
+    {
+        start = std::chrono::high_resolution_clock::now();
+    }
+
+    ~AccumulatingTimer() {
+        auto end = std::chrono::high_resolution_clock::now();
+        target_ms += std::chrono::duration<float, std::milli>(end - start).count();
+    }
+
+    AccumulatingTimer(const AccumulatingTimer&) = delete;
+    AccumulatingTimer& operator=(const AccumulatingTimer&) = delete;
+};
+
+/**
+ * @brief CSV profiling data logger for batch analysis
+ *
+ * Writes profiling data to CSV file for later analysis with Python/pandas/Excel
+ */
+class ProfilingLogger {
+private:
+    std::ofstream file;
+    bool headers_written;
+    std::vector<std::string> column_names;
+
+public:
+    ProfilingLogger();
+    ~ProfilingLogger();
+
+    /**
+     * @brief Open a CSV file for writing profiling data
+     * @param filename Path to CSV file
+     * @param columns Column names for the CSV header
+     * @return true if file opened successfully
+     */
+    bool open(const std::string& filename, const std::vector<std::string>& columns);
+
+    /**
+     * @brief Write a row of profiling data
+     * @param values Data values (must match column count)
+     */
+    void writeRow(const std::vector<float>& values);
+
+    /**
+     * @brief Close the file and flush data
+     */
+    void close();
+
+    /**
+     * @brief Check if logger is ready to write
+     */
+    bool isOpen() const { return file.is_open(); }
+};

src/ProfilerOverlay.cpp

@@ -0,0 +1,135 @@
+#include "GameEngine.h"
+#include <sstream>
+#include <iomanip>
+
+GameEngine::ProfilerOverlay::ProfilerOverlay(sf::Font& fontRef)
+    : font(fontRef), visible(false), updateInterval(10), frameCounter(0)
+{
+    text.setFont(font);
+    text.setCharacterSize(14);
+    text.setFillColor(sf::Color::White);
+    text.setPosition(10.0f, 10.0f);
+
+    // Semi-transparent dark background
+    background.setFillColor(sf::Color(0, 0, 0, 180));
+    background.setPosition(5.0f, 5.0f);
+}
+
+void GameEngine::ProfilerOverlay::toggle() {
+    visible = !visible;
+}
+
+void GameEngine::ProfilerOverlay::setVisible(bool vis) {
+    visible = vis;
+}
+
+bool GameEngine::ProfilerOverlay::isVisible() const {
+    return visible;
+}
+
+sf::Color GameEngine::ProfilerOverlay::getPerformanceColor(float frameTimeMs) {
+    if (frameTimeMs < 16.6f) {
+        return sf::Color::Green;  // 60+ FPS
+    } else if (frameTimeMs < 33.3f) {
+        return sf::Color::Yellow; // 30-60 FPS
+    } else {
+        return sf::Color::Red;    // <30 FPS
+    }
+}
+
+std::string GameEngine::ProfilerOverlay::formatFloat(float value, int precision) {
+    std::stringstream ss;
+    ss << std::fixed << std::setprecision(precision) << value;
+    return ss.str();
+}
+
+std::string GameEngine::ProfilerOverlay::formatPercentage(float part, float total) {
+    if (total <= 0.0f) return "0%";
+    float pct = (part / total) * 100.0f;
+    return formatFloat(pct, 0) + "%";
+}
+
+void GameEngine::ProfilerOverlay::update(const ProfilingMetrics& metrics) {
+    if (!visible) return;
+
+    // Only update text every N frames to reduce overhead
+    frameCounter++;
+    if (frameCounter < updateInterval) {
+        return;
+    }
+    frameCounter = 0;
+
+    std::stringstream ss;
+    ss << "McRogueFace Performance Monitor\n";
+    ss << "================================\n";
+
+    // Frame time and FPS
+    float frameMs = metrics.avgFrameTime;
+    ss << "FPS: " << metrics.fps << " (" << formatFloat(frameMs, 1) << "ms/frame)\n";
+
+    // Performance warning
+    if (frameMs > 33.3f) {
+        ss << "WARNING: Frame time exceeds 30 FPS target!\n";
+    }
+
+    ss << "\n";
+
+    // Timing breakdown
+    ss << "Frame Time Breakdown:\n";
+    ss << "  Grid Render:  " << formatFloat(metrics.gridRenderTime, 1) << "ms ("
+       << formatPercentage(metrics.gridRenderTime, frameMs) << ")\n";
+    ss << "    Cells: " << metrics.gridCellsRendered << " rendered\n";
+    ss << "    Entities: " << metrics.entitiesRendered << " / " << metrics.totalEntities << " drawn\n";
+
+    if (metrics.fovOverlayTime > 0.01f) {
+        ss << "    FOV Overlay: " << formatFloat(metrics.fovOverlayTime, 1) << "ms\n";
+    }
+
+    if (metrics.entityRenderTime > 0.01f) {
+        ss << "  Entity Render: " << formatFloat(metrics.entityRenderTime, 1) << "ms ("
+           << formatPercentage(metrics.entityRenderTime, frameMs) << ")\n";
+    }
+
+    if (metrics.pythonScriptTime > 0.01f) {
+        ss << "  Python:       " << formatFloat(metrics.pythonScriptTime, 1) << "ms ("
+           << formatPercentage(metrics.pythonScriptTime, frameMs) << ")\n";
+    }
+
+    if (metrics.animationTime > 0.01f) {
+        ss << "  Animations:   " << formatFloat(metrics.animationTime, 1) << "ms ("
+           << formatPercentage(metrics.animationTime, frameMs) << ")\n";
+    }
+
+    ss << "\n";
+
+    // Other metrics
+    ss << "Draw Calls: " << metrics.drawCalls << "\n";
+    ss << "UI Elements: " << metrics.uiElements << " (" << metrics.visibleElements << " visible)\n";
+
+    // Calculate unaccounted time
+    float accountedTime = metrics.gridRenderTime + metrics.entityRenderTime +
+                          metrics.pythonScriptTime + metrics.animationTime;
+    float unaccountedTime = frameMs - accountedTime;
+
+    if (unaccountedTime > 1.0f) {
+        ss << "\n";
+        ss << "Other: " << formatFloat(unaccountedTime, 1) << "ms ("
+           << formatPercentage(unaccountedTime, frameMs) << ")\n";
+    }
+
+    ss << "\n";
+    ss << "Press F3 to hide this overlay";
+
+    text.setString(ss.str());
+
+    // Update background size to fit text
+    sf::FloatRect textBounds = text.getLocalBounds();
+    background.setSize(sf::Vector2f(textBounds.width + 20.0f, textBounds.height + 20.0f));
+}
+
+void GameEngine::ProfilerOverlay::render(sf::RenderTarget& target) {
+    if (!visible) return;
+
+    target.draw(background);
+    target.draw(text);
+}

src/UIGrid.cpp

@@ -3,6 +3,7 @@
 #include "McRFPy_API.h"
 #include "PythonObjectCache.h"
 #include "UIEntity.h"
+#include "Profiler.h"
 #include <algorithm>
 // UIDrawable methods now in UIBase.h
 
@@ -95,11 +96,14 @@ void UIGrid::update() {}
 
 void UIGrid::render(sf::Vector2f offset, sf::RenderTarget& target)
 {
+    // Profile total grid rendering time
+    ScopedTimer gridTimer(Resources::game->metrics.gridRenderTime);
+
     // Check visibility
     if (!visible) return;
-    
+
     // TODO: Apply opacity to output sprite
-    
+
     output.setPosition(box.getPosition() + offset); // output sprite can move; update position when drawing
     // output size can change; update size when drawing
     output.setTextureRect(
@@ -135,11 +139,12 @@ void UIGrid::render(sf::Vector2f offset, sf::RenderTarget& target)
     if (y_limit > grid_y) y_limit = grid_y;
 
     // base layer - bottom color, tile sprite ("ground")
+    int cellsRendered = 0;
     for (int x = (left_edge - 1 >= 0 ? left_edge - 1 : 0);
-        x < x_limit; //x < view_width; 
+        x < x_limit; //x < view_width;
         x+=1)
     {
-        //for (float y = (top_edge >= 0 ? top_edge : 0); 
+        //for (float y = (top_edge >= 0 ? top_edge : 0);
         for (int y = (top_edge - 1 >= 0 ? top_edge - 1 : 0);
             y < y_limit; //y < view_height;
             y+=1)
@@ -163,35 +168,53 @@ void UIGrid::render(sf::Vector2f offset, sf::RenderTarget& target)
                 sprite = ptex->sprite(gridpoint.tilesprite, pixel_pos, sf::Vector2f(zoom, zoom)); //setSprite(gridpoint.tilesprite);;
                 renderTexture.draw(sprite);
             }
+
+            cellsRendered++;
         }
     }
 
+    // Record how many cells were rendered
+    Resources::game->metrics.gridCellsRendered += cellsRendered;
+
     // middle layer - entities
     // disabling entity rendering until I can render their UISprite inside the rendertexture (not directly to window)
-    for (auto e : *entities) {
-        // Skip out-of-bounds entities for performance
-        // Check if entity is within visible bounds (with 1 cell margin for partially visible entities)
-        if (e->position.x < left_edge - 1 || e->position.x >= left_edge + width_sq + 1 ||
-            e->position.y < top_edge - 1 || e->position.y >= top_edge + height_sq + 1) {
-            continue; // Skip this entity as it's not visible
+    {
+        ScopedTimer entityTimer(Resources::game->metrics.entityRenderTime);
+        int entitiesRendered = 0;
+        int totalEntities = entities->size();
+
+        for (auto e : *entities) {
+            // Skip out-of-bounds entities for performance
+            // Check if entity is within visible bounds (with 1 cell margin for partially visible entities)
+            if (e->position.x < left_edge - 1 || e->position.x >= left_edge + width_sq + 1 ||
+                e->position.y < top_edge - 1 || e->position.y >= top_edge + height_sq + 1) {
+                continue; // Skip this entity as it's not visible
+            }
+
+            //auto drawent = e->cGrid->indexsprite.drawable();
+            auto& drawent = e->sprite;
+            //drawent.setScale(zoom, zoom);
+            drawent.setScale(sf::Vector2f(zoom, zoom));
+            auto pixel_pos = sf::Vector2f(
+                (e->position.x*cell_width - left_spritepixels) * zoom,
+                (e->position.y*cell_height - top_spritepixels) * zoom );
+            //drawent.setPosition(pixel_pos);
+            //renderTexture.draw(drawent);
+            drawent.render(pixel_pos, renderTexture);
+
+            entitiesRendered++;
         }
-        
-        //auto drawent = e->cGrid->indexsprite.drawable();
-        auto& drawent = e->sprite;
-        //drawent.setScale(zoom, zoom);
-        drawent.setScale(sf::Vector2f(zoom, zoom));
-        auto pixel_pos = sf::Vector2f(
-            (e->position.x*cell_width - left_spritepixels) * zoom,
-            (e->position.y*cell_height - top_spritepixels) * zoom );
-        //drawent.setPosition(pixel_pos);
-        //renderTexture.draw(drawent);
-        drawent.render(pixel_pos, renderTexture);
+
+        // Record entity rendering stats
+        Resources::game->metrics.entitiesRendered += entitiesRendered;
+        Resources::game->metrics.totalEntities += totalEntities;
     }
     
 
     // top layer - opacity for discovered / visible status based on perspective
     // Only render visibility overlay if perspective is enabled
     if (perspective_enabled) {
+        ScopedTimer fovTimer(Resources::game->metrics.fovOverlayTime);
         auto entity = perspective_entity.lock();
         
         // Create rectangle for overlays