print_n_panic/Microtransactions64
0
0
Fork 0
mirror of https://github.com/Print-and-Panic/Microtransactions64.git synced 2026-01-21 10:17:19 -08:00
Code Issues Packages Projects Releases Wiki Activity

Remove profiler.c

Browse Source 
It's in its own commit, so if you for some reason disagree with this, reverting it is super easy.
This commit is contained in:
Fazana
2021-09-28 17:52:42 +01:00
parent 4ba2285969
commit e562c6543b
10 changed files with 4 additions and 399 deletions
Download Patch File Download Diff File Expand all files Collapse all files

25
src/boot/main.c
View File

@@ -8,7 +8,6 @@
#include "game/game_init.h"
#include "game/memory.h"
#include "game/sound_init.h"
#include "game/profiler.h"
#include "buffers/buffers.h"
#include "segments.h"
#include "game/main.h"
@@ -71,27 +70,14 @@ s8 gDebugLevelSelect = TRUE;
s8 gDebugLevelSelect = FALSE;
#endif
s8 gShowProfiler = FALSE;
s8 gShowDebugText = FALSE;
// unused
void handle_debug_key_sequences(void) {
static u16 sProfilerKeySequence[] = {
U_JPAD, U_JPAD, D_JPAD, D_JPAD, L_JPAD, R_JPAD, L_JPAD, R_JPAD
};
static u16 sDebugTextKeySequence[] = { D_JPAD, D_JPAD, U_JPAD, U_JPAD,
L_JPAD, R_JPAD, L_JPAD, R_JPAD };
static s16 sProfilerKey = 0;
static s16 sDebugTextKey = 0;
if (gPlayer3Controller->buttonPressed != 0) {
if (sProfilerKeySequence[sProfilerKey++] == gPlayer3Controller->buttonPressed) {
if (sProfilerKey == ARRAY_COUNT(sProfilerKeySequence)) {
sProfilerKey = 0, gShowProfiler ^= 1;
}
} else {
sProfilerKey = 0;
}
if (sDebugTextKeySequence[sDebugTextKey++] == gPlayer3Controller->buttonPressed) {
if (sDebugTextKey == ARRAY_COUNT(sDebugTextKeySequence)) {
sDebugTextKey = 0, gShowDebugText ^= 1;
@@ -192,7 +178,6 @@ void interrupt_gfx_sptask(void) {
void start_gfx_sptask(void) {
if (gActiveSPTask == NULL && sCurrentDisplaySPTask != NULL
&& sCurrentDisplaySPTask->state == SPTASK_STATE_NOT_STARTED) {
profiler_log_gfx_time(TASKS_QUEUED);
#if PUPPYPRINT_DEBUG
rspDelta = osGetTime();
#endif
@@ -224,7 +209,6 @@ void handle_vblank(void) {
if (gActiveSPTask != NULL) {
interrupt_gfx_sptask();
} else {
profiler_log_vblank_time();
if (sAudioEnabled) {
start_sptask(M_AUDTASK);
} else {
@@ -234,7 +218,6 @@ void handle_vblank(void) {
} else {
if (gActiveSPTask == NULL && sCurrentDisplaySPTask != NULL
&& sCurrentDisplaySPTask->state != SPTASK_STATE_FINISHED) {
profiler_log_gfx_time(TASKS_QUEUED);
#if PUPPYPRINT_DEBUG
rspDelta = osGetTime();
#endif
@@ -267,11 +250,9 @@ void handle_sp_complete(void) {
#if PUPPYPRINT_DEBUG
profiler_update(rspGenTime, rspDelta);
#endif
profiler_log_gfx_time(RSP_COMPLETE);
}
// Start the audio task, as expected by handle_vblank.
profiler_log_vblank_time();
if (sAudioEnabled) {
start_sptask(M_AUDTASK);
} else {
@@ -281,12 +262,8 @@ void handle_sp_complete(void) {
curSPTask->state = SPTASK_STATE_FINISHED;
if (curSPTask->task.t.type == M_AUDTASK) {
// After audio tasks come gfx tasks.
profiler_log_vblank_time();
if (sCurrentDisplaySPTask != NULL
&& sCurrentDisplaySPTask->state != SPTASK_STATE_FINISHED) {
if (sCurrentDisplaySPTask->state != SPTASK_STATE_INTERRUPTED) {
profiler_log_gfx_time(TASKS_QUEUED);
}
start_sptask(M_GFXTASK);
}
sCurrentAudioSPTask = NULL;
@@ -300,7 +277,6 @@ void handle_sp_complete(void) {
#if PUPPYPRINT_DEBUG
profiler_update(rspGenTime, rspDelta);
#endif
profiler_log_gfx_time(RSP_COMPLETE);
}
}
}
@@ -310,7 +286,6 @@ void handle_dp_complete(void) {
if (sCurrentDisplaySPTask->msgqueue != NULL) {
osSendMesg(sCurrentDisplaySPTask->msgqueue, sCurrentDisplaySPTask->msg, OS_MESG_NOBLOCK);
}
profiler_log_gfx_time(RDP_COMPLETE);
sCurrentDisplaySPTask->state = SPTASK_STATE_FINISHED_DP;
sCurrentDisplaySPTask = NULL;
}

2
src/engine/level_script.c
View File

@@ -13,7 +13,6 @@
#include "game/memory.h"
#include "game/object_helpers.h"
#include "game/object_list_processor.h"
#include "game/profiler.h"
#include "game/save_file.h"
#include "game/sound_init.h"
#include "goddard/renderer.h"
@@ -961,7 +960,6 @@ struct LevelCommand *level_script_execute(struct LevelCommand *cmd) {
LevelScriptJumpTable[sCurrentCmd->type]();
}
profiler_log_thread5_time(LEVEL_SCRIPT_EXECUTE);
init_rcp(CLEAR_ZBUFFER);
render_game();
end_master_display_list();

4
src/game/area.c
View File

@@ -369,7 +369,9 @@ void play_transition_after_delay(s16 transType, s16 time, u8 red, u8 green, u8 b
void render_game(void) {
if (gCurrentArea != NULL && !gWarpTransition.pauseRendering) {
geo_process_root(gCurrentArea->graphNode, gViewportOverride, gViewportClip, gFBSetColor);
if (gCurrentArea->graphNode) {
geo_process_root(gCurrentArea->graphNode, gViewportOverride, gViewportClip, gFBSetColor);
}
gSPViewport(gDisplayListHead++, VIRTUAL_TO_PHYSICAL(&gViewport));

8
src/game/game_init.c
View File

@@ -11,7 +11,6 @@
#include "game_init.h"
#include "main.h"
#include "memory.h"
#include "profiler.h"
#include "save_file.h"
#include "seq_ids.h"
#include "sound_init.h"
@@ -322,9 +321,6 @@ void init_rcp(s32 resetZB) {
*/
void end_master_display_list(void) {
draw_screen_borders();
if (gShowProfiler) {
draw_profiler();
}
gDPFullSync(gDisplayListHead++);
gSPEndDisplayList(gDisplayListHead++);
@@ -415,7 +411,6 @@ void display_and_vsync(void) {
gIsConsole = 1;
gBorderHeight = BORDER_HEIGHT_CONSOLE;
}
profiler_log_thread5_time(BEFORE_DISPLAY_LISTS);
//gIsConsole = (IO_READ(DPC_PIPEBUSY_REG));
osRecvMesg(&gGfxVblankQueue, &gMainReceivedMesg, OS_MESG_BLOCK);
if (gGoddardVblankCallback != NULL) {
@@ -423,10 +418,8 @@ void display_and_vsync(void) {
gGoddardVblankCallback = NULL;
}
exec_display_list(&gGfxPool->spTask);
profiler_log_thread5_time(AFTER_DISPLAY_LISTS);
osRecvMesg(&gGameVblankQueue, &gMainReceivedMesg, OS_MESG_BLOCK);
osViSwapBuffer((void *) PHYSICAL_TO_VIRTUAL(gPhysicalFrameBuffers[sRenderedFramebuffer]));
profiler_log_thread5_time(THREAD5_END);
osRecvMesg(&gGameVblankQueue, &gMainReceivedMesg, OS_MESG_BLOCK);
// Skip swapping buffers on emulator so that they display immediately as the Gfx task finishes
if (gIsConsole || gIsVC) { // Read RDP Clock Register, has a value of zero on emulators
@@ -741,7 +734,6 @@ void thread5_game_loop(UNUSED void *arg) {
draw_reset_bars();
continue;
}
profiler_log_thread5_time(THREAD5_START);
#if PUPPYPRINT_DEBUG
while (TRUE) {
lastTime = osGetTime();

2
src/game/level_update.c
View File

@@ -1335,7 +1335,7 @@ s32 lvl_set_current_level(UNUSED s16 arg0, s32 levelNum) {
return 0;
}
if (gDebugLevelSelect && !gShowProfiler) {
if (gDebugLevelSelect) {
return 0;
}

1
src/game/main.h
View File

@@ -65,7 +65,6 @@ extern u32 gNumVblanks;
extern s8 gResetTimer;
extern s8 gNmiResetBarsTimer;
extern s8 gDebugLevelSelect;
extern s8 gShowProfiler;
extern s8 gShowDebugText;
void set_vblank_handler(s32 index, struct VblankHandler *handler, OSMesgQueue *queue, OSMesg *msg);

1
src/game/object_list_processor.c
View File

@@ -18,7 +18,6 @@
#include "object_helpers.h"
#include "object_list_processor.h"
#include "platform_displacement.h"
#include "profiler.h"
#include "spawn_object.h"
#include "puppyprint.h"
#include "puppylights.h"

306
src/game/profiler.c
View File

@@ -1,306 +0,0 @@
#include <ultra64.h>
#include "sm64.h"
#include "profiler.h"
#include "game_init.h"
s16 gProfilerMode = 0;
// the thread 3 info is logged on the opposite profiler from what is used by
// the thread4 and 5 loggers. It's likely because the sound thread runs at a
// much faster rate and shouldn't be flipping the index for the "slower" game
// threads, which could leave the frame data in a possibly corrupt or incomplete
// state.
s16 gCurrentFrameIndex1 = 1;
s16 gCurrentFrameIndex2 = 0;
struct ProfilerFrameData gProfilerFrameData[2];
// log the current osTime to the appropriate idx for current thread5 processes.
void profiler_log_thread5_time(enum ProfilerGameEvent eventID) {
gProfilerFrameData[gCurrentFrameIndex1].gameTimes[eventID] = osGetTime();
// event ID 4 is the last profiler event for after swapping
// buffers: switch the Info after updating.
if (eventID == THREAD5_END) {
gCurrentFrameIndex1 ^= 1;
gProfilerFrameData[gCurrentFrameIndex1].numSoundTimes = 0;
}
}
// log the audio system before and after osTimes in pairs to the soundTimes array.
void profiler_log_thread4_time(void) {
struct ProfilerFrameData *profiler = &gProfilerFrameData[gCurrentFrameIndex1];
if (profiler->numSoundTimes < ARRAY_COUNT(profiler->soundTimes)) {
profiler->soundTimes[profiler->numSoundTimes++] = osGetTime();
}
}
// log the times for gfxTimes: RSP completes, and RDP completes.
void profiler_log_gfx_time(enum ProfilerGfxEvent eventID) {
if (eventID == TASKS_QUEUED) {
gCurrentFrameIndex2 ^= 1;
gProfilerFrameData[gCurrentFrameIndex2].numVblankTimes = 0;
}
gProfilerFrameData[gCurrentFrameIndex2].gfxTimes[eventID] = osGetTime();
}
// log the times between vblank started and ended.
void profiler_log_vblank_time(void) {
struct ProfilerFrameData *profiler = &gProfilerFrameData[gCurrentFrameIndex2];
if (profiler->numVblankTimes < ARRAY_COUNT(profiler->vblankTimes)) {
profiler->vblankTimes[profiler->numVblankTimes++] = osGetTime();
}
}
// draw the specified profiler given the information passed.
void draw_profiler_bar(OSTime clockBase, OSTime clockStart, OSTime clockEnd, s16 posY, u16 color) {
s64 durationStart, durationEnd;
s32 rectX1, rectX2;
// set the duration to start, and floor to 0 if the result is below 0.
if ((durationStart = clockStart - clockBase) < 0) {
durationStart = 0;
}
// like the above, but with end.
if ((durationEnd = clockEnd - clockBase) < 0) {
durationEnd = 0;
}
// calculate the x coordinates of where start and end begins, respectively.
rectX1 = ((((durationStart * 1000000) / osClockRate * 3) / 1000) + 30);
rectX2 = ((((durationEnd * 1000000) / osClockRate * 3) / 1000) + 30);
//! I believe this is supposed to cap rectX1 and rectX2 to 320, but the
// code seems to use the wrong variables... it's possible that the variable
// names were very similar within a single letter.
if (rectX1 > 319) {
clockStart = 319;
}
if (rectX2 > 319) {
clockEnd = 319;
}
// perform the render if start is less than end. in most cases, it should be.
if (rectX1 < rectX2) {
gDPPipeSync(gDisplayListHead++);
gDPSetFillColor(gDisplayListHead++, color << 16 | color);
gDPFillRectangle(gDisplayListHead++, rectX1, posY, rectX2, posY + 2);
}
}
void draw_reference_profiler_bars(void) {
// Draws the reference "max" bars underneath the real thing.
// Blue
gDPPipeSync(gDisplayListHead++);
gDPSetFillColor(gDisplayListHead++,
GPACK_RGBA5551(40, 80, 255, 1) << 16 | GPACK_RGBA5551(40, 80, 255, 1));
gDPFillRectangle(gDisplayListHead++, 30, 220, 79, 222);
// Yellow
gDPPipeSync(gDisplayListHead++);
gDPSetFillColor(gDisplayListHead++,
GPACK_RGBA5551(255, 255, 40, 1) << 16 | GPACK_RGBA5551(255, 255, 40, 1));
gDPFillRectangle(gDisplayListHead++, 79, 220, 128, 222);
// Orange
gDPPipeSync(gDisplayListHead++);
gDPSetFillColor(gDisplayListHead++,
GPACK_RGBA5551(255, 120, 40, 1) << 16 | GPACK_RGBA5551(255, 120, 40, 1));
gDPFillRectangle(gDisplayListHead++, 128, 220, 177, 222);
// Red
gDPPipeSync(gDisplayListHead++);
gDPSetFillColor(gDisplayListHead++,
GPACK_RGBA5551(255, 40, 40, 1) << 16 | GPACK_RGBA5551(255, 40, 40, 1));
gDPFillRectangle(gDisplayListHead++, 177, 220, 226, 222);
}
/*
Draw Profiler Mode 1. This mode draws a traditional per-event bar for durations of tasks
recorded by the profiler calls of various threads.
Information:
(yellow): Level Scripts Execution
(orange): Rendering
(blue): Display Lists Send
(red): Sound Updates
(yellow): Time from SP tasks queued to RSP complete
(orange): Time from RSP complete to RDP complete (possibly bugged, see //! note below)
(red): VBlank Times
*/
void draw_profiler_mode_1(void) {
s32 i;
struct ProfilerFrameData *profiler;
OSTime clockBase;
// the profiler logs 2 frames of data: last frame and current frame. Indexes are used
// to keep track of the current frame, so the index is xor'd to retrieve the last frame's
// data.
profiler = &gProfilerFrameData[gCurrentFrameIndex1 ^ 1];
// calculate the clockBase.
clockBase = profiler->soundTimes[0] - (16433 * osClockRate / 1000000);
// draw the profiler for the time it takes for level scripts to execute. (yellow)
draw_profiler_bar(clockBase, profiler->gameTimes[0], profiler->gameTimes[1], 212,
GPACK_RGBA5551(255, 255, 40, 1));
// draw the profiler for the time it takes for the game to render (between level scripts and
// pre-display lists). (orange)
draw_profiler_bar(clockBase, profiler->gameTimes[1], profiler->gameTimes[2], 212,
GPACK_RGBA5551(255, 120, 40, 1));
// draw the profiler for the time it takes for the display lists to send. (blue)
draw_profiler_bar(clockBase, profiler->gameTimes[2], profiler->gameTimes[3], 212,
GPACK_RGBA5551(40, 192, 230, 1));
// we need to get the amount of finished numSoundTimes pairs, so get rid of the odd bit to get the
// limit of finished pairs.
profiler->numSoundTimes &= 0xFFFE;
// draw the sound update times. (red)
for (i = 0; i < profiler->numSoundTimes; i += 2) {
draw_profiler_bar(clockBase, profiler->soundTimes[i], profiler->soundTimes[i + 1], 212,
GPACK_RGBA5551(255, 40, 40, 1));
}
//! RSP and RDP run in parallel, so while they are not absolutely guaranteed to return in order,
// it is theoretically possible they might not. In all cases, the RDP should finish later than RSP.
// Thus, this is not really a bug in practice, but should still be noted that the C doesn't check
// this.
draw_profiler_bar(clockBase, profiler->gfxTimes[0], profiler->gfxTimes[1], 216,
GPACK_RGBA5551(255, 255, 40, 1));
// (orange)
draw_profiler_bar(clockBase, profiler->gfxTimes[1], profiler->gfxTimes[2], 216,
GPACK_RGBA5551(255, 120, 40, 1));
// like earlier, toss the odd bit.
profiler->numVblankTimes &= 0xFFFE;
// render the vblank time pairs. (red)
for (i = 0; i < profiler->numVblankTimes; i += 2) {
draw_profiler_bar(clockBase, profiler->vblankTimes[i], profiler->vblankTimes[i + 1], 216,
GPACK_RGBA5551(255, 40, 40, 1));
}
draw_reference_profiler_bars();
}
/*
Draw Profiler Mode 0. This mode renders bars over each other to make it
easier to see which processes take the longest.
Information:
(red): Sound Updates
(yellow): Level Script Execution
(orange): Rendering
(orange): RDP Duration
(yellow): RSP Duration
(red): VBlank Duration
*/
void draw_profiler_mode_0(void) {
s32 i;
struct ProfilerFrameData *profiler;
u64 clockStart;
u64 levelScriptDuration;
u64 renderDuration;
u64 taskStart;
u64 rspDuration;
u64 rdpDuration;
u64 vblank;
u64 soundDuration;
// get the last frame profiler. gCurrentFrameIndex1 has the current frame being processed, so
// xor it to get the last frame profiler.
profiler = &gProfilerFrameData[gCurrentFrameIndex1 ^ 1];
// was thread 5 ran before thread 4? set the lower one to be the clockStart.
clockStart = profiler->gameTimes[0] <= profiler->soundTimes[0] ? profiler->gameTimes[0]
: profiler->soundTimes[0];
// set variables for duration of tasks.
levelScriptDuration = profiler->gameTimes[1] - clockStart;
renderDuration = profiler->gameTimes[2] - profiler->gameTimes[1];
taskStart = 0;
rspDuration = profiler->gfxTimes[1] - profiler->gfxTimes[0];
rdpDuration = profiler->gfxTimes[2] - profiler->gfxTimes[0];
vblank = 0;
// like above functions, toss the odd bit.
profiler->numSoundTimes &= 0xFFFE;
// sound duration seems to be rendered with empty space and not actually drawn.
for (i = 0; i < profiler->numSoundTimes; i += 2) {
// calculate sound duration of max - min
soundDuration = profiler->soundTimes[i + 1] - profiler->soundTimes[i];
taskStart += soundDuration;
// was the sound time minimum less than level script execution?
if (profiler->soundTimes[i] < profiler->gameTimes[1]) {
// overlay the levelScriptDuration onto the profiler by subtracting the soundDuration.
levelScriptDuration -= soundDuration;
} else if (profiler->soundTimes[i] < profiler->gameTimes[2]) {
// overlay the renderDuration onto the profiler by subtracting the soundDuration.
renderDuration -= soundDuration;
}
}
// same as above. toss the odd bit.
profiler->numSoundTimes &= 0xFFFE;
//! wrong index used to retrieve vblankTimes, thus empty pairs can
// potentially be passed to draw_profiler_bar, because it could be sending
// pairs that are beyond the numVblankTimes enforced non-odd limit, due to
// using the wrong num value.
for (i = 0; i < profiler->numSoundTimes; i += 2) {
vblank += (profiler->vblankTimes[i + 1] - profiler->vblankTimes[i]);
}
// Draw top profilers.
// draw sound duration as the first bar. (red)
clockStart = 0;
draw_profiler_bar(0, clockStart, clockStart + taskStart, 212, GPACK_RGBA5551(255, 40, 40, 1));
// draw level script execution duration. (yellow)
clockStart += taskStart;
draw_profiler_bar(0, clockStart, clockStart + levelScriptDuration, 212,
GPACK_RGBA5551(255, 255, 40, 1));
// draw render duration. (orange)
clockStart += levelScriptDuration;
draw_profiler_bar(0, clockStart, clockStart + renderDuration, 212,
GPACK_RGBA5551(255, 120, 40, 1));
// Draw bottom profilers.
// rdp duration (orange)
draw_profiler_bar(0, 0, rdpDuration, 216, GPACK_RGBA5551(255, 120, 40, 1));
// rsp duration (yellow)
draw_profiler_bar(0, 0, rspDuration, 216, GPACK_RGBA5551(255, 255, 40, 1));
// vblank duration (red)
draw_profiler_bar(0, 0, vblank, 216, GPACK_RGBA5551(255, 40, 40, 1));
draw_reference_profiler_bars();
}
// Draw the Profiler per frame. Toggle the mode if the player presses L while this
// renderer is active.
void draw_profiler(void) {
if (gPlayer1Controller->buttonPressed & L_TRIG) {
gProfilerMode ^= 1;
}
if (gProfilerMode == 0) {
draw_profiler_mode_0();
} else {
draw_profiler_mode_1();
}
}

51
src/game/profiler.h
View File

@@ -1,51 +0,0 @@
#ifndef PROFILER_H
#define PROFILER_H
#include <PR/ultratypes.h>
#include <PR/os_time.h>
#include "types.h"
extern u64 osClockRate;
struct ProfilerFrameData {
/* 0x00 */ s16 numSoundTimes;
/* 0x02 */ s16 numVblankTimes;
// gameTimes:
// 0: thread 5 start
// 1: level script execution
// 2: render
// 3: display lists
// 4: thread 4 end (0 terminated)
/* 0x08 */ OSTime gameTimes[5];
// gfxTimes:
// 0: processors queued
// 1: rsp completed
// 2: rdp completed
/* 0x30 */ OSTime gfxTimes[3];
/* 0x48 */ OSTime soundTimes[8];
/* 0x88 */ OSTime vblankTimes[8];
};
// thread event IDs
enum ProfilerGameEvent {
THREAD5_START,
LEVEL_SCRIPT_EXECUTE,
BEFORE_DISPLAY_LISTS,
AFTER_DISPLAY_LISTS,
THREAD5_END
};
enum ProfilerGfxEvent {
TASKS_QUEUED,
RSP_COMPLETE,
RDP_COMPLETE
};
void profiler_log_thread5_time(enum ProfilerGameEvent eventID);
void profiler_log_thread4_time(void);
void profiler_log_gfx_time(enum ProfilerGfxEvent eventID);
void profiler_log_vblank_time(void);
void draw_profiler(void);
#endif // PROFILER_H

3
src/game/sound_init.c
View File

@@ -9,7 +9,6 @@
#include "main.h"
#include "paintings.h"
#include "print.h"
#include "profiler.h"
#include "save_file.h"
#include "seq_ids.h"
#include "sm64.h"
@@ -358,12 +357,10 @@ void thread4_sound(UNUSED void *arg) {
#endif
if (gResetTimer < 25) {
struct SPTask *spTask;
profiler_log_thread4_time();
spTask = create_next_audio_frame_task();
if (spTask != NULL) {
dispatch_audio_sptask(spTask);
}
profiler_log_thread4_time();
#if PUPPYPRINT_DEBUG
profiler_update(audioTime, lastTime);
audioTime[perfIteration] -= dmaAudioTime[perfIteration];