rg_system: Improved logging

Added colors and also added a verbose mode that is stripped from release builds (so RG_LOGV calls can contain costly calculations that won't impact normal runtime)
This commit is contained in:
Alex Duchesne 2024-03-06 20:22:46 -05:00
parent 841ffe3513
commit f68a0003c1
12 changed files with 67 additions and 43 deletions

View File

@ -88,7 +88,7 @@ static void network_event_handler(void *arg, esp_event_base_t event_base, int32_
}
}
RG_LOGD("Event: %d %d\n", (int)event_base, (int)event_id);
RG_LOGV("Event: %d %d\n", (int)event_base, (int)event_id);
}
#endif

View File

@ -195,7 +195,7 @@ static void system_monitor_task(void *arg)
}
// Try to avoid complex conversions that could allocate, prefer rounding/ceiling if necessary.
RG_LOGX("STACK:%d, HEAP:%d+%d (%d+%d), BUSY:%d%%, FPS:%d (SKIP:%d, PART:%d, FULL:%d), BATT:%d\n",
rg_system_log(RG_LOG_DEBUG, NULL, "STACK:%d, HEAP:%d+%d (%d+%d), BUSY:%d%%, FPS:%d (%d+%d+%d), BATT:%d\n",
statistics.freeStackMain,
statistics.freeMemoryInt / 1024,
statistics.freeMemoryExt / 1024,
@ -327,10 +327,16 @@ rg_app_t *rg_system_init(int sampleRate, const rg_handlers_t *handlers, const rg
.tickRate = 60,
.frameskip = 0,
.overclock = 0,
.watchdog = 1,
.tickTimeout = 3000000,
.lowMemoryMode = 0,
.watchdog = true,
.lowMemoryMode = false,
#ifdef RG_RELEASE
.isRelease = true,
.logLevel = RG_LOG_INFO,
#else
.isRelease = false,
.logLevel = RG_LOG_DEBUG,
#endif
.options = options, // TO DO: We should make a copy of it?
};
@ -360,7 +366,7 @@ rg_app_t *rg_system_init(int sampleRate, const rg_handlers_t *handlers, const rg
printf("\n========================================================\n");
printf("%s %s (%s)\n", app.name, app.version, app.buildDate);
printf(" built for: %s. aud=%d disp=%d pad=%d sd=%d cfg=%d\n", RG_TARGET_NAME, 0, 0, 0, 0, 0);
printf(" built for: %s. type: %s\n", RG_TARGET_NAME, app.isRelease ? "release" : "dev");
printf("========================================================\n\n");
rg_storage_init();
@ -406,6 +412,7 @@ rg_app_t *rg_system_init(int sampleRate, const rg_handlers_t *handlers, const rg
app.bootFlags = rg_settings_get_number(NS_BOOT, SETTING_BOOT_FLAGS, 0);
app.saveSlot = (app.bootFlags & RG_BOOT_SLOT_MASK) >> 4;
app.romPath = app.bootArgs;
app.isLauncher = strcmp(app.name, "launcher") == 0; // Might be overriden after init
rg_display_init();
rg_gui_init();
@ -613,7 +620,7 @@ IRAM_ATTR int64_t rg_system_timer(void)
void rg_system_event(int event, void *arg)
{
RG_LOGD("Dispatching event:%d arg:%p\n", event, arg);
RG_LOGV("Dispatching event:%d arg:%p\n", event, arg);
if (app.handlers.event)
app.handlers.event(event, arg);
}
@ -725,19 +732,17 @@ void rg_system_panic(const char *context, const char *message)
void rg_system_vlog(int level, const char *context, const char *format, va_list va)
{
const char *levels[RG_LOG_MAX] = {NULL, "=", "error", "warn", "info", "debug"};
const char *levels[RG_LOG_MAX] = {"=", "error", "warn", "info", "debug", "trace"};
const char *colors[RG_LOG_MAX] = {"", "\e[31m", "\e[33m", "", "\e[34m", "\e[36m"};
char buffer[300];
size_t len = 0;
if (app.logLevel && level > app.logLevel)
return;
if (level > RG_LOG_PRINT && level < RG_LOG_MAX)
if (level >= 0 && level < RG_LOG_MAX)
{
if (levels[level])
len += sprintf(buffer + len, "[%s] ", levels[level]);
if (context)
len += sprintf(buffer + len, "%s: ", context);
len = snprintf(buffer, sizeof(buffer), "[%s] %s: ", levels[level], context);
else
len = snprintf(buffer, sizeof(buffer), "[%s] ", levels[level]);
}
len += vsnprintf(buffer + len, sizeof(buffer) - len, format, va);
@ -750,12 +755,26 @@ void rg_system_vlog(int level, const char *context, const char *format, va_list
}
if (panicTraceCleared)
{
logbuf_puts(&panicTrace, buffer);
fputs(buffer, stdout);
}
#ifdef RG_TARGET_SDL2
fflush(stdout);
#endif
if (level <= app.logLevel)
{
if (level >= 0 && level < RG_LOG_MAX)
{
fputs(colors[level], stdout);
fputs(buffer, stdout);
fputs("\e[0m", stdout);
}
else
{
fputs(buffer, stdout);
}
#ifdef RG_TARGET_SDL2
fflush(stdout);
#endif
}
}
void rg_system_log(int level, const char *context, const char *format, ...)
@ -887,10 +906,10 @@ void rg_system_set_overclock(int level)
app.overclock = level;
RG_LOGX("\n\n");
RG_LOGI("BASE: %d %d %d %d %d", BASE_ENDIV5, BASE_BBADC_DSMP, BASE_BBADC_OC_LREF, BASE_BBADC_OC_DIV_7_0, BASE_BBADC_OC_DCUR);
RG_LOGI("NEW : %d %d %d %d %d", ENDIV5, BBADC_DSMP, BBADC_OC_LREF, BBADC_OC_DIV_7_0, BBADC_OC_DCUR);
RG_LOGX("\n\n");
RG_LOGW(" ");
RG_LOGW("BASE: %d %d %d %d %d", BASE_ENDIV5, BASE_BBADC_DSMP, BASE_BBADC_OC_LREF, BASE_BBADC_OC_DIV_7_0, BASE_BBADC_OC_DCUR);
RG_LOGW("NEW : %d %d %d %d %d", ENDIV5, BBADC_DSMP, BBADC_OC_LREF, BBADC_OC_DIV_7_0, BBADC_OC_DCUR);
RG_LOGW(" ");
rom_i2c_writeReg(I2C_BBPLL, I2C_BBPLL_HOSTID, I2C_BBPLL_ENDIV5, ENDIV5);
rom_i2c_writeReg(I2C_BBPLL, I2C_BBPLL_HOSTID, I2C_BBPLL_BBADC_DSMP, BBADC_DSMP);

View File

@ -81,13 +81,12 @@ typedef enum
typedef enum
{
RG_LOG_PRINT = 0,
RG_LOG_USER,
RG_LOG_PRINTF = 0,
RG_LOG_ERROR,
RG_LOG_WARN,
RG_LOG_INFO,
RG_LOG_DEBUG,
RG_LOG_TRACE,
RG_LOG_VERBOSE,
RG_LOG_MAX,
} rg_log_level_t;
@ -171,10 +170,11 @@ typedef struct
int tickRate;
int frameskip;
int overclock;
int isLauncher;
int watchdog;
int tickTimeout;
int lowMemoryMode;
bool watchdog;
bool lowMemoryMode;
bool isLauncher;
bool isRelease;
int logLevel;
int saveSlot;
const char *romPath;
@ -262,12 +262,15 @@ rg_emu_states_t *rg_emu_get_states(const char *romPath, size_t slots);
#define RG_LOG_TAG __func__
#endif
#define RG_LOGX(x, ...) rg_system_log(RG_LOG_PRINT, RG_LOG_TAG, x, ## __VA_ARGS__)
#define RG_LOGE(x, ...) rg_system_log(RG_LOG_ERROR, RG_LOG_TAG, x, ## __VA_ARGS__)
#define RG_LOGW(x, ...) rg_system_log(RG_LOG_WARN, RG_LOG_TAG, x, ## __VA_ARGS__)
#define RG_LOGI(x, ...) rg_system_log(RG_LOG_INFO, RG_LOG_TAG, x, ## __VA_ARGS__)
#define RG_LOGU(x, ...) rg_system_log(RG_LOG_USER, RG_LOG_TAG, x, ## __VA_ARGS__)
#define RG_LOGD(x, ...) rg_system_log(RG_LOG_DEBUG, RG_LOG_TAG, x, ## __VA_ARGS__)
#ifndef RG_RELEASE
#define RG_LOGV(x, ...) rg_system_log(RG_LOG_VERBOSE, RG_LOG_TAG, x, ## __VA_ARGS__)
#else
#define RG_LOGV(x, ...)
#endif
#ifdef RG_ENABLE_PROFILING
void __cyg_profile_func_enter(void *this_fn, void *call_site);

View File

@ -6,7 +6,7 @@
#define RG_TIMER_INIT() int64_t _rgts_ = rg_system_timer(), _rgtl_ = rg_system_timer();
#define RG_TIMER_LAP(name) \
RG_LOGX("Lap %s: %dms Total: %dms\n", #name, (int((rg_system_timer() - _rgtl_) / 1000), \
RG_LOGW("Lap %s: %dms Total: %dms\n", #name, (int((rg_system_timer() - _rgtl_) / 1000), \
(int)((rg_system_timer() - _rgts_) / 1000)); \
_rgtl_ = rg_system_timer();

View File

@ -36,14 +36,14 @@ static const char *get_path(const char *path)
int msx_chdir(const char *path)
{
RG_LOGD("called ('%s')", path);
RG_LOGV("called ('%s')", path);
strcpy(path_cwd, get_path(path));
return 0;
}
char *msx_getcwd(char *buf, size_t size)
{
RG_LOGD("called");
RG_LOGV("called");
if (!buf)
return strdup(path_cwd);
if (strlen(path_cwd) < size)
@ -53,7 +53,7 @@ char *msx_getcwd(char *buf, size_t size)
DIR *msx_opendir(const char *path)
{
RG_LOGD("called ('%s')", path);
RG_LOGV("called ('%s')", path);
return opendir(get_path(path));
}
@ -69,7 +69,7 @@ struct dirent *msx_readdir(DIR *dir)
FILE *msx_fopen(const char *path, const char *mode)
{
RG_LOGD("called ('%s', '%s')", path, mode);
RG_LOGV("called ('%s', '%s')", path, mode);
if (strstr(msx_ignore_files, path))
return NULL;
if (strcmp(path, "CARTS.SHA") == 0)
@ -87,7 +87,7 @@ FILE *msx_fopen(const char *path, const char *mode)
int msx_stat(const char *path, struct stat *sbuf)
{
RG_LOGD("called ('%s')", path);
RG_LOGV("called ('%s')", path);
if (strstr(msx_ignore_files, path))
return -1;
#if defined(DT_REG) && defined(DT_DIR)
@ -109,7 +109,7 @@ int msx_stat(const char *path, struct stat *sbuf)
int msx_unlink(const char *path)
{
RG_LOGD("called ('%s')", path);
RG_LOGV("called ('%s')", path);
return unlink(get_path(path));
}
#endif

View File

@ -4,6 +4,8 @@
#include <math.h>
#include <stdio.h>
// #define printf(x...) rg_system_log(RG_LOG_PRINT, NULL, x)
// Misc fixes
#define main(x, y) fmsx_main(x, y)
#define abs(x) __abs(x)

View File

@ -56,7 +56,7 @@ void lprintf(OutputLevels lvl, const char *s, ...)
va_list arg;
va_start(arg, s);
#ifdef RETRO_GO
rg_system_vlog(RG_LOG_USER, NULL, s, arg);
rg_system_vlog(RG_LOG_PRINTF, NULL, s, arg);
#else
vprintf(s, arg);
#endif

View File

@ -6,7 +6,7 @@
#ifdef RETRO_GO
#include <rg_system.h>
#define LOG_PRINTF(level, x...) rg_system_log(RG_LOG_USER, NULL, x)
#define LOG_PRINTF(level, x...) rg_system_log(RG_LOG_PRINTF, NULL, x)
#else
#define LOG_PRINTF(level, x...) printf(x)
#define IRAM_ATTR

View File

@ -142,7 +142,7 @@ extern UBYTE *gPrimaryFrameBuffer;
//
#ifdef RETRO_GO
#include <rg_system.h>
#define log_printf(x...) rg_system_log(RG_LOG_USER, NULL, x)
#define log_printf(x...) rg_system_log(RG_LOG_PRINTF, NULL, x)
#define crc32_le(a, b, c) rg_crc32(a, b, c)
#else
#include <stdio.h>

View File

@ -2,7 +2,7 @@
#ifdef RETRO_GO
#include <rg_system.h>
#define LOG_PRINTF(level, x...) rg_system_log(RG_LOG_USER, NULL, x)
#define LOG_PRINTF(level, x...) rg_system_log(RG_LOG_PRINTF, NULL, x)
#define CRC32(a, b, c) rg_crc32(a, b, c)
#else
#include <stdio.h>

View File

@ -10,7 +10,7 @@
#ifdef RETRO_GO
#include <rg_system.h>
#define LOG_PRINTF(level, x...) rg_system_log(RG_LOG_USER, NULL, x)
#define LOG_PRINTF(level, x...) rg_system_log(RG_LOG_PRINTF, NULL, x)
#define crc32_le(a, b, c) rg_crc32(a, b, c)
#else
#define LOG_PRINTF(level, x...) printf(x)

View File

@ -20,7 +20,7 @@ typedef signed long int int32;
#ifdef RETRO_GO
#include <rg_system.h>
#define LOG_PRINTF(level, x...) rg_system_log(RG_LOG_USER, NULL, x)
#define LOG_PRINTF(level, x...) rg_system_log(RG_LOG_PRINTF, NULL, x)
#define crc32_le(a, b, c) rg_crc32(a, b, c)
#else
#define LOG_PRINTF(level, x...) printf(x)