Added CPU audio to lightweight profiler

* Downgraded from F3DZEX2.08J to F3DZEX2.08I so that point lighting works on Jabo

* Swapped to MM's rspboot to fix bug caused by MM's F3DZEX2

Makefile

@@ -323,11 +323,25 @@ ifeq ($(filter clean distclean print-%,$(MAKECMDGOALS)),)
   ifeq ($(NOEXTRACT),0)
     DUMMY != $(PYTHON) extract_assets.py $(VERSION) >&2 || echo FAIL
     ifeq ($(DUMMY),FAIL)
-      $(error Failed to extract assets)
+      $(error Failed to extract assets from US ROM)
     endif
-    DUMMY != $(PYTHON) extract_assets.py jp >&2 || echo FAIL
-    ifeq ($(DUMMY),FAIL)
-      $(error Failed to extract assets)
+    ifneq (,$(wildcard baserom.jp.z64))
+      DUMMY != $(PYTHON) extract_assets.py jp >&2 || echo FAIL
+      ifeq ($(DUMMY),FAIL)
+        $(error Failed to extract assets from JP ROM)
+      endif
+    endif
+    ifneq (,$(wildcard baserom.eu.z64))
+      DUMMY != $(PYTHON) extract_assets.py eu >&2 || echo FAIL
+      ifeq ($(DUMMY),FAIL)
+        $(error Failed to extract assets from EU ROM)
+      endif
+    endif
+    ifneq (,$(wildcard baserom.sh.z64))
+      DUMMY != $(PYTHON) extract_assets.py sh >&2 || echo FAIL
+      ifeq ($(DUMMY),FAIL)
+        $(error Failed to extract assets from SH ROM)
+      endif
     endif
   endif
 

data/behavior_data.c

@@ -791,6 +791,7 @@ const BehaviorScript bhvWfBreakableWallLeft[] = {
     // WF breakable walls - common:
     OR_INT(oFlags, (OBJ_FLAG_ACTIVE_FROM_AFAR | OBJ_FLAG_COMPUTE_DIST_TO_MARIO | OBJ_FLAG_SET_FACE_YAW_TO_MOVE_YAW | OBJ_FLAG_UPDATE_GFX_POS_AND_ANGLE)),
     SET_HITBOX(/*Radius*/ 300, /*Height*/ 400),
+    SET_FLOAT(oDrawingDistance, 4500),
     SET_INT(oIntangibleTimer, 0),
     BEGIN_LOOP(),
         CALL_NATIVE(bhv_wf_breakable_wall_loop),

include/config/config_game.h

@@ -58,7 +58,7 @@
 
 // Include the English characters that were missing from US segment2
 // J, Q, V, X, Z, ¨, !, !!, ?, &, %, ., and the beta key.
-// [MAKE SURE TO ALSO BUILD FROM JP/SH AND EU TO OBTAIN THE ASSETS]
+// [MAKE SURE TO HAVE EU AND JP/SH BASEROMS TO OBTAIN THE ASSETS]
 // If this is disabled, backup assets will be used.
 // #define COMPLETE_EN_US_SEGMENT2
 

include/config/config_rom.h

@@ -12,9 +12,6 @@
 // Currently not recommended, as it may cause random crashes.
 //#define ENABLE_RUMBLE (1 || VERSION_SH)
 
-// Clear RAM on boot
-#define CLEARRAM 1
-
 // Screen Size Defines
 #define SCREEN_WIDTH  320
 #define SCREEN_HEIGHT 240

include/level_table.h

@@ -14,8 +14,8 @@ enum LevelNum {
     LEVEL_COUNT,
     LEVEL_MAX = LEVEL_COUNT - 1,
     LEVEL_MIN = LEVEL_NONE + 1,
-    LEVEL_FILE_SELECT  = 100, //! This probably breaks if you have 99+ levels
-    LEVEL_LEVEL_SELECT = (LEVEL_FILE_SELECT + 1)
+    LEVEL_FILE_SELECT = LEVEL_COUNT + 1,
+    LEVEL_LEVEL_SELECT = LEVEL_FILE_SELECT + 1,
 };
 
 #undef STUB_LEVEL

include/sm64.h

@@ -32,28 +32,30 @@
 
 // Common cos values for degrees, often used for surface Y normals
 // These are different than coss()
-#define COS1    0.9998477f
-#define COS5    0.9961947f
-#define COS10   0.9848077f
-#define COS15   0.9659258f
-#define COS20   0.9396926f
-#define COS25   0.9063078f  // ledge grabs
-#define COS30   0.8660254f
-#define COS35   0.85264016f
-#define COS36   0.8443279f
-#define COS38   0.7880108f  // mario_floor_is_slippery default
-#define COS40   0.80901699f
-#define COS45   0.76040596f
-#define COS50   0.70710678f // SURFACE_FLAG_X_PROJECTION
-#define COS55   0.64944805f
-#define COS60   0.58778525f
-#define COS65   0.52249856f
-#define COS70   0.4539905f
+#define COS0    1.0f
+#define COS1    0.99984770f // mario_floor_is_slippery, mario_floor_is_slope
+#define COS5    0.99619470f // mario_floor_is_slope
+#define COS10   0.98480775f // act_butt_slide_air, act_hold_butt_slide_air, mario_floor_is_slippery, mario_floor_is_slope
+#define COS15   0.96592583f // mario_floor_is_slope
+#define COS20   0.93969262f // mario_floor_is_slippery, mario_floor_is_slope, mario_floor_is_steep
+#define COS25   0.90630779f // ledge grabs
+#define COS30   0.86602540f // should_get_stuck_in_ground, mario_floor_is_steep
+#define COS35   0.81915204f
+#define COS36   0.80901699f
+#define COS38   0.78801075f // mario_floor_is_slippery default
+#define COS40   0.76604444f
+#define COS45   0.70710678f // SURFACE_FLAG_X_PROJECTION
+#define COS50   0.64278761f
+#define COS55   0.57357644f
+#define COS60   0.5f
+#define COS65   0.42261826f
+#define COS70   0.34202014f
 #define COS73   0.29237169f // common_landing_cancels, check_common_idle_cancels, check_common_hold_idle_cancels
-#define COS75   0.38268343f
+#define COS75   0.25881905f
 #define COS78   0.20791169f
 #define COS80   0.17364818f // braking action
-#define COS85   0.23344536f
+#define COS85   0.087155743f
+#define COS90   0.0f
 
 enum RenderLayers {
     LAYER_FORCE,

src/boot/main.c

@@ -19,6 +19,7 @@
 #endif
 #include "game/puppyprint.h"
 #include "game/puppylights.h"
+#include "game/profiling.h"
 
 // Message IDs
 enum MessageIDs {
@@ -189,6 +190,7 @@ void start_gfx_sptask(void) {
         rspDelta = osGetTime();
 #endif
         start_sptask(M_GFXTASK);
+        fast_profiler_rsp_started(PROFILER_RSP_GFX);
     }
 }
 
@@ -220,6 +222,7 @@ void handle_vblank(void) {
             } else {
                 pretend_audio_sptask_done();
             }
+            fast_profiler_rsp_started(PROFILER_RSP_AUDIO);
         }
     } else {
         if (gActiveSPTask == NULL
@@ -229,6 +232,7 @@ void handle_vblank(void) {
             rspDelta = osGetTime();
 #endif
             start_sptask(M_GFXTASK);
+            fast_profiler_rsp_started(PROFILER_RSP_GFX);
         }
     }
 #if ENABLE_RUMBLE
@@ -256,6 +260,9 @@ void handle_sp_complete(void) {
 #if PUPPYPRINT_DEBUG
             profiler_update(rspGenTime, rspDelta);
 #endif
+            fast_profiler_rsp_completed(PROFILER_RSP_GFX);
+        } else {
+            fast_profiler_rsp_yielded();
         }
 
         // Start the audio task, as expected by handle_vblank.
@@ -264,12 +271,19 @@ void handle_sp_complete(void) {
         } else {
             pretend_audio_sptask_done();
         }
+        fast_profiler_rsp_started(PROFILER_RSP_AUDIO);
     } else {
         curSPTask->state = SPTASK_STATE_FINISHED;
         if (curSPTask->task.t.type == M_AUDTASK) {
+            fast_profiler_rsp_completed(PROFILER_RSP_AUDIO);
             // After audio tasks come gfx tasks.
             if ((sCurrentDisplaySPTask != NULL)
              && (sCurrentDisplaySPTask->state != SPTASK_STATE_FINISHED)) {
+                if (sCurrentDisplaySPTask->state == SPTASK_STATE_INTERRUPTED) {
+                    fast_profiler_rsp_resumed();
+                } else {
+                    fast_profiler_rsp_started(PROFILER_RSP_GFX);
+                }
                 start_sptask(M_GFXTASK);
             }
             sCurrentAudioSPTask = NULL;
@@ -283,6 +297,7 @@ void handle_sp_complete(void) {
 #if PUPPYPRINT_DEBUG
             profiler_update(rspGenTime, rspDelta);
 #endif
+            fast_profiler_rsp_completed(PROFILER_RSP_GFX);
         }
     }
 }
@@ -478,12 +493,10 @@ void thread1_idle(UNUSED void *arg) {
     }
 }
 
-#if CLEARRAM
-void ClearRAM(void)
-{
+// Clear RAM on boot
+void ClearRAM(void) {
     bzero(_mainSegmentEnd, (size_t)osMemSize - (size_t)OS_K0_TO_PHYSICAL(_mainSegmentEnd));
 }
-#endif
 
 #ifdef ISVPRINT
 extern u32 gISVDbgPrnAdrs;
@@ -502,9 +515,7 @@ void osInitialize_fakeisv() {
 #endif
 
 void main_func(void) {
-#if CLEARRAM
     ClearRAM();
-#endif
     __osInitialize_common();
 #ifdef ISVPRINT
     osInitialize_fakeisv();

src/game/area.c

@@ -25,6 +25,7 @@
 #include "puppyprint.h"
 #include "debug_box.h"
 #include "engine/colors.h"
+#include "profiling.h"
 
 struct SpawnInfo gPlayerSpawnInfos[1];
 struct GraphNode *gGraphNodePointers[MODEL_ID_COUNT];
@@ -434,6 +435,9 @@ void render_game(void) {
 
     gViewportOverride = NULL;
     gViewportClip     = NULL;
+    
+    fast_profiler_update(PROFILER_TIME_GFX);
+    fast_profiler_print_times();
 
 #if PUPPYPRINT_DEBUG
     profiler_update(graphTime, first);

src/game/behaviors/mr_i.inc.c

@@ -76,7 +76,7 @@ void bhv_mr_i_iris_loop(void) {
         obj_build_transform_from_pos_and_angle(o, O_PARENT_RELATIVE_POS_INDEX, O_MOVE_ANGLE_INDEX);
         obj_translate_local(o, O_POS_INDEX, O_PARENT_RELATIVE_POS_INDEX);
         o->oFaceAnglePitch = o->oMoveAnglePitch;
-        o->oGraphYOffset = o->header.gfx.scale[1] * 100.0f;
+        o->oGraphYOffset = o->parentObj->oGraphYOffset;
     }
 
     if (!o->parentObj->oMrIBlinking) {
@@ -128,7 +128,7 @@ void mr_i_body_act_spin_death(void) {
             cur_obj_become_intangible();
             spawn_mist_particles();
             o->oMrIScale = scaleModifier * 0.6f;
-            if (o->oBehParams2ndByte != 0) {
+            if (o->oBehParams2ndByte != MR_I_BP_NORMAL) {
                 o->oPosY += 100.0f;
                 spawn_default_star(1370, 2000.0f, -320.0f);
                 obj_mark_for_deletion(o);

src/game/fasttext.c

@@ -0,0 +1,76 @@
+// This file is a modification of a file from https://github.com/danbolt/n64-jam-1, which was licensed under the MPL-2.0 License
+// See the original repo for more details.
+
+#include <ultra64.h>
+
+#define TEX_ASCII_START '!'
+
+#define G_CC_TEXT PRIMITIVE, 0, TEXEL0, 0, 0, 0, 0, TEXEL0
+
+__asm__(
+ ".section \".rodata\", \"a\", @progbits\n"
+ ".global fastfont\n"
+ "fastfont:\n"
+ ".incbin \"src/game/newfont2_swapped.bin\"\n"
+ ".previous\n"
+);
+
+extern u8 fastfont[];
+
+// Naive strlen copied from
+// https://stackoverflow.com/questions/22520413/c-strlen-implementation-in-one-line-of-code
+void my_strlen(const char *str, u32 *len)
+{
+    for (*len = 0; str[*len]; (*len)++);
+}
+
+int computeS(unsigned char letter) {
+  int idx = letter;  
+  if (letter > 'z') {
+    idx -= (3 + 2 + 3 + 1 + 3);
+  } else if (letter > '^') {
+    idx -= (2 + 3 + 1 + 3);
+  } else if (letter > 'Z') {
+    idx -= (3 + 1 + 3);
+  } else if (letter > '?') {
+    idx -= (1 + 3);
+  } else if (letter > ';') {
+    idx -= (3);
+  }
+
+  return (idx - TEX_ASCII_START) * 8;
+}
+
+void drawSmallString_impl(Gfx **dl, int x, int y, const char* string, int r, int g, int b) {
+  int i = 0;
+  int xPos = x;
+  int yPos = y;
+  int s = 0;
+  Gfx *dlHead = *dl;
+
+  r = g = b = 255;
+  gDPLoadTextureBlock_4bS(dlHead++, fastfont, G_IM_FMT_IA, 672, 12, 0, G_TX_MIRROR | G_TX_WRAP, G_TX_MIRROR | G_TX_WRAP, G_TX_NOMASK, G_TX_NOMASK, G_TX_NOLOD, G_TX_NOLOD);
+  gDPSetPrimColor(dlHead++, 0, 0, r, g, b, 255);
+  gDPSetCombineMode(dlHead++, G_CC_TEXT, G_CC_TEXT);
+  gDPPipeSync(dlHead++);
+  while (string[i] != '\0') {
+    if (string[i] == '\n') {
+      xPos = x;
+      yPos += 12;
+      i++;
+      continue;
+    }
+
+    if (string[i] != ' ') {
+      s = computeS(string[i]);
+      gSPTextureRectangle(dlHead++, (xPos + 0) << 2, (yPos + 0) << 2, (xPos + 8) << 2, (yPos + 12) << 2, 0, s << 5, 0, 1 << 10, 1 << 10);
+    }
+
+    xPos += 8;
+    i++;
+  }
+  gDPSetPrimColor(dlHead++, 0, 0, 255, 255, 255, 255);
+  gDPPipeSync(dlHead++);
+
+  *dl = dlHead;
+}

src/game/fasttext.h

@@ -0,0 +1,14 @@
+#ifndef __FASTTEXT_H__
+#define __FASTTEXT_H__
+
+void drawSmallString_impl(Gfx**, int, int, const char*, int, int , int);
+
+static inline void drawSmallString(Gfx **dl, int x, int y, const char* string) {
+  drawSmallString_impl(dl, x, y, string, 255, 255, 255);
+}
+
+static inline void drawSmallStringCol(Gfx **dl, int x, int y, const char* string, int r, int g, int b) {
+  drawSmallString_impl(dl, x, y, string, r, g, b);
+}
+
+#endif

src/game/game_init.c

@@ -29,6 +29,7 @@
 #include "puppycam2.h"
 #include "debug_box.h"
 #include "vc_check.h"
+#include "profiling.h"
 
 // First 3 controller slots
 struct Controller gControllers[3];
@@ -762,6 +763,7 @@ void thread5_game_loop(UNUSED void *arg) {
     render_init();
 
     while (TRUE) {
+        fast_profiler_frame_setup();
         // If the reset timer is active, run the process to reset the game.
         if (gResetTimer != 0) {
             draw_reset_bars();
@@ -788,6 +790,7 @@ void thread5_game_loop(UNUSED void *arg) {
         audio_game_loop_tick();
         select_gfx_pool();
         read_controller_inputs(THREAD_5_GAME_LOOP);
+        fast_profiler_update(PROFILER_TIME_CONTROLLERS);
         addr = level_script_execute(addr);
 #if !PUPPYPRINT_DEBUG && defined(VISUAL_DEBUG)
         debug_box_input();

src/game/mario_actions_airborne.c

@@ -116,11 +116,12 @@ s32 check_kick_or_dive_in_air(struct MarioState *m) {
     return FALSE;
 }
 
-s32 should_get_stuck_in_ground(struct MarioState *m) {
 #ifdef NO_GETTING_BURIED
+s32 should_get_stuck_in_ground(UNUSED struct MarioState *m) {
     return FALSE;
+}
 #else
-
+s32 should_get_stuck_in_ground(struct MarioState *m) {
     u32 terrainType = m->area->terrainType & TERRAIN_MASK;
     struct Surface *floor = m->floor;
     s32 flags = floor->flags;
@@ -134,8 +135,8 @@ s32 should_get_stuck_in_ground(struct MarioState *m) {
     }
 
     return FALSE;
-#endif
 }
+#endif
 
 s32 check_fall_damage_or_get_stuck(struct MarioState *m, u32 hardFallAction) {
     if (should_get_stuck_in_ground(m)) {

src/game/object_list_processor.c

@@ -21,6 +21,7 @@
 #include "spawn_object.h"
 #include "puppyprint.h"
 #include "puppylights.h"
+#include "profiling.h"
 
 
 /**
@@ -611,6 +612,7 @@ void update_objects(UNUSED s32 unused) {
     OSTime first = osGetTime();
     OSTime colTime = collisionTime[perfIteration];
 #endif
+    fast_profiler_update(PROFILER_TIME_LEVEL_SCRIPT);
 
     // cycleCounts[0] = get_current_clock();
 
@@ -632,6 +634,8 @@ void update_objects(UNUSED s32 unused) {
     // Update spawners and objects with surfaces
     // cycleCounts[2] = get_clock_difference(cycleCounts[0]);
     update_terrain_objects();
+    
+    fast_profiler_update(PROFILER_TIME_OBJECTS1);
 
     // If Mario was touching a moving platform at the end of last frame, apply
     // displacement now
@@ -673,4 +677,6 @@ void update_objects(UNUSED s32 unused) {
     profiler_update(behaviourTime, first);
     behaviourTime[perfIteration] -= collisionTime[perfIteration] - colTime;
 #endif
+    
+    fast_profiler_update(PROFILER_TIME_OBJECTS2);
 }

src/game/profiling.c

@@ -0,0 +1,202 @@
+#include <ultra64.h>
+#include <PR/os_internal_reg.h>
+#include "game_init.h"
+
+#include "profiling.h"
+#include "fasttext.h"
+
+#define RDP_CYCLE_CONV(x) ((10 * (x)) / 625) // 62.5 million cycles per frame
+
+typedef struct {
+    u32 counts[PROFILING_BUFFER_SIZE];
+    u32 total;
+} ProfileTimeData;
+
+ProfileTimeData all_profiling_data[PROFILER_TIME_COUNT];
+
+int profile_buffer_index = -1;
+int rsp_buffer_indices[PROFILER_RSP_COUNT];
+// Holds either the start time if the task is running, or the amount of time the task has run for so far if yielded
+u32 rsp_pending_times[PROFILER_RSP_COUNT];
+u32 prev_start;
+u32 start;
+u32 prev_time;
+u32 audio_start;
+u32 audio_buffer_index;
+u32 preempted_time;
+
+static void buffer_update(ProfileTimeData* data, u32 new, int buffer_index) {
+    u32 old = data->counts[buffer_index];
+    data->total -= old;
+    data->total += new;
+    data->counts[buffer_index] = new;
+}
+
+void fast_profiler_update(enum ProfilerTime which) {
+    u32 cur_time = osGetCount();
+    u32 diff;
+    ProfileTimeData* cur_data = &all_profiling_data[which];
+
+    diff = cur_time - prev_time;
+
+    u32 saved = __osDisableInt();
+    u32 cur_preempted_time = preempted_time;
+    preempted_time = 0;
+    __osRestoreInt(saved);
+    if (cur_preempted_time > 0) {
+        diff -= cur_preempted_time;
+        start += cur_preempted_time;
+    }
+    
+    buffer_update(cur_data, diff, profile_buffer_index);
+    prev_time = cur_time;
+}
+
+void fast_profiler_rsp_started(enum ProfilerRSPTime which) {
+    rsp_pending_times[which] = osGetCount();
+}
+
+void fast_profiler_rsp_completed(enum ProfilerRSPTime which) {
+    ProfileTimeData* cur_data = &all_profiling_data[PROFILER_TIME_RSP_GFX + which];
+    int cur_index = rsp_buffer_indices[which];
+    u32 time = osGetCount() - rsp_pending_times[which];
+    rsp_pending_times[which] = 0;
+
+    buffer_update(cur_data, time, cur_index);
+    cur_index++;
+    if (cur_index >= PROFILING_BUFFER_SIZE) {
+        cur_index = 0;
+    }
+    rsp_buffer_indices[which] = cur_index;
+}
+
+void fast_profiler_rsp_resumed() {
+    rsp_pending_times[PROFILER_RSP_GFX] = osGetCount() - rsp_pending_times[PROFILER_RSP_GFX];
+}
+
+// This ends up being the same math as resumed, so we just use resumed for both
+// void fast_profiler_rsp_yielded() {
+//     rsp_pending_times[PROFILER_RSP_GFX] = osGetCount() - rsp_pending_times[PROFILER_RSP_GFX];
+// }
+
+void fast_profiler_audio_started() {
+    audio_start = osGetCount();
+}
+
+void fast_profiler_audio_completed() {
+    ProfileTimeData* cur_data = &all_profiling_data[PROFILER_TIME_AUDIO];
+    u32 time = osGetCount() - audio_start;
+    u32 cur_index = audio_buffer_index;
+
+    preempted_time = time;
+    buffer_update(cur_data, time, cur_index);
+    cur_index++;
+    if (cur_index >= PROFILING_BUFFER_SIZE) {
+        cur_index = 0;
+    }
+
+    audio_buffer_index = cur_index;
+}
+
+static void update_fps_timer() {
+    u32 diff = start - prev_start;
+
+    buffer_update(&all_profiling_data[PROFILER_TIME_FPS], diff, profile_buffer_index);
+    prev_start = start;
+}
+
+static void update_total_timer() {
+    u32 saved = __osDisableInt();
+    u32 cur_preempted_time = preempted_time;
+    preempted_time = 0;
+    __osRestoreInt(saved);
+
+    prev_time = start + cur_preempted_time;
+    fast_profiler_update(PROFILER_TIME_TOTAL);
+}
+
+static void update_rdp_timers() {
+    u32 tmem = IO_READ(DPC_TMEM_REG);
+    u32 cmd =  IO_READ(DPC_BUFBUSY_REG);
+    u32 pipe = IO_READ(DPC_PIPEBUSY_REG);
+    
+    if (gGlobalTimer > 5) {
+        IO_WRITE(DPC_STATUS_REG, (DPC_CLR_CLOCK_CTR | DPC_CLR_CMD_CTR | DPC_CLR_PIPE_CTR | DPC_CLR_TMEM_CTR));
+    }
+
+    buffer_update(&all_profiling_data[PROFILER_TIME_TMEM], tmem, profile_buffer_index);
+    buffer_update(&all_profiling_data[PROFILER_TIME_CMD], cmd, profile_buffer_index);
+    buffer_update(&all_profiling_data[PROFILER_TIME_PIPE], pipe, profile_buffer_index);
+}
+
+void fast_profiler_print_times() {
+    u32 microseconds[PROFILER_TIME_COUNT];
+    char text_buffer[196];
+
+    update_fps_timer();
+    update_total_timer();
+    update_rdp_timers();
+
+    for (int i = 0; i < PROFILER_TIME_COUNT; i++) {
+        if (i < PROFILER_TIME_TMEM) {
+            microseconds[i] = OS_CYCLES_TO_USEC(all_profiling_data[i].total / PROFILING_BUFFER_SIZE);
+        } else {
+            microseconds[i] = RDP_CYCLE_CONV(all_profiling_data[i].total / PROFILING_BUFFER_SIZE);
+        }
+    }
+
+    sprintf(text_buffer,
+        "FPS:    %5.2f\n"
+        "CPU\n"
+        "CONT: %7d\n"
+        "LEVEL:%7d\n"
+        "OBJ1: %7d\n"
+        "OBJ2: %7d\n"
+        "GFX:  %7d\n"
+        "AUDIO:%7d\n"
+        "TOTAL:%7d\n"
+        "RDP\n"
+        "TMEM: %7d\n"
+        "CMD:  %7d\n"
+        "PIPE: %7d\n"
+        "RSP\n"
+        "GFX:  %7d\n"
+        "AUDIO:%7d\n"
+        "TOTAL:%7d",
+        1000000.0f / microseconds[PROFILER_TIME_FPS],
+        microseconds[PROFILER_TIME_CONTROLLERS],
+        microseconds[PROFILER_TIME_LEVEL_SCRIPT],
+        microseconds[PROFILER_TIME_OBJECTS1],
+        microseconds[PROFILER_TIME_OBJECTS2],
+        microseconds[PROFILER_TIME_GFX],
+        microseconds[PROFILER_TIME_AUDIO] * 2, // audio is 60Hz, so double the average
+        microseconds[PROFILER_TIME_TOTAL] + microseconds[PROFILER_TIME_AUDIO] * 2, // audio time is removed from the main thread profiling, so add it back here
+        microseconds[PROFILER_TIME_TMEM],
+        microseconds[PROFILER_TIME_CMD],
+        microseconds[PROFILER_TIME_PIPE],
+        microseconds[PROFILER_TIME_RSP_GFX],
+        microseconds[PROFILER_TIME_RSP_AUDIO],
+        microseconds[PROFILER_TIME_RSP_GFX] + microseconds[PROFILER_TIME_RSP_AUDIO]
+    );
+
+    Gfx* dlHead = gDisplayListHead;
+    gDPPipeSync(dlHead++);
+    gDPSetCycleType(dlHead++, G_CYC_1CYCLE);
+    gDPSetRenderMode(dlHead++, G_RM_TEX_EDGE, G_RM_TEX_EDGE2);
+    gDPSetTexturePersp(dlHead++, G_TP_NONE);
+    gDPSetTextureFilter(dlHead++, G_TF_POINT);
+    gDPSetTextureLUT(dlHead++, G_TT_NONE);
+    drawSmallStringCol(&dlHead, 10, 10, text_buffer, 0, 0, 0);
+    gDisplayListHead = dlHead;
+}
+
+void fast_profiler_frame_setup() {
+    profile_buffer_index++;
+    preempted_time = 0;
+
+    if (profile_buffer_index >= PROFILING_BUFFER_SIZE) {
+        profile_buffer_index = 0;
+    }
+
+    prev_time = start = osGetCount();
+}

src/game/profiling.h

@@ -0,0 +1,45 @@
+#ifndef __PROFILING_H__
+#define __PROFILING_H__
+
+#include <ultra64.h>
+#include "macros.h"
+
+#define PROFILING_BUFFER_SIZE 64
+
+enum ProfilerTime {
+    PROFILER_TIME_FPS,
+    PROFILER_TIME_CONTROLLERS,
+    PROFILER_TIME_LEVEL_SCRIPT,
+    PROFILER_TIME_OBJECTS1,
+    PROFILER_TIME_OBJECTS2,
+    PROFILER_TIME_GFX,
+    PROFILER_TIME_AUDIO,
+    PROFILER_TIME_TOTAL,
+    PROFILER_TIME_TMEM,
+    PROFILER_TIME_PIPE,
+    PROFILER_TIME_CMD,
+    PROFILER_TIME_RSP_GFX,
+    PROFILER_TIME_RSP_AUDIO,
+    PROFILER_TIME_COUNT,
+};
+
+enum ProfilerRSPTime {
+    PROFILER_RSP_GFX,
+    PROFILER_RSP_AUDIO,
+    PROFILER_RSP_COUNT
+};
+
+void fast_profiler_update(enum ProfilerTime which);
+void fast_profiler_print_times();
+void fast_profiler_frame_setup();
+void fast_profiler_rsp_started(enum ProfilerRSPTime which);
+void fast_profiler_rsp_completed(enum ProfilerRSPTime which);
+void fast_profiler_rsp_resumed();
+void fast_profiler_audio_started();
+void fast_profiler_audio_completed();
+// See profiling.c to see why fast_profiler_rsp_yielded isn't its own function
+static ALWAYS_INLINE void fast_profiler_rsp_yielded() {
+    fast_profiler_rsp_resumed();
+}
+
+#endif