Show bottleneck on profile output

This commit is contained in:
Ryan Dwyer
2023-05-03 23:01:00 +10:00
parent f54c812fdf
commit 6b016ffd4f
5 changed files with 96 additions and 139 deletions
+14 -3
View File
@@ -914,6 +914,8 @@ Gfx *lvPrintCounter(Gfx *gdl, s32 *y, char *label, u32 cycles, u32 cycles_per_se
return gdl;
}
extern u8 g_ScBottleneck;
Gfx *lvPrintRateText(Gfx *gdl)
{
if (g_FontHandelGothicXs) {
@@ -959,7 +961,6 @@ Gfx *lvPrintRateText(Gfx *gdl)
gdl = textRender(gdl, &x, &y, buffer, g_CharsHandelGothicXs, g_FontHandelGothicXs, 0x00ff00a0, 0x000000a0, viGetWidth(), viGetHeight(), 0, 0);
}
#ifdef PROFILING
{
u32 counters[5];
@@ -971,11 +972,21 @@ Gfx *lvPrintRateText(Gfx *gdl)
gdl = lvPrintCounter(gdl, &y, " audio", counters[2], OS_CPU_COUNTER);
gdl = lvPrintCounter(gdl, &y, " main", counters[3], OS_CPU_COUNTER);
gdl = lvPrintCounter(gdl, &y, " sched", counters[4], OS_CPU_COUNTER);
gdl = textRender(gdl, &x, &y, "\n", g_CharsHandelGothicXs, g_FontHandelGothicXs, 0x00ff00a0, 0x000000a0, viGetWidth(), viGetHeight(), 0, 0);
}
#endif
x = 10;
sprintf(buffer, "\nmema free %d KB\n", memaGetLongestFree() / 1024);
if (g_ScBottleneck == 'C') {
gdl = textRender(gdl, &x, &y, "bottleneck CPU\n\n", g_CharsHandelGothicXs, g_FontHandelGothicXs, 0x3333ffa0, 0x000000a0, viGetWidth(), viGetHeight(), 0, 0);
} else if (g_ScBottleneck == 'R') {
gdl = textRender(gdl, &x, &y, "bottleneck RDP\n\n", g_CharsHandelGothicXs, g_FontHandelGothicXs, 0xff0000a0, 0x000000a0, viGetWidth(), viGetHeight(), 0, 0);
} else if (g_ScBottleneck == 'V') {
gdl = textRender(gdl, &x, &y, "bottleneck VI\n\n", g_CharsHandelGothicXs, g_FontHandelGothicXs, 0x00ff00a0, 0x000000a0, viGetWidth(), viGetHeight(), 0, 0);
}
sprintf(buffer, "mema free %d KB\n", memaGetLongestFree() / 1024);
gdl = textRender(gdl, &x, &y, buffer, g_CharsHandelGothicXs, g_FontHandelGothicXs, 0x00ff00a0, 0x000000a0, viGetWidth(), viGetHeight(), 0, 0);
sprintf(buffer, "memp free %d KB\n", mempGetStageFree() / 1024);
-10
View File
@@ -3510,20 +3510,10 @@ enum profilemarker {
PROFILEMARKER_TMP,
NUM_PROFILEMARKERS
};
enum rspevent {
RSPEVENT_AUD_START,
RSPEVENT_AUD_FINISH,
RSPEVENT_GFX_START,
RSPEVENT_GFX_PAUSE,
RSPEVENT_GFX_RESUME,
RSPEVENT_GFX_FINISH
};
#else
#define PROFILE(marker, code) code
#define profileStart(marker)
#define profileEnd(marker)
#define profileHandleRspEvent(event)
#endif
#define PROJECTILEFLAG_AIRBORNE 0x00000001
+9 -2
View File
@@ -4,16 +4,23 @@
#include "data.h"
#include "types.h"
enum rspevent {
RSPEVENT_AUD_START,
RSPEVENT_AUD_FINISH,
RSPEVENT_GFX_START,
RSPEVENT_GFX_FINISH
};
void profileInit(void);
void profileTick(void);
void profileReset(void);
void profile00009a98(void);
void profileHandleRspEvent(s32 event);
void profileGetCounters(u32 counters[5]);
#ifdef PROFILING
void profileStart(s32 arg0);
void profileEnd(s32 arg0);
void profileHandleRspEvent(s32 event);
void profileGetCounters(u32 counters[5]);
#endif
Gfx *profileRender(Gfx *gdl);
+69 -124
View File
@@ -3,21 +3,84 @@
#include "bss.h"
#include "data.h"
#include "game/game_1531a0.h"
#include "lib/profile.h"
#include "lib/vi.h"
#include "types.h"
#define NUM_SAMPLES 32
u32 g_ProfileAudStart;
u32 g_ProfileAudCycles;
u32 g_ProfileGfxCycles;
extern OSThread g_SchedThread;
u32 profileReadCounters(void)
{
u32 buf = IO_READ(DPC_BUFBUSY_REG);
u32 tmm = IO_READ(DPC_TMEM_REG);
u32 bus = IO_READ(DPC_PIPEBUSY_REG);
u32 max;
max = buf > tmm ? buf : tmm;
max = bus > max ? bus : max;
return max;
}
void profileGetCounters(u32 counters[5])
{
s32 i;
OSPri prevpri = osGetThreadPri(0);
osSetThreadPri(0, THREADPRI_SCHED + 1);
// RSP
counters[0] = g_ProfileAudCycles;
// RDP
counters[1] = g_ProfileGfxCycles;
// Audio thread
counters[2] = g_AudioManager.thread.cycles_saved;
g_AudioManager.thread.cycles_saved = 0;
// Main thread
counters[3] = g_MainThread.cycles_saved + (osGetCount() - g_MainThread.cycles_at_dispatch);
g_MainThread.cycles_saved = 0;
g_MainThread.cycles_at_dispatch = osGetCount();
// Scheduler thread
counters[4] = g_SchedThread.cycles_saved;
g_SchedThread.cycles_saved = 0;
osSetThreadPri(0, prevpri);
}
void profileHandleRspEvent(s32 event)
{
switch (event) {
case RSPEVENT_AUD_START:
g_ProfileAudStart = osGetCount();
break;
case RSPEVENT_AUD_FINISH:
g_ProfileAudCycles = osGetCount() - g_ProfileAudStart;
break;
case RSPEVENT_GFX_START:
osDpSetStatus(DPC_CLR_CMD_CTR | DPC_CLR_PIPE_CTR | DPC_CLR_TMEM_CTR);
break;
case RSPEVENT_GFX_FINISH:
g_ProfileGfxCycles = profileReadCounters();
break;
}
}
#ifdef PROFILING
#define NUM_SAMPLES 32
// [x][x][0] is the current ticks tally (for multiple start + stops within one frame)
// [x][x][1] is the start time
u32 g_ProfileMarkers[NUM_SAMPLES][NUM_PROFILEMARKERS][2];
s32 g_ProfileIndex = 0;
u32 g_ProfileAudStart;
u32 g_ProfileAudCycles;
u32 g_ProfileGfxCycles;
u32 g_ProfileGfxHistory[30];
u32 g_ProfileGfxIndex = 0;
struct profileslot *g_ProfileCurrentSlot;
struct profileslot {
@@ -123,124 +186,6 @@ void profileEnd(s32 marker)
g_ProfileMarkers[g_ProfileIndex][marker][0] += osGetCount() - g_ProfileMarkers[g_ProfileIndex][marker][1];
}
u32 profileReadCounters(void)
{
u32 buf = IO_READ(DPC_BUFBUSY_REG);
u32 tmm = IO_READ(DPC_TMEM_REG);
u32 bus = IO_READ(DPC_PIPEBUSY_REG);
u32 max;
max = buf > tmm ? buf : tmm;
max = bus > max ? bus : max;
return max;
}
extern OSThread g_SchedThread;
void profileGetCounters(u32 counters[5])
{
s32 i;
u32 max = 0;
OSPri prevpri = osGetThreadPri(0);
osSetThreadPri(0, THREADPRI_SCHED + 1);
// RSP
counters[0] = g_ProfileAudCycles;
// RDP
for (i = 0; i < ARRAYCOUNT(g_ProfileGfxHistory); i++) {
if (g_ProfileGfxHistory[i] > max) {
max = g_ProfileGfxHistory[i];
}
}
counters[1] = g_ProfileGfxCycles;
// Audio thread
counters[2] = g_AudioManager.thread.cycles_saved;
g_AudioManager.thread.cycles_saved = 0;
// Main thread
counters[3] = g_MainThread.cycles_saved + (osGetCount() - g_MainThread.cycles_at_dispatch);
g_MainThread.cycles_saved = 0;
g_MainThread.cycles_at_dispatch = osGetCount();
// Scheduler thread
counters[4] = g_SchedThread.cycles_saved;
g_SchedThread.cycles_saved = 0;
osSetThreadPri(0, prevpri);
}
void profileHandleRspEvent(s32 event)
{
switch (event) {
case RSPEVENT_AUD_START:
g_ProfileAudStart = osGetCount();
break;
case RSPEVENT_AUD_FINISH:
g_ProfileAudCycles = osGetCount() - g_ProfileAudStart;
break;
case RSPEVENT_GFX_START:
osDpSetStatus(DPC_CLR_CMD_CTR | DPC_CLR_PIPE_CTR | DPC_CLR_TMEM_CTR);
break;
case RSPEVENT_GFX_FINISH:
g_ProfileGfxCycles = profileReadCounters();
g_ProfileGfxHistory[g_ProfileGfxIndex] = g_ProfileGfxCycles;
g_ProfileGfxIndex = (g_ProfileGfxIndex + 1) % ARRAYCOUNT(g_ProfileGfxHistory);
break;
}
}
Gfx *profileRenderRdpLine(Gfx *gdl, s32 x, s32 *y, char *label, u32 *ticksarray)
{
char buffer[64];
s32 percent;
u32 colour;
u32 microseconds;
s32 textwidth;
s32 textheight;
s32 x2;
u32 ticks = 0;
s32 i;
for (i = 0; i < NUM_SAMPLES; i++) {
ticks += ticksarray[i];
}
ticks /= NUM_SAMPLES;
percent = ticks * 100 / (62500000 / 60);
microseconds = ticks * 10 / 625;
if (percent >= 100) {
colour = 0xff0000a0;
} else if (percent >= 80) {
colour = 0xffff00a0;
} else {
colour = 0x00ff00a0;
}
x2 = x;
gdl = textRender(gdl, &x2, y, label, g_CharsHandelGothicXs, g_FontHandelGothicXs, colour, 0x000000a0, viGetWidth(), viGetHeight(), 0, 0);
sprintf(buffer, "%d", microseconds);
textMeasure(&textheight, &textwidth, buffer, g_CharsHandelGothicXs, g_FontHandelGothicXs, 0);
x2 = x + 100 - textwidth;
gdl = textRender(gdl, &x2, y, buffer, g_CharsHandelGothicXs, g_FontHandelGothicXs, colour, 0x000000a0, viGetWidth(), viGetHeight(), 0, 0);
sprintf(buffer, "%d%%\n", percent);
textMeasure(&textheight, &textwidth, buffer, g_CharsHandelGothicXs, g_FontHandelGothicXs, 0);
x2 = x + 130 - textwidth;
gdl = textRender(gdl, &x2, y, buffer, g_CharsHandelGothicXs, g_FontHandelGothicXs, colour, 0x000000a0, viGetWidth(), viGetHeight(), 0, 0);
return gdl;
}
Gfx *profileRenderCpuLine(Gfx *gdl, s32 x, s32 *y, char *label, s32 marker)
{
char buffer[64];
+4
View File
@@ -33,6 +33,7 @@ s32 var8008de0c;
s32 var8008de10;
u32 var8008de14;
OSTimer g_SchedRspTimer;
u8 g_ScBottleneck = ' ';
s32 var8005ce74 = 0;
f32 g_ViXScalesBySlot[2] = {1, 1};
@@ -292,8 +293,11 @@ void schedSubmitGfxTask(OSSched *sc, OSScTask *t)
t->state = OS_SC_NEEDS_RSP | OS_SC_NEEDS_RDP;
if (sc->curRSPTask == NULL && sc->curRDPTask == NULL && sc->queuedFB == NULL) {
g_ScBottleneck = 'C';
__scExec(sc, t);
} else {
g_ScBottleneck = sc->queuedFB ? 'V' : 'R';
if (sc->nextGfxTask == NULL) {
sc->nextGfxTask = t;
} else {