From f0e4dd964bd17b181d35e3a15481354b26946771 Mon Sep 17 00:00:00 2001 From: Arceveti <73617174+Arceveti@users.noreply.github.com> Date: Sun, 26 Sep 2021 12:33:02 -0700 Subject: [PATCH] Add option to display puppyprint debug values as cycles --- include/config.h | 2 + src/audio/heap.c | 4 ++ src/game/hud.c | 7 +--- src/game/level_update.c | 4 ++ src/game/puppyprint.c | 92 ++++++++++++++++++++++++++--------------- 5 files changed, 71 insertions(+), 38 deletions(-) diff --git a/include/config.h b/include/config.h index 2d2eb2eb..18422ac1 100644 --- a/include/config.h +++ b/include/config.h @@ -190,6 +190,8 @@ // Include Puppyprint, a display library for text and large images. Also includes a custom, enhanced performance profiler. //#define PUPPYPRINT #define PUPPYPRINT_DEBUG 0 +// Use cycles instead of microseconds +//#define PUPPYPRINT_DEBUG_CYCLES // Visual debug enables some collision visuals. Tapping Right on the dpad will cycle between visual hitboxes, visual surfaces, both, and neither. // If puppyprint is enabled, then this can be cycled only while the screen is active. //#define VISUAL_DEBUG diff --git a/src/audio/heap.c b/src/audio/heap.c index c87692f2..33c848e5 100644 --- a/src/audio/heap.c +++ b/src/audio/heap.c @@ -1493,7 +1493,11 @@ void audio_reset_session(void) { } #endif #if PUPPYPRINT_DEBUG +#ifdef PUPPYPRINT_DEBUG_CYCLES + append_puppyprint_log("Audio Initialised in %dc.", (s32)(osGetTime() - first)); +#else append_puppyprint_log("Audio Initialised in %dus.", (s32)OS_CYCLES_TO_USEC(osGetTime() - first)); +#endif #endif sAudioFirstBoot = 1; } diff --git a/src/game/hud.c b/src/game/hud.c index 2d949127..4f99deb2 100644 --- a/src/game/hud.c +++ b/src/game/hud.c @@ -35,8 +35,7 @@ u8 curFrameTimeIndex = 0; #include "PR/os_convert.h" // Call once per frame -f32 calculate_and_update_fps() -{ +f32 calculate_and_update_fps() { OSTime newTime = osGetTime(); OSTime oldTime = frameTimes[curFrameTimeIndex]; frameTimes[curFrameTimeIndex] = newTime; @@ -45,12 +44,10 @@ f32 calculate_and_update_fps() if (curFrameTimeIndex >= FRAMETIME_COUNT) curFrameTimeIndex = 0; - return ((f32)FRAMETIME_COUNT * 1000000.0f) / (s32)OS_CYCLES_TO_USEC(newTime - oldTime); } -void print_fps(s32 x, s32 y) -{ +void print_fps(s32 x, s32 y) { f32 fps = calculate_and_update_fps(); char text[14]; diff --git a/src/game/level_update.c b/src/game/level_update.c index a39343bb..840d65de 100644 --- a/src/game/level_update.c +++ b/src/game/level_update.c @@ -1252,7 +1252,11 @@ s32 init_level(void) { #endif #if PUPPYPRINT_DEBUG +#ifdef PUPPYPRINT_DEBUG_CYCLES + append_puppyprint_log("Level loaded in %dc", (s32)(osGetTime() - first)); +#else append_puppyprint_log("Level loaded in %dus", (s32)(OS_CYCLES_TO_USEC(osGetTime() - first))); +#endif #endif return TRUE; } diff --git a/src/game/puppyprint.c b/src/game/puppyprint.c index cb4752f3..7ab328c6 100644 --- a/src/game/puppyprint.c +++ b/src/game/puppyprint.c @@ -139,8 +139,7 @@ void puppyprint_calculate_ram_usage(void) audioPool[6] + audioPool[7] + audioPool[8] + audioPool[9] + audioPool[10] + audioPool[11]; } -void puppyprint_profiler_finished(void) -{ +void puppyprint_profiler_finished(void) { s32 i = 0; benchMark[NUM_BENCH_ITERATIONS] = 0; benchMark[NUM_BENCH_ITERATIONS+1] = 0; @@ -158,37 +157,37 @@ void puppyprint_profiler_finished(void) //RGB colour lookup table for colouring all the funny ram prints. u8 colourChart[33][3] = { - {255, 0, 0}, - {0, 0, 255}, - {0, 255, 0}, - {255, 255, 0}, - {255, 0, 255}, - {255, 127, 0}, - {0, 255, 255}, - {51, 255, 51}, - {255, 153, 153}, - {204, 0, 102}, - {0, 153, 153}, - {153, 255, 153}, - {0, 0, 128}, - {128, 0, 128}, - {218, 165, 32}, - {107, 142, 35}, - {188, 143, 143}, - {210, 105, 30}, - {154, 205, 50}, - {165, 42, 42}, - {255, 105, 180}, - {139, 69, 19}, - {250, 240, 230}, - {95, 158, 160}, - {60, 179, 113}, - {255, 69, 0}, - {128, 0, 0}, - {216, 191, 216}, - {244, 164, 96}, - {176, 196, 222}, - {255, 255, 255}}; + { 255, 0, 0 }, + { 0, 0, 255 }, + { 0, 255, 0 }, + { 255, 255, 0 }, + { 255, 0, 255 }, + { 255, 127, 0 }, + { 0, 255, 255 }, + { 51, 255, 51 }, + { 255, 153, 153 }, + { 204, 0, 102 }, + { 0, 153, 153 }, + { 153, 255, 153 }, + { 0, 0, 128 }, + { 128, 0, 128 }, + { 218, 165, 32 }, + { 107, 142, 35 }, + { 188, 143, 143 }, + { 210, 105, 30 }, + { 154, 205, 50 }, + { 165, 42, 42 }, + { 255, 105, 180 }, + { 139, 69, 19 }, + { 250, 240, 230 }, + { 95, 158, 160 }, + { 60, 179, 113 }, + { 255, 69, 0 }, + { 128, 0, 0 }, + { 216, 191, 216 }, + { 244, 164, 96 }, + { 176, 196, 222 }, + { 255, 255, 255 }}; //Change this to alter the width of the bar at the bottom. #define BAR_LENGTH 200 @@ -366,8 +365,13 @@ void puppyprint_render_profiler(void) s32 perfPercentage[5]; s32 graphPos; s32 prevGraph; +#ifdef PUPPYPRINT_DEBUG_CYCLES + OSTime cpuCount = (cpuTime+audioTime[NUM_PERF_ITERATIONS]+dmaAudioTime[NUM_PERF_ITERATIONS]+faultTime[NUM_PERF_ITERATIONS] + +taskTime[NUM_PERF_ITERATIONS]-profilerTime[NUM_PERF_ITERATIONS]-profilerTime2[NUM_PERF_ITERATIONS]); +#else OSTime cpuCount = OS_CYCLES_TO_USEC(cpuTime+audioTime[NUM_PERF_ITERATIONS]+dmaAudioTime[NUM_PERF_ITERATIONS]+faultTime[NUM_PERF_ITERATIONS] +taskTime[NUM_PERF_ITERATIONS]-profilerTime[NUM_PERF_ITERATIONS]-profilerTime2[NUM_PERF_ITERATIONS]); +#endif OSTime first = osGetTime(); char textBytes[80]; @@ -383,7 +387,11 @@ void puppyprint_render_profiler(void) if (!ramViewer && !benchViewer && !logViewer) { print_fps(16,40); +#ifdef PUPPYPRINT_DEBUG_CYCLES + sprintf(textBytes, "CPU: %dc (%d_)#RSP: %dc (%d_)#RDP: %dc (%d_)", (s32)cpuCount, (s32)(cpuCount/333), (s32)(rspTime), (s32)(rspTime)/333, (s32)(rdpTime), (s32)(rdpTime)/333); +#else sprintf(textBytes, "CPU: %dus (%d_)#RSP: %dus (%d_)#RDP: %dus (%d_)", (s32)cpuCount, (s32)(cpuCount/333), (s32)OS_CYCLES_TO_USEC(rspTime), (s32)OS_CYCLES_TO_USEC(rspTime)/333, (s32)OS_CYCLES_TO_USEC(rdpTime), (s32)OS_CYCLES_TO_USEC(rdpTime)/333); +#endif print_small_text(16, 52, textBytes, PRINT_TEXT_ALIGN_LEFT, PRINT_ALL); sprintf(textBytes, "OBJ: %d/%d", gObjectCounter, OBJECT_POOL_CAPACITY); @@ -406,8 +414,13 @@ void puppyprint_render_profiler(void) { benchmarkTimer--; prepare_blank_box(); +#ifdef PUPPYPRINT_DEBUG_CYCLES + //sprintf(textBytes, "Benchmark: %dus#High: %dc", (s32)(benchMark[NUM_BENCH_ITERATIONS]), (s32)(benchMark[NUM_BENCH_ITERATIONS+1])); + sprintf(textBytes, "Done in %0.000f seconds#Benchmark: %dc#High: %dc", (f32)(benchmarkProgramTimer)*0.000001f, (s32)(benchMark[NUM_BENCH_ITERATIONS]), (s32)(benchMark[NUM_BENCH_ITERATIONS+1])); +#else //sprintf(textBytes, "Benchmark: %dus#High: %dus", (s32)OS_CYCLES_TO_USEC(benchMark[NUM_BENCH_ITERATIONS]), (s32)OS_CYCLES_TO_USEC(benchMark[NUM_BENCH_ITERATIONS+1])); sprintf(textBytes, "Done in %0.000f seconds#Benchmark: %dus#High: %dus", (f32)(benchmarkProgramTimer)*0.000001f, (s32)OS_CYCLES_TO_USEC(benchMark[NUM_BENCH_ITERATIONS]), (s32)OS_CYCLES_TO_USEC(benchMark[NUM_BENCH_ITERATIONS+1])); +#endif render_blank_box(160-(get_text_width(textBytes)/2)-4, 158, 160+(get_text_width(textBytes)/2)+4, 196, 0, 0, 0, 255); print_set_envcolour(255, 255, 255, 255); print_small_text(160, 160, textBytes, PRINT_TEXT_ALIGN_CENTRE, PRINT_ALL); @@ -422,6 +435,18 @@ void puppyprint_render_profiler(void) perfPercentage[4] = MAX((dmaTime[NUM_PERF_ITERATIONS]/ADDTIMES), 1); #undef ADDTIMES +#ifdef PUPPYPRINT_DEBUG_CYCLES + sprintf(textBytes, "Collision: %dc", (s32)(collisionTime[NUM_PERF_ITERATIONS])); + print_small_text(304, 40, textBytes, PRINT_TEXT_ALIGN_RIGHT, PRINT_ALL); + sprintf(textBytes, "Graph: %dc", (s32)(graphTime[NUM_PERF_ITERATIONS])); + print_small_text(304, 52, textBytes, PRINT_TEXT_ALIGN_RIGHT, PRINT_ALL); + sprintf(textBytes, "Behaviour: %dc", (s32)(behaviourTime[NUM_PERF_ITERATIONS])); + print_small_text(304, 64, textBytes, PRINT_TEXT_ALIGN_RIGHT, PRINT_ALL); + sprintf(textBytes, "Audio: %dc", (s32)(audioTime[NUM_PERF_ITERATIONS])); + print_small_text(304, 76, textBytes, PRINT_TEXT_ALIGN_RIGHT, PRINT_ALL); + sprintf(textBytes, "DMA: %dc", (s32)(dmaTime[NUM_PERF_ITERATIONS])); + print_small_text(304, 88, textBytes, PRINT_TEXT_ALIGN_RIGHT, PRINT_ALL); +#else sprintf(textBytes, "Collision: %dus", (s32)OS_CYCLES_TO_USEC(collisionTime[NUM_PERF_ITERATIONS])); print_small_text(304, 40, textBytes, PRINT_TEXT_ALIGN_RIGHT, PRINT_ALL); sprintf(textBytes, "Graph: %dus", (s32)OS_CYCLES_TO_USEC(graphTime[NUM_PERF_ITERATIONS])); @@ -432,6 +457,7 @@ void puppyprint_render_profiler(void) print_small_text(304, 76, textBytes, PRINT_TEXT_ALIGN_RIGHT, PRINT_ALL); sprintf(textBytes, "DMA: %dus", (s32)OS_CYCLES_TO_USEC(dmaTime[NUM_PERF_ITERATIONS])); print_small_text(304, 88, textBytes, PRINT_TEXT_ALIGN_RIGHT, PRINT_ALL); +#endif //Render CPU breakdown bar. prepare_blank_box();