Hri7566
/
sm64coopdx
1
0
Fork 0
Code Issues Pull Requests Packages Projects Releases Wiki Activity

Added profiling to more places to make lag easier to track down

This commit is contained in:
MysterD 2023-04-30 17:39:45 -07:00
parent b2a17a018d
commit 01d91ff07d
24 changed files with 207 additions and 10 deletions
Show Stats Download Patch File Download Diff File Expand all files Collapse all files

1
include/types.h
View File

@ -229,6 +229,7 @@ struct Object
/*?????*/ struct Object* usingObj;
/*?????*/ u8 hookRender;
/*?????*/ u8 setHome;
/*?????*/ u8 ctx;
};
struct ObjectHitbox

1
lang/Dutch.ini
View File

@ -231,6 +231,7 @@ PLAY_VANILLA_DEMOS = "Speel normale demos af"
DEBUG_TITLE = "DEBUG"
FIXED_COLLISIONS = "vaste botsingen"
LUA_PROFILER = "Lua Profiler"
CTX_PROFILER = "Ctx Profiler"
DEBUG_PRINT = "Debug Print"
DEBUG_INFO = "Debug Informatie"
DEBUG_ERRORS = "Debug Errors"

1
lang/English.ini
View File

@ -232,6 +232,7 @@ PLAY_VANILLA_DEMOS = "Play Vanilla Demos"
DEBUG_TITLE = "DEBUG"
FIXED_COLLISIONS = "Fixed Collisions"
LUA_PROFILER = "Lua Profiler"
CTX_PROFILER = "Ctx Profiler"
DEBUG_PRINT = "Debug Print"
DEBUG_INFO = "Debug Info"
DEBUG_ERRORS = "Debug Errors"

1
lang/French.ini
View File

@ -232,6 +232,7 @@ PLAY_VANILLA_DEMOS = "Jouer les démos"
DEBUG_TITLE = "DÉBOGAGE"
FIXED_COLLISIONS = "Collisions Améliorées"
LUA_PROFILER = "Profileur Lua"
CTX_PROFILER = "Profileur Ctx"
DEBUG_PRINT = "Affichage du Débogage"
DEBUG_INFO = "Infos de Débogage"
DEBUG_ERRORS = "Erreurs de Débogage"

1
lang/German.ini
View File

@ -232,6 +232,7 @@ PLAY_VANILLA_DEMOS = "Vanilla Demos spielen"
DEBUG_TITLE = "DEBUG"
FIXED_COLLISIONS = "Feste Kollision"
LUA_PROFILER = "Lua Profiler"
CTX_PROFILER = "Ctx Profiler"
DEBUG_PRINT = "Debug Druck"
DEBUG_INFO = "Debug Info"
DEBUG_ERRORS = "Debug Fehler"

1
lang/Italian.ini
View File

@ -229,6 +229,7 @@ PLAY_VANILLA_DEMOS = "Riproduci le demo di gioco"
DEBUG_TITLE = "DEBUG"
FIXED_COLLISIONS = "Collisioni Aggiustate"
LUA_PROFILER = "Profiler Lua"
CTX_PROFILER = "Profiler Ctx"
DEBUG_PRINT = "Stampa di debug"
DEBUG_INFO = "Info di debug"
DEBUG_ERRORS = "Errori di debug"

1
lang/Portuguese.ini
View File

@ -232,6 +232,7 @@ PLAY_VANILLA_DEMOS = "Tocar Demos do Vanilla"
DEBUG_TITLE = "DEBUG"
FIXED_COLLISIONS = "Colisão Consertada"
LUA_PROFILER = "Lua Profiler"
CTX_PROFILER = "Ctx Profiler"
DEBUG_PRINT = "Debug Print"
DEBUG_INFO = "Debug Info"
DEBUG_ERRORS = "Debug Errors"

1
lang/Russian.ini
View File

@ -231,6 +231,7 @@ PLAY_VANILLA_DEMOS = "Воспроизведение демоверсий"
DEBUG_TITLE = "DEBUG"
FIXED_COLLISIONS = "Фиксированные столкновения"
LUA_PROFILER = "Профайлер Lua"
CTX_PROFILER = "Профайлер Ctx"
DEBUG_PRINT = "Отладочная печать"
DEBUG_INFO = "Отладочная информация"
DEBUG_ERRORS = "Ошибки отладки"

1
lang/Spanish.ini
View File

@ -232,6 +232,7 @@ PLAY_VANILLA_DEMOS = "Demos originales"
DEBUG_TITLE = "DEPURACIÓN"
FIXED_COLLISIONS = "Colisiones Arregladas"
LUA_PROFILER = "Perfilador de Lua"
CTX_PROFILER = "Perfilador de Ctx"
DEBUG_PRINT = "Mensajes de Depuración"
DEBUG_INFO = "Información de Depuración"
DEBUG_ERRORS = "Errores de Depuración"

9
src/engine/level_script.c
View File

@ -25,9 +25,10 @@
#include "surface_collision.h"
#include "surface_load.h"
#include "level_table.h"
#include "src/pc/lua/utils/smlua_model_utils.h"
#include "src/pc/lua/smlua.h"
#include "src/pc/djui/djui.h"
#include "pc/lua/utils/smlua_model_utils.h"
#include "pc/lua/smlua.h"
#include "pc/djui/djui.h"
#include "pc/debug_context.h"
#include "game/hardcoded.h"
#include "menu/intro_geo.h"
@ -1134,6 +1135,7 @@ struct LevelCommand *level_script_execute(struct LevelCommand *cmd) {
sScriptStatus = SCRIPT_RUNNING;
sCurrentCmd = cmd;
CTX_BEGIN(CTX_LEVEL_SCRIPT);
while (sScriptStatus == SCRIPT_RUNNING) {
sCurrentCmd = dynos_swap_cmd(sCurrentCmd);
void *dynosCurrCmd = (void *) sCurrentCmd;
@ -1141,6 +1143,7 @@ struct LevelCommand *level_script_execute(struct LevelCommand *cmd) {
void *dynosNextCmd = dynos_update_cmd(dynosCurrCmd);
if (dynosNextCmd) sCurrentCmd = dynosNextCmd;
}
CTX_END(CTX_LEVEL_SCRIPT);
profiler_log_thread5_time(LEVEL_SCRIPT_EXECUTE);
init_render_image();

5
src/game/hud.c
View File

@ -692,6 +692,11 @@ void render_hud(void) {
extern void lua_profiler_update_counters();
lua_profiler_update_counters();
}
extern bool configCtxProfiler;
if (configCtxProfiler) {
extern void ctx_profiler_update_counters();
ctx_profiler_update_counters();
}
#endif
}
}

5
src/game/spawn_object.c
View File

@ -15,6 +15,7 @@
#include "types.h"
#include "pc/network/network.h"
#include "pc/lua/smlua_hooks.h"
#include "pc/debug_context.h"
/**
* An unused linked list struct that seems to have been replaced by ObjectNode.
@ -108,6 +109,10 @@ struct Object *try_allocate_object(struct ObjectNode *destList, struct ObjectNod
geo_remove_child(&nextObj->gfx.node);
geo_add_child(&gObjParentGraphNode, &nextObj->gfx.node);
((struct Object *)nextObj)->ctx = 0
| ((u8)CTX_WITHIN(CTX_LEVEL_SCRIPT) << 0)
| ((u8)CTX_WITHIN(CTX_HOOK) << 1);
return (struct Object *) nextObj;
}

2
src/pc/configfile.c
View File

@ -143,6 +143,7 @@ unsigned int configDrawDistance = 5;
bool configDisablePopups = 0;
#if defined(DEVELOPMENT)
bool configLuaProfiler = 0;
bool configCtxProfiler = 0;
#endif
bool configDisableDownloadedModels = 0;
unsigned int configInterpolationMode = 1;
@ -253,6 +254,7 @@ static const struct ConfigOption options[] = {
{.name = "disable_popups", .type = CONFIG_TYPE_BOOL , .boolValue = &configDisablePopups},
#if defined(DEVELOPMENT)
{.name = "lua_profiler", .type = CONFIG_TYPE_BOOL , .boolValue = &configLuaProfiler},
{.name = "ctx_profiler", .type = CONFIG_TYPE_BOOL , .boolValue = &configCtxProfiler},
#endif
{.name = "disable_downloaded_models", .type = CONFIG_TYPE_BOOL , .boolValue = &configDisableDownloadedModels},
{.name = "interpolation_mode", .type = CONFIG_TYPE_UINT , .uintValue = &configInterpolationMode},

1
src/pc/configfile.h
View File

@ -102,6 +102,7 @@ extern unsigned int configDrawDistance;
extern bool configDisablePopups;
#if defined(DEVELOPMENT)
extern bool configLuaProfiler;
extern bool configCtxProfiler;
#endif
extern bool configDisableDownloadedModels;
extern unsigned int configInterpolationMode;

103
src/pc/debug_context.c Normal file
View File

@ -0,0 +1,103 @@
#include <PR/ultratypes.h>
#include "utils/misc.h"
#include "debug_context.h"
#include "debuglog.h"
#include "game/print.h"
#include "game/hud.h"
static u32 sCtxDepth[CTX_MAX] = { 0 };
#ifdef DEVELOPMENT
static f64 sCtxTime[CTX_MAX] = { 0 };
#define MAX_TIME_STACK 16
static f64 sCtxStartTimeStack[MAX_TIME_STACK] = { 0 };
static u32 sCtxStackIndex = 0;
static char* sDebugContextNames[] = {
"NONE",
"FRAME",
"NET",
"INTERP",
"GAME",
"SMLUA",
"AUDIO",
"RENDER",
"LEVEL",
"HOOK",
"MAX",
};
#endif
void debug_context_begin(enum DebugContext ctx) {
sCtxDepth[ctx]++;
#ifdef DEVELOPMENT
if (sCtxStackIndex < MAX_TIME_STACK) {
sCtxStartTimeStack[sCtxStackIndex] = clock_elapsed_f64();
} else {
LOG_ERROR("Exceeded time stack!");
}
sCtxStackIndex++;
#endif
}
void debug_context_end(enum DebugContext ctx) {
sCtxDepth[ctx]--;
#ifdef DEVELOPMENT
sCtxStackIndex--;
if (sCtxStackIndex < MAX_TIME_STACK) {
sCtxTime[ctx] += clock_elapsed_f64() - sCtxStartTimeStack[sCtxStackIndex];
}
#endif
}
void debug_context_reset(void) {
for (int i = 0; i < CTX_MAX; i++) {
if (sCtxDepth[i]) { LOG_ERROR("Context was not zero on reset: %u", i); }
sCtxDepth[i] = 0;
#ifdef DEVELOPMENT
sCtxTime[i] = 0;
#endif
}
}
bool debug_context_within(enum DebugContext ctx) {
if (ctx > CTX_MAX) { return false; }
return sCtxDepth[ctx] > 0;
}
#ifdef DEVELOPMENT
void ctx_profiler_update_counters() {
s32 y = SCREEN_HEIGHT - 60;
for (s32 i = 1; i < CTX_MAX; i++) {
const char *name = sDebugContextNames[i];
s32 counterUs = (s32) (sCtxTime[i] * 1000000.0);
char text[256];
snprintf(text, 256, " %05d", counterUs);
memcpy(text, name, MIN(12, strlen(name)));
for (s32 j = 0; j != 12; ++j) {
char c = text[j];
if (c >= 'a' && c <= 'z') c -= ('a' - 'A');
if (c == 'J') c = 'I';
if (c == 'Q') c = 'O';
if (c == 'V') c = 'U';
if (c == 'X') c = '*';
if (c == 'Z') c = '2';
if ((c < '0' || c > '9') && (c < 'A' || c > 'Z')) c = ' ';
text[j] = c;
}
print_text(gfx_dimensions_rect_from_left_edge(4), y, text);
y -= 18;
}
}
#endif

27
src/pc/debug_context.h Normal file
View File

@ -0,0 +1,27 @@
#pragma once
#include <stdbool.h>
#define CTX_BEGIN(_ctx) debug_context_begin(_ctx)
#define CTX_END(_ctx) debug_context_end(_ctx)
#define CTX_WITHIN(_ctx) debug_context_within(_ctx)
enum DebugContext {
CTX_NONE,
CTX_FRAME,
CTX_NETWORK,
CTX_INTERP,
CTX_GAME_LOOP,
CTX_SMLUA,
CTX_AUDIO,
CTX_RENDER,
CTX_LEVEL_SCRIPT,
CTX_HOOK,
CTX_MAX,
// MUST BE KEPT IN SYNC WITH sDebugContextNames
};
void debug_context_begin(enum DebugContext ctx);
void debug_context_end(enum DebugContext ctx);
void debug_context_reset(void);
bool debug_context_within(enum DebugContext ctx);

1
src/pc/djui/djui_panel_join_lobbies.c
View File

@ -74,6 +74,7 @@ void djui_panel_join_lobby(struct DjuiBase* caller) {
void djui_panel_join_query(uint64_t aLobbyId, UNUSED uint64_t aOwnerId, uint16_t aConnections, uint16_t aMaxConnections, UNUSED const char* aGame, const char* aVersion, const char* aHostName, const char* aMode, const char* aDescription) {
if (!sLobbyLayout) { return; }
if (aMaxConnections > MAX_PLAYERS) { return; }
char playerText[64] = "";
snprintf(playerText, 63, "%u/%u", aConnections, aMaxConnections);

1
src/pc/djui/djui_panel_misc.c
View File

@ -15,6 +15,7 @@ void djui_panel_options_debug_create(struct DjuiBase* caller) {
{
djui_checkbox_create(body, DLANG(MISC, FIXED_COLLISIONS), (bool*)&gLevelValues.fixCollisionBugs, NULL);
djui_checkbox_create(body, DLANG(MISC, LUA_PROFILER), &configLuaProfiler, NULL);
djui_checkbox_create(body, DLANG(MISC, CTX_PROFILER), &configCtxProfiler, NULL);
djui_checkbox_create(body, DLANG(MISC, DEBUG_PRINT), &configDebugPrint, NULL);
djui_checkbox_create(body, DLANG(MISC, DEBUG_INFO), &configDebugInfo, NULL);
djui_checkbox_create(body, DLANG(MISC, DEBUG_ERRORS), &configDebugError, NULL);

5
src/pc/lua/smlua_hooks.c
View File

@ -5,6 +5,7 @@
#include "pc/djui/djui_chat_message.h"
#include "pc/crash_handler.h"
#include "src/game/hud.h"
#include "pc/debug_context.h"
#if defined(DEVELOPMENT)
#include "../mods/mods.h"
@ -97,7 +98,11 @@ int smlua_call_hook(lua_State* L, int nargs, int nresults, int errfunc, struct M
lua_profiler_start_counter(activeMod);
}
#endif
CTX_BEGIN(CTX_HOOK);
int rc = smlua_pcall(L, nargs, nresults, errfunc);
CTX_END(CTX_HOOK);
#if defined(DEVELOPMENT)
if (configLuaProfiler) {
lua_profiler_stop_counter(activeMod);

4
src/pc/network/coopnet/coopnet.c
View File

@ -14,7 +14,11 @@
#ifdef COOPNET
#ifdef DEVELOPMENT
#define CN_GAME_STR "sm64ex-dev"
#else
#define CN_GAME_STR "sm64ex-coop"
#endif
uint64_t gCoopNetDesiredLobby = 0;
char gCoopNetPassword[64] = "";

10
src/pc/network/packets/packet_spawn_objects.c
View File

@ -16,6 +16,7 @@
#pragma pack(1)
struct SpawnObjectData {
u8 ctx;
u32 parentId;
u32 model;
u32 behaviorId;
@ -79,7 +80,7 @@ void network_send_spawn_objects_to(u8 sendToLocalIndex, struct Object* objects[]
for (u8 i = 0; i < objectCount; i++) {
struct Object* o = objects[i];
if (!o) {
if (!o || !o->ctx) {
LOG_ERROR("Tried to send null object");
return;
}
@ -91,6 +92,7 @@ void network_send_spawn_objects_to(u8 sendToLocalIndex, struct Object* objects[]
u16 extendedModelId = (so && so->o == o)
? so->extendedModelId
: 0xFFFF;
packet_write(&p, &o->ctx, sizeof(u8));
packet_write(&p, &parentId, sizeof(u32));
packet_write(&p, &model, sizeof(u32));
packet_write(&p, &behaviorId, sizeof(u32));
@ -132,6 +134,8 @@ void network_receive_spawn_objects(struct Packet* p) {
for (u8 i = 0; i < objectCount; i++) {
struct SpawnObjectData data = { 0 };
Vec3f scale = { 0 };
u8 ctx = 0;
packet_read(p, &ctx, sizeof(u8));
packet_read(p, &data.parentId, sizeof(u32));
packet_read(p, &data.model, sizeof(u32));
packet_read(p, &data.behaviorId, sizeof(u32));
@ -184,12 +188,14 @@ void network_receive_spawn_objects(struct Packet* p) {
}
void* behavior = (void*)get_behavior_from_id(data.behaviorId);
struct Object* o = spawn_object(parentObj, data.model, behavior);
struct Object* o = NULL;
if (ctx) { o = spawn_object(parentObj, data.model, behavior); }
if (o == NULL) {
LOG_ERROR("ERROR: failed to allocate object!");
return;
}
o->ctx = ctx;
o->globalPlayerIndex = data.globalPlayerIndex;
o->coopFlags |= COOP_OBJ_FLAG_NETWORK;
o->setHome = data.setHome;

16
src/pc/network/sync_object.c
View File

@ -11,6 +11,7 @@
#include "pc/debuglog.h"
#include "pc/utils/misc.h"
#include "data/dynos_cmap.cpp.h"
#include "pc/debug_context.h"
static void* sSoMap = NULL;
static void* sSoIter = NULL;
@ -193,6 +194,7 @@ struct SyncObject* sync_object_init(struct Object *o, float maxSyncDistance) {
so->override_ownership = NULL;
so->on_forget = NULL;
so->syncDeathEvent = true;
so->ctx = 0;
if (!hadSyncId) {
so->extendedModelId = 0xFFFF;
}
@ -375,6 +377,8 @@ u32 sync_object_get_available_local_id() {
bool sync_object_set_id(struct Object* o) {
u32 syncId = o->oSyncID;
u8 ctx = o->ctx;
if (syncId == 0) {
if (!gNetworkAreaLoaded) {
// check if we should set our id based on our parent
@ -405,11 +409,12 @@ bool sync_object_set_id(struct Object* o) {
}
}
if (syncId == 0) {
if (syncId == 0 || !ctx) {
o->oSyncID = 0;
LOG_ERROR("failed to set sync id for object w/behavior %d (set_sync_id) %u", get_id_from_behavior(o->behavior), gNetworkAreaLoaded);
return false;
return !ctx;
}
struct SyncObject* so = sync_object_get(syncId);
if (!so) {
@ -422,17 +427,18 @@ bool sync_object_set_id(struct Object* o) {
}
if (!so) {
LOG_ERROR("failed to set sync id (o) for object w/behavior %d (set_sync_id) %u", get_id_from_behavior(o->behavior), gNetworkAreaLoaded);
LOG_ERROR("failed to set sync id (o) for object w/behavior %d (set_sync_id) %u, ctx %u", get_id_from_behavior(o->behavior), gNetworkAreaLoaded, ctx);
return false;
}
so->id = syncId;
so->o = o;
so->behavior = (BehaviorScript*) o->behavior;
so->ctx = ctx;
o->oSyncID = syncId;
if (gNetworkAreaLoaded) {
LOG_INFO("set sync id for object w/behavior %d", get_id_from_behavior(o->behavior));
LOG_INFO("set sync id for object w/behavior %d, ctx %u", get_id_from_behavior(o->behavior), ctx);
}
return true;

1
src/pc/network/sync_object.h
View File

@ -36,6 +36,7 @@ struct SyncObject {
u16 extendedModelId;
struct Packet lastReliablePacket;
u8 forgetting;
u8 ctx;
};

18
src/pc/pc_main.c
View File

@ -55,6 +55,7 @@
#include "pc/mods/mods.h"
#include "debug_context.h"
#include "menu/intro_geo.h"
#ifdef DISCORD_SDK
@ -207,19 +208,30 @@ void produce_interpolation_frames_and_delay(void) {
}
void produce_one_frame(void) {
CTX_BEGIN(CTX_NETWORK);
network_update();
CTX_END(CTX_NETWORK);
CTX_BEGIN(CTX_INTERP);
patch_interpolations_before();
CTX_END(CTX_INTERP);
const f32 master_mod = (f32)configMasterVolume / 127.0f;
set_sequence_player_volume(SEQ_PLAYER_LEVEL, (f32)configMusicVolume / 127.0f * master_mod);
set_sequence_player_volume(SEQ_PLAYER_SFX, (f32)configSfxVolume / 127.0f * master_mod);
set_sequence_player_volume(SEQ_PLAYER_ENV, (f32)configEnvVolume / 127.0f * master_mod);
CTX_BEGIN(CTX_GAME_LOOP);
game_loop_one_iteration();
CTX_END(CTX_GAME_LOOP);
CTX_BEGIN(CTX_SMLUA);
smlua_update();
CTX_END(CTX_SMLUA);
thread6_rumble_loop(NULL);
CTX_BEGIN(CTX_AUDIO);
int samples_left = audio_api->buffered();
u32 num_audio_samples = samples_left < audio_api->get_desired_buffered() ? SAMPLES_HIGH : SAMPLES_LOW;
//printf("Audio samples: %d %u\n", samples_left, num_audio_samples);
@ -234,8 +246,11 @@ void produce_one_frame(void) {
//printf("Audio samples before submitting: %d\n", audio_api->buffered());
audio_api->play((u8 *)audio_buffer, 2 * num_audio_samples * 4);
CTX_END(CTX_AUDIO);
CTX_BEGIN(CTX_RENDER);
produce_interpolation_frames_and_delay();
CTX_END(CTX_RENDER);
}
void audio_shutdown(void) {
@ -395,6 +410,8 @@ void main_func(void) {
#endif
while (true) {
debug_context_reset();
CTX_BEGIN(CTX_FRAME);
wm_api->main_loop(produce_one_frame);
#ifdef DISCORD_SDK
discord_update();
@ -403,6 +420,7 @@ void main_func(void) {
fflush(stdout);
fflush(stderr);
#endif
CTX_END(CTX_FRAME);
}
bassh_deinit();