Skip to content
19 changes: 19 additions & 0 deletions README.md
Original file line number Diff line number Diff line change
Expand Up @@ -44,6 +44,25 @@ Build
-----
For compiling from sources, please see [BUILD.md](BUILD.md).

Logging channels
----------------
When running a local build, you can limit log output to specific channels by listing the individual channel names you want, separated by commas:

```bash
./openomf --log-level DEBUG --log-channels ai,rec
```

If `--log-channels` is omitted, all channels are enabled.

| Channel | Description |
| --- | --- |
| `ai` | AI state changes, decisions, tactic selection, and scoring |
| `rec` | REC playback/recording, replay controls, and REC assertions |
| `network` | Reserved placeholder for networking |
| `gameplay` | Reserved placeholder for gameplay |
| `video` | Reserved placeholder for video |
| `audio` | Reserved placeholder for audio |

License
-------
OpenOMF is developed under the MIT License. Please read [LICENSE](LICENSE)
Expand Down
95 changes: 20 additions & 75 deletions src/controller/ai_controller.c

Large diffs are not rendered by default.

9 changes: 5 additions & 4 deletions src/controller/rec_controller.c
Original file line number Diff line number Diff line change
Expand Up @@ -82,7 +82,8 @@ int rec_controller_poll(controller *ctrl, ctrl_event **ev) {
sd_rec_move *move;
unsigned int len;
if(ticks > data->max_tick) {
log_debug("closing controller because tick %u is higher than max_tick %u", ticks, data->max_tick);
log_debug_channel(LOG_CHANNEL_REC, "closing controller because tick %u is higher than max_tick %u", ticks,
data->max_tick);
controller_close(ctrl, ev);
return 0;
}
Expand All @@ -104,7 +105,7 @@ int rec_controller_poll(controller *ctrl, ctrl_event **ev) {
} else if(move->lookup_id == 10 && extra_data[0] == REC_LOOKUP10_SETRANDOM_BYTE) {
uint32_t seed;
memcpy(&seed, extra_data + 4, sizeof(seed));
log_debug("setting random seed to %u from REC file", seed);
log_debug_channel(LOG_CHANNEL_REC, "setting random seed to %u from REC file", seed);
random_seed(&ctrl->gs->rand, seed);
} else if(move->lookup_id == 2) {
int action = unpack_sd_action(extra_data[0]);
Expand Down Expand Up @@ -184,7 +185,7 @@ void rec_controller_step_back(controller *ctrl) {

data->last_tick = ctrl->gs->tick;

log_debug("REWOUND game state from %u to %u", ctrl->gs->tick, gs_new->tick);
log_debug_channel(LOG_CHANNEL_REC, "REWOUND game state from %u to %u", ctrl->gs->tick, gs_new->tick);

// fix the game state pointers in the controllers
for(int i = 0; i < game_state_num_players(gs_new); i++) {
Expand Down Expand Up @@ -225,7 +226,7 @@ void rec_controller_create(controller *ctrl, int player, sd_rec_file *rec) {
data->max_tick = rec_move->tick;
}
}
log_debug("max tick is %" PRIu32, data->max_tick);
log_debug_channel(LOG_CHANNEL_REC, "max tick is %" PRIu32, data->max_tick);
ctrl->data = data;
ctrl->type = CTRL_TYPE_REC;
ctrl->poll_fun = &rec_controller_poll;
Expand Down
11 changes: 9 additions & 2 deletions src/main.c
Original file line number Diff line number Diff line change
Expand Up @@ -81,9 +81,13 @@ int main(int argc, char *argv[]) {
struct arg_lit *warp = arg_lit0(NULL, "warp", "run the game at warp speed");
struct arg_int *speed = arg_int0(NULL, "speed", "<speed>", "game speed to use: 1-10");
struct arg_str *log_level = arg_str0(NULL, "log-level", "<level>", "Log level (DEBUG, INFO, WARN, ERROR)");
struct arg_str *log_channels = arg_str0(NULL, "log-channels", "<channels>",
"Comma-separated log channels to enable "
"(ai,rec)");
struct arg_end *end = arg_end(30);
void *argtable[] = {help, vers, listen, lobby, lobbyarg, connect, force_audio_backend, force_renderer,
trace, port, play, rec, warp, speed, log_level, end};
void *argtable[] = {help, vers, listen, lobby, lobbyarg, connect, force_audio_backend,
force_renderer, trace, port, play, rec, warp, speed,
log_level, log_channels, end};
const char *progname = "openomf";

// Make sure everything got allocated
Expand Down Expand Up @@ -191,6 +195,9 @@ int main(int argc, char *argv[]) {
}
log_set_level(log_level_text_to_enum(log_level->sval[0], LOG_INFO));
}
if(log_channels->count > 0) {
log_set_channel_filter(log_channels_from_string(log_channels->sval[0]));
}

// Load file paths
if(!resource_path_init()) {
Expand Down
82 changes: 76 additions & 6 deletions src/utils/log.c
Original file line number Diff line number Diff line change
Expand Up @@ -8,6 +8,7 @@
#include <time.h>

#include "utils/allocator.h"
#include "utils/c_string_util.h"

#define MAX_TARGETS 3
#define LOG_LEVELS 4
Expand All @@ -25,6 +26,7 @@ typedef struct log_target {
typedef struct log_state {
bool colors;
log_level level;
log_channel_filter channel_filter;
log_target targets[MAX_TARGETS];
int target_count;
uint32_t tick;
Expand All @@ -44,6 +46,12 @@ static const char *level_colors[] = {
"\x1b[31m",
};

static const char *channel_names[LOG_CHANNEL_COUNT] = {
[LOG_CHANNEL_AI] = "ai", [LOG_CHANNEL_REC] = "rec",
[LOG_CHANNEL_NETWORK] = "network", [LOG_CHANNEL_GAMEPLAY] = "gameplay",
[LOG_CHANNEL_VIDEO] = "video", [LOG_CHANNEL_AUDIO] = "audio",
};

static log_state *state = NULL;

void log_init(void) {
Expand Down Expand Up @@ -103,6 +111,47 @@ void log_set_colors(bool toggle) {
state->colors = toggle;
}

void log_set_channel_filter(log_channel_filter filter) {
assert(state != NULL);
state->channel_filter = filter;
}

log_channel_filter log_channels_from_string(const char *modules) {
log_channel_filter result = {0};
if(modules == NULL || modules[0] == '\0') {
return result;
}

char *copy = omf_strdup(modules);
if(copy == NULL) {
return result;
}

for(char *token = strtok(copy, " \t,"); token != NULL; token = strtok(NULL, " \t,")) {
for(log_channel i = LOG_CHANNEL_AI; i < LOG_CHANNEL_COUNT; i++) {
if(strcmp(token, channel_names[i]) == 0) {
result.enabled[i] = true;
result.active = true;
break;
}
}
}

omf_free(copy);
return result;
}

// Format the message channel, not the active filter.
// Example: " [ai]"; empty for LOG_CHANNEL_NONE.
static void format_channel_tag(log_channel module, char *buf, size_t len) {
Comment thread
snafudev marked this conversation as resolved.
Comment thread
snafudev marked this conversation as resolved.
buf[0] = '\0';
if(module <= LOG_CHANNEL_NONE || module >= LOG_CHANNEL_COUNT) {
return;
}

snprintf(buf, len, " [%s]", channel_names[module]);
}

static void log_add_fp(FILE *fp, bool close, log_level level, bool colors) {
assert(state != NULL);
assert(state->target_count < MAX_TARGETS - 1);
Expand All @@ -129,22 +178,28 @@ static void format_timestamp(char *buffer, size_t len) {
time_t t = time(NULL);
struct tm *tm = localtime(&t);
strftime(buffer, len, "%H:%M:%S", tm);
buffer[len - 1] = 0;
buffer[len - 1] = '\0';
}

void log_msg(log_level level, const char *fmt, ...) {
ATTR_FORMAT_PRINTF(3, 0)
static void log_vmsg_channel(log_channel module, log_level level, const char *fmt, va_list args) {
assert(state != NULL);
assert(module >= LOG_CHANNEL_NONE && module < LOG_CHANNEL_COUNT);
char dt[16];
va_list args;
char module_tag[64];
const char *color = level_colors[level];
const char *name = level_names[level];

if(level < state->level) {
return;
}
// Channel filtering only applies to tagged messages.
if(module != LOG_CHANNEL_NONE && state->channel_filter.active && !state->channel_filter.enabled[module]) {
return;
}

va_start(args, fmt);
format_timestamp(dt, 16);
format_channel_tag(module, module_tag, sizeof(module_tag));
for(int i = 0; i < state->target_count; i++) {
const log_target *target = &state->targets[i];
if(level < target->level) {
Expand All @@ -154,9 +209,9 @@ void log_msg(log_level level, const char *fmt, ...) {
continue;
}
if(state->colors && target->colors) {
fprintf(target->fp, "%s %s%-5s\x1b[0m \x1b[0m ", dt, color, name);
fprintf(target->fp, "%s %s%-5s\x1b[0m%s \x1b[0m ", dt, color, name, module_tag);
} else {
fprintf(target->fp, "%s %-5s ", dt, name);
fprintf(target->fp, "%s %-5s%s ", dt, name, module_tag);
}
va_list args_copy;
va_copy(args_copy, args);
Expand All @@ -175,6 +230,21 @@ void log_msg(log_level level, const char *fmt, ...) {
fflush(target->fp);
SDL_UnlockMutex(target->lock);
}
}

void log_msg(log_level level, const char *fmt, ...) {
assert(state != NULL);
va_list args;
va_start(args, fmt);
log_vmsg_channel(LOG_CHANNEL_NONE, level, fmt, args);
va_end(args);
}

void log_msg_channel(log_channel module, log_level level, const char *fmt, ...) {
assert(state != NULL);
va_list args;
va_start(args, fmt);
log_vmsg_channel(module, level, fmt, args);
va_end(args);
}

Expand Down
74 changes: 74 additions & 0 deletions src/utils/log.h
Original file line number Diff line number Diff line change
Expand Up @@ -12,7 +12,9 @@
#define LOG_H

#include "utils/compat.h"

#include <stdbool.h>
#include <stdint.h>
#include <stdlib.h>

/**
Expand All @@ -26,6 +28,27 @@ typedef enum log_level
LOG_ERROR ///< Error messages
} log_level;

/**
* @brief Channel attached to a log message.
*/
typedef enum log_channel
{
LOG_CHANNEL_NONE = 0,
LOG_CHANNEL_AI, ///< AI state transitions, decisions, and intent flow.
LOG_CHANNEL_REC, ///< REC playback/recording controller events.
LOG_CHANNEL_NETWORK, ///< Reserved placeholder for networking/logging during future migration.
LOG_CHANNEL_GAMEPLAY, ///< Reserved placeholder for gameplay systems and world simulation logs.
LOG_CHANNEL_VIDEO, ///< Reserved placeholder for rendering and video pipeline diagnostics.
LOG_CHANNEL_AUDIO, ///< Reserved placeholder for audio system diagnostics.
LOG_CHANNEL_COUNT ///< Number of channel values; not a message channel.
} log_channel;

/** An inactive filter accepts all tagged channels. */
typedef struct log_channel_filter {
bool active;
bool enabled[LOG_CHANNEL_COUNT];
} log_channel_filter;

/**
* @brief Log a debug message.
* @param ... Printf-style format string and arguments
Expand All @@ -50,6 +73,57 @@ typedef enum log_level
*/
#define log_error(...) log_msg(LOG_ERROR, __VA_ARGS__)

/**
* @brief Log a debug message tagged with a channel.
* @param channel Channel to tag the message with.
* @param ... Printf-style format string and arguments
*/
#define log_debug_channel(channel, ...) log_msg_channel((channel), LOG_DEBUG, __VA_ARGS__)

/**
* @brief Log an informational message tagged with a channel.
* @param channel Channel to tag the message with.
* @param ... Printf-style format string and arguments
*/
#define log_info_channel(channel, ...) log_msg_channel((channel), LOG_INFO, __VA_ARGS__)

/**
* @brief Log a warning message tagged with a channel.
* @param channel Channel to tag the message with.
* @param ... Printf-style format string and arguments
*/
#define log_warn_channel(channel, ...) log_msg_channel((channel), LOG_WARN, __VA_ARGS__)

/**
* @brief Log an error message tagged with a channel.
* @param channel Channel to tag the message with.
* @param ... Printf-style format string and arguments
*/
#define log_error_channel(channel, ...) log_msg_channel((channel), LOG_ERROR, __VA_ARGS__)

/**
* @brief Set the active channel filter.
* @param filter Enabled channels; inactive means all tagged channels.
*/
void log_set_channel_filter(log_channel_filter filter);

/**
* @brief Parse a channel list into a filter.
* @param channels Comma-separated channel names, such as "ai,rec".
* @return Enabled channels; NULL/empty or no recognized names accepts all tagged channels.
*/
log_channel_filter log_channels_from_string(const char *channels);

/**
* @brief Log a message at the specified level, tagged with a channel.
* @details Prefer using the log_debug_channel/info_channel/warn_channel/error_channel macros instead.
* @param channel Channel to tag the message with.
* @param level Severity level
* @param fmt Printf-style format string
* @param ... Format arguments
*/
void log_msg_channel(log_channel channel, log_level level, const char *fmt, ...) ATTR_FORMAT_PRINTF(3, 4);

/**
* @brief Initialize the logging system.
* @details Must be called before any logging functions.
Expand Down
Loading