New src/dusk/perf module: a simple push/pop tick-stack (perfPush/perfPop/ perfReport) for measuring how long a labeled span of code takes, wired into engine.c's init/dispose. perfGetTick() is a placeholder - real time on DUSK_LINUX (clock_gettime) and DUSK_PSP (sceKernelGetSystemTimeWide), 0 elsewhere until a proper cross-platform answer is settled on. Used it this session to chase a reported PSP hitch when crossing a chunk boundary. Confirmed mapPositionSet itself (unload/load sweeps, chunk order rebuild, entity chunkIndex recompute) is consistently under ~3ms - not the cause. Along the way, found and fixed a real, unrelated bug: logDebug()/logError() on PSP did a fopen+write+fclose to the Memory Stick on every single call, which was massively inflating any perf measurement that logged from inside another measurement (the actual source of the ~29-128ms numbers first seen). That's now gated behind a new DUSK_PSP_LOG_FILE CMake option (default off). Also, as a real test based on this session's findings: - MAP_CHUNK_LOAD_CONCURRENCY dropped from 2 to 1 (8 and 4 both crashed/ were untested further on real PSP hardware; 1 is confirmed safe). - MAP_CHUNK_LOAD_DELAY_TEST: an intentionally exaggerated (now 50ms) artificial delay between starting successive chunk loads, gated in mapChunkLoadNext/mapUpdate, to observe the effect on framerate. All perf instrumentation call sites added during this investigation (assetChunkLoaderSync, assetMeshLoaderSync, mapPositionSet, the map area callback invocation, engine.c's frame boundary) were removed again once they'd served their purpose - only the reusable perf module itself and the two real fixes above remain. Co-Authored-By: Claude Sonnet 5 <[email protected]>
58 lines
1.3 KiB
C
58 lines
1.3 KiB
C
/**
|
|
* Copyright (c) 2026 Dominic Masters
|
|
*
|
|
* This software is released under the MIT License.
|
|
* https://opensource.org/licenses/MIT
|
|
*/
|
|
|
|
#include "log/log.h"
|
|
|
|
void logDebug(const char_t *message, ...) {
|
|
va_list args;
|
|
va_start(args, message);
|
|
|
|
// print to stdout
|
|
va_list copy;
|
|
va_copy(copy, args);
|
|
vprintf(message, copy);
|
|
va_end(copy);
|
|
|
|
#ifdef DUSK_PSP_LOG_FILE
|
|
// print to file - fopen+fclose every call is real, measured Memory
|
|
// Stick I/O cost (this is why the flag exists - see psp.cmake).
|
|
FILE *file = fopen("ms0:/PSP/GAME/Dusk/debug.log", "a");
|
|
if(file) {
|
|
va_copy(copy, args);
|
|
vfprintf(file, message, copy);
|
|
va_end(copy);
|
|
fclose(file);
|
|
}
|
|
#endif
|
|
|
|
va_end(args);
|
|
}
|
|
|
|
void logError(const char_t *message, ...) {
|
|
va_list args;
|
|
va_start(args, message);
|
|
|
|
// print to stderr
|
|
va_list copy;
|
|
va_copy(copy, args);
|
|
vfprintf(stderr, message, copy);
|
|
va_end(copy);
|
|
|
|
#ifdef DUSK_PSP_LOG_FILE
|
|
// print to file - fopen+fclose every call is real, measured Memory
|
|
// Stick I/O cost (this is why the flag exists - see psp.cmake).
|
|
FILE *file = fopen("ms0:/PSP/GAME/Dusk/error.log", "a");
|
|
if(file) {
|
|
va_copy(copy, args);
|
|
vfprintf(file, message, copy);
|
|
va_end(copy);
|
|
fclose(file);
|
|
}
|
|
#endif
|
|
|
|
va_end(args);
|
|
} |