Frame stats

.github/workflows/build.yml

@@ -10,16 +10,19 @@ jobs:
                     - os: windows-latest
                       artifact: "windows"
                       wasm4: bin/wasm4.exe
+                      wasm4_glfw: bin/wasm4_glfw.exe
                       libretro: lib/wasm4_libretro.dll
 
                     - os: macos-latest
                       artifact: "mac"
                       wasm4: bin/wasm4
+                      wasm4_glfw: bin/wasm4_glfw
                       libretro: lib/wasm4_libretro.dylib
 
                     - os: ubuntu-latest
                       artifact: "linux"
                       wasm4: bin/wasm4
+                      wasm4_glfw: bin/wasm4_glfw
                       libretro: lib/wasm4_libretro.so
 
         name: Build ${{ matrix.config.artifact }}
@@ -53,6 +56,12 @@ jobs:
                   path: runtimes/native/instdir/${{ matrix.config.wasm4 }}
                   name: wasm4-${{ matrix.config.artifact }}
 
+            - name: Upload wasm4_glfw artifact
+              uses: actions/upload-artifact@v2
+              with:
+                  path: runtimes/native/instdir/${{ matrix.config.wasm4_glfw }}
+                  name: wasm4-glfw-${{ matrix.config.artifact }}
+
             - name: Upload libretro artifact
               uses: actions/upload-artifact@v2
               with:
@@ -94,7 +103,7 @@ jobs:
                   mkdir -p assets/natives
                   ls -R ../artifacts
                   mv ../artifacts/wasm4-windows/wasm4.exe assets/natives/wasm4-windows.exe
-                  mv ../artifacts/wasm4-mac/wasm4 assets/natives/wasm4-mac
+                  mv ../artifacts/wasm4-glfw-mac/wasm4_glfw assets/natives/wasm4-mac
                   mv ../artifacts/wasm4-linux/wasm4 assets/natives/wasm4-linux
                   chmod +x assets/natives/wasm4-*
 

.gitmodules

@@ -1,6 +1,9 @@
 [submodule "runtimes/native/vendor/wasm3"]
 	path = runtimes/native/vendor/wasm3
 	url = https://github.com/wasm3/wasm3
+[submodule "runtimes/native/vendor/glfw"]
+	path = runtimes/native/vendor/glfw
+	url = https://github.com/glfw/glfw
 [submodule "runtimes/native/vendor/minifb"]
 	path = runtimes/native/vendor/minifb
 	url = https://github.com/emoon/minifb

runtimes/native/CMakeLists.txt

@@ -45,7 +45,7 @@ if (LIBRETRO)
 endif ()
 
 if (NOT LIBRETRO)
-# add_subdirectory(vendor/glfw)
+add_subdirectory(vendor/glfw)
 add_subdirectory(vendor/minifb)
 add_subdirectory(vendor/cubeb)
 endif ()
@@ -94,23 +94,23 @@ if (WASMER_DIR)
     install(TARGETS wasm4_wasmer)
 endif ()
 
-# #
-# # Desktop (glfw + cubeb) backend
-# #
-# 
-# set(GLFW_SOURCES
-#     src/backend/main.c
-#     src/backend/wasm_wasm3.c
-#     src/backend/window_glfw.c
-#     vendor/glad/src/glad.c
-# )
-# add_executable(wasm4_glfw)
-# target_sources(wasm4_glfw PRIVATE ${COMMON_SOURCES} ${GLFW_SOURCES} ${M3_SOURCES})
-# target_include_directories(wasm4_glfw PRIVATE "${CMAKE_SOURCE_DIR}/vendor/wasm3/source")
-# target_include_directories(wasm4_glfw PRIVATE "${CMAKE_SOURCE_DIR}/vendor/glad/include")
-# target_link_libraries(wasm4_glfw glfw cubeb)
-# set_target_properties(wasm4_glfw PROPERTIES C_STANDARD 99)
-# install(TARGETS wasm4_glfw)
+#
+# Desktop (glfw + cubeb) backend
+#
+
+set(GLFW_SOURCES
+    src/backend/main.c
+    src/backend/wasm_wasm3.c
+    src/backend/window_glfw.c
+    vendor/glad/src/glad.c
+)
+add_executable(wasm4_glfw)
+target_sources(wasm4_glfw PRIVATE ${COMMON_SOURCES} ${GLFW_SOURCES} ${M3_SOURCES})
+target_include_directories(wasm4_glfw PRIVATE "${CMAKE_SOURCE_DIR}/vendor/wasm3/source")
+target_include_directories(wasm4_glfw PRIVATE "${CMAKE_SOURCE_DIR}/vendor/glad/include")
+target_link_libraries(wasm4_glfw glfw cubeb)
+set_target_properties(wasm4_glfw PROPERTIES C_STANDARD 99)
+install(TARGETS wasm4_glfw)
 
 #
 # Libretro backend

runtimes/native/README.md

@@ -31,5 +31,6 @@ If you want to build only one target:
 
 ``` shell
 cmake --build build --target wasm4_libretro
+cmake --build build --target wasm4_glfw
 cmake --build build --target wasm4
 ```

runtimes/native/src/backend/main.c

@@ -117,6 +117,10 @@ static void trimFileExtension (char *path) {
     }
 }
 
+static void logFrameStatsMsg(const char* msg) {
+    printf("%s", msg);
+}
+
 int main (int argc, const char* argv[]) {
     uint8_t* cartBytes;
     size_t cartLength;
@@ -188,4 +192,6 @@ int main (int argc, const char* argv[]) {
     audioUninit();
 
     saveDiskFile(&disk, diskPath);
+
+    w4_runtimeLogFrameStats(logFrameStatsMsg);
 }

runtimes/native/src/backend/main_libretro.c

@@ -49,13 +49,21 @@ static void fallback_log(enum retro_log_level level,
 
 static retro_log_printf_t log_cb = fallback_log;
 
+static void logFrameStatsMsg(const char* msg) {
+    log_cb(RETRO_LOG_INFO, "%s", msg);
+}
+
 #if !defined(PSP) && !defined(PS2)
 static void audio_callback () {
     w4_apuWriteSamples(audio_output, AUDIO_BUFFER_FRAMES_CALLBACK);
     audio_batch_cb(audio_output, AUDIO_BUFFER_FRAMES_CALLBACK);
 }
 #endif
 
+static void frame_time_callback(retro_usec_t usec) {
+    w4_runtimeRecordFrameDuration(usec);
+}
+
 unsigned retro_api_version () {
     return RETRO_API_VERSION;
 }
@@ -333,6 +341,9 @@ bool retro_load_game (const struct retro_game_info* game) {
 	log_cb(RETRO_LOG_INFO, "Using normal audio\n");
     }
 
+    struct retro_frame_time_callback frame_cb = { frame_time_callback, 1000000 / 60 };
+    environ_cb(RETRO_ENVIRONMENT_SET_FRAME_TIME_CALLBACK, &frame_cb);
+
     return true;
 }
 
@@ -345,6 +356,7 @@ void retro_unload_game () {
     if (wasmCopy) {
         free(wasmData);
     }
+    w4_runtimeLogFrameStats(logFrameStatsMsg);
 }
 
 void retro_reset () {

runtimes/native/src/backend/window_glfw.c

@@ -216,6 +216,10 @@ void w4_windowBoot (const char* title) {
         while ((timeRemaining = timeEnd - glfwGetTime()) > 0) {
             glfwWaitEventsTimeout(timeRemaining);
         }
+
+        double timeEndActual = glfwGetTime();
+        uint64_t durationUsec = (uint64_t) ((timeEndActual - timeStart) * 1e6);
+        w4_runtimeRecordFrameDuration(durationUsec);
     }
 
     glfwDestroyWindow(window);

runtimes/native/src/backend/window_minifb.c

@@ -23,6 +23,8 @@ void w4_windowBoot (const char* title) {
 
     mfb_set_resize_callback(window, onResize);
 
+    struct mfb_timer* frameTimer = mfb_timer_create();
+
     do {
         // Keyboard handling
         const uint8_t* keyBuffer = mfb_get_key_buffer(window);
@@ -92,7 +94,12 @@ void w4_windowBoot (const char* title) {
         if (mfb_update_ex(window, pixels, 160, 160) < 0) {
             break;
         }
+
+        uint64_t durationUsec = (uint64_t) (mfb_timer_delta(frameTimer) * 1e6);
+        w4_runtimeRecordFrameDuration(durationUsec);
     } while (mfb_wait_sync(window));
+
+    mfb_timer_destroy(frameTimer);
 }
 
 void w4_windowComposite (const uint32_t* palette, const uint8_t* framebuffer) {

runtimes/native/src/runtime.c

@@ -1,5 +1,7 @@
 #include "runtime.h"
 
+#define __STDC_FORMAT_MACROS
+#include <inttypes.h>
 #include <stdio.h>
 #include <string.h>
 
@@ -14,6 +16,8 @@
 
 #define SYSTEM_PRESERVE_FRAMEBUFFER 1
 
+#define FRAME_STATS_BINS 100
+
 typedef struct {
     uint8_t _padding[4];
     uint32_t palette[4];
@@ -37,11 +41,14 @@ typedef struct {
 static Memory* memory;
 static w4_Disk* disk;
 static bool firstFrame;
+static uint64_t frameStats[FRAME_STATS_BINS];
+static char frameStatsLogBuf[256];
 
 void w4_runtimeInit (uint8_t* memoryBytes, w4_Disk* diskBytes) {
     memory = (Memory*)memoryBytes;
     disk = diskBytes;
     firstFrame = true;
+    memset(frameStats, 0, sizeof(frameStats));
 
     // Set memory to initial state
     memset(memory, 0, 1 << 16);
@@ -208,3 +215,40 @@ void w4_runtimeUnserialize (const void* src) {
     memcpy(disk, &state->disk, sizeof(w4_Disk));
     firstFrame = state->firstFrame;
 }
+
+void w4_runtimeRecordFrameDuration(uint64_t durationUsec) {
+    uint64_t durationMsec = durationUsec / 1000;
+    size_t bin = (size_t) (
+        durationMsec >= FRAME_STATS_BINS
+        ? (FRAME_STATS_BINS - 1)
+        : durationMsec
+    );
+    frameStats[bin] += 1;
+}
+
+void w4_runtimeLogFrameStats(void (*logFrameStatsMsg)(const char *msg)) {
+    logFrameStatsMsg("Frame stats:\n");
+    size_t lastBin = FRAME_STATS_BINS - 1;
+    for (size_t bin = 0; bin < lastBin; bin++) {
+        uint64_t count = frameStats[bin];
+        if (count == 0) {
+            continue;
+        }
+        snprintf(
+            frameStatsLogBuf,
+            sizeof(frameStatsLogBuf),
+            "  %2" PRIu64 " ms: %8" PRIu64 "\n",
+            (uint64_t) bin,
+            count
+        );
+        logFrameStatsMsg(frameStatsLogBuf);
+    }
+    snprintf(
+        frameStatsLogBuf,
+        sizeof(frameStatsLogBuf),
+        ">=%2" PRIu64 " ms: %8" PRIu64 "\n",
+        (uint64_t) lastBin,
+        frameStats[lastBin]
+    );
+    logFrameStatsMsg(frameStatsLogBuf);
+}

runtimes/native/src/runtime.h

@@ -51,3 +51,11 @@ void w4_runtimeUpdate ();
 int w4_runtimeSerializeSize ();
 void w4_runtimeSerialize (void* dest);
 void w4_runtimeUnserialize (const void* src);
+
+/// Record duration of each frame (in microseconds)
+/// so that we can generate frame stats at the end of the run.
+void w4_runtimeRecordFrameDuration(uint64_t durationUsec);
+
+/// Log frame stats to stdout or local equivalent.
+/// The log function must accept and print a string.
+void w4_runtimeLogFrameStats(void (*logFrameStatsMsg)(const char *msg));