From 9079ab5c24a44ca8adda3d69a310f85db6638483 Mon Sep 17 00:00:00 2001 From: evgeny Date: Wed, 21 Oct 2026 17:10:44 +0200 Subject: [PATCH] Fix debug timestamps, default output and log reopening --- lib/debug_config.c | 35 +++++++++---- lib/debug_config.h | 28 ++++++---- tests/test_config_debug.c | 107 ++++++++++++++++++++++++++++++++++++++ 3 files changed, 150 insertions(+), 20 deletions(-) diff --git a/lib/debug_config.c b/lib/debug_config.c index 9f30f206..0374964e 100644 --- a/lib/debug_config.c +++ b/lib/debug_config.c @@ -272,6 +272,10 @@ void debug_set_masks(debug_category_t category_idx, debug_level_t level) { debug_set_category_level(category_idx, level); } +void debug_enable_timestamp(int enable) { + g_debug_config.timestamp_enabled = !!enable; +} + void debug_enable_function_name(int enable) { g_debug_config.function_name_enabled = enable; } @@ -323,15 +327,24 @@ void debug_disable_file_output(void) { } } -/* Reopen log file (append mode) for SIGHUP. Complete operation with full error logging. */ +/* Переоткрыть лог в append-режиме; при ошибке открытия сохранить прежний поток. */ int debug_reopen_log(void) { if (!g_debug_config.output_file) { DEBUG_WARN(DEBUG_CATEGORY_CONFIG, "No log path for reopen"); return -1; } const char* path = g_debug_config.output_file; - debug_disable_file_output(); - debug_enable_file_output(path, 0); // append + FILE* new_file = fopen(path, "a"); + if (!new_file) { + DEBUG_ERROR(DEBUG_CATEGORY_CONFIG, "Cannot reopen log '%s': %s", path, strerror(errno)); + return -1; + } + FILE* old_file = g_debug_config.file_output; + g_debug_config.file_output = new_file; + if (old_file && fclose(old_file) != 0) { + DEBUG_ERROR(DEBUG_CATEGORY_CONFIG, "Cannot close previous log '%s': %s", path, strerror(errno)); + return -1; + } DEBUG_INFO(DEBUG_CATEGORY_CONFIG, "Log reopened: %s", path); return 0; } @@ -391,13 +404,15 @@ void debug_output(debug_level_t level, debug_category_t category_idx, va_start(args, format); /* Add timestamp with microseconds: hh:mm:ss-xxx.yyy */ - struct timeval tv; - utun_gettimeofday(&tv, NULL); - time_t tv_sec = (time_t)tv.tv_sec; - struct tm* tm_info = localtime(&tv_sec); - char time_str[32]; - strftime(time_str, sizeof(time_str), "%H:%M:%S", tm_info); - BUF_ADVANCE(snprintf(buffer + offset, remaining, "[%s-%03ld.%03ld] ", time_str, tv.tv_usec / 1000, tv.tv_usec % 1000)); + if (g_debug_config.timestamp_enabled) { + struct timeval tv; + utun_gettimeofday(&tv, NULL); + time_t tv_sec = (time_t)tv.tv_sec; + struct tm* tm_info = localtime(&tv_sec); + char time_str[32]; + strftime(time_str, sizeof(time_str), "%H:%M:%S", tm_info); + BUF_ADVANCE(snprintf(buffer + offset, remaining, "[%s-%03ld.%03ld] ", time_str, tv.tv_usec / 1000, tv.tv_usec % 1000)); + } /* Add thread marker if set */ if (g_debug_config.thread_marker > 0) { diff --git a/lib/debug_config.h b/lib/debug_config.h index a2fdcb93..5a467240 100644 --- a/lib/debug_config.h +++ b/lib/debug_config.h @@ -1,6 +1,7 @@ /** - * Runtime debug configuration system - * Provides flexible control over debug output without recompilation + * Управление диагностикой: debug_config_init → уровни категорий и настройки вывода → DEBUG_*. + * NONE наследует общий уровень, DISABLED отключает категорию. Имена настроек — category=level. + * Открытый файл имеет приоритет над консолью; hook получает сообщения независимо от выбора выхода. */ #ifndef DEBUG_CONFIG_H @@ -86,9 +87,9 @@ typedef struct { int timestamp_enabled; // Include timestamps in output int function_name_enabled; // Include function names int file_line_enabled; // Include file:line info - const char* output_file; // NULL = stdout, otherwise file path + const char* output_file; // Заимствованный путь для reopen; строка должна жить, пока поле её хранит - // Dual output support + // Выход: файл, иначе консоль при console_enabled != 0 FILE* file_output; // File handle for log file (NULL if not open) int console_enabled; // Enable console output int thread_marker; // Thread identification (0=none, e.g. 2 for uasync) @@ -116,16 +117,23 @@ void debug_set_categories(debug_category_t categories); /* Установка уровня одной категории (аргумент categories — индекс, не битовая маска). */ void debug_set_masks(debug_category_t categories, debug_level_t level); -/* Configure output options */ +/* Configure output options */ +/* Ненулевое enable включает временную метку, 0 отключает. */ void debug_enable_timestamp(int enable); void debug_enable_function_name(int enable); void debug_enable_file_line(int enable); -void debug_set_output_file(const char* file_path); +/* Открыть ненулевой file_path в append-режиме, только если файл ещё не открыт; путь заимствован. */ +void debug_set_output_file(const char* file_path); -/* Dual output configuration */ +/* Заменить файл: truncate != 0 → обрезать, иначе append. NULL ничего не меняет. + * Путь заимствован; успешное открытие также выключает console_enabled. */ void debug_enable_file_output(const char* file_path, int truncate); +/* Закрыть файл; прежнее значение console_enabled не восстанавливается. */ void debug_disable_file_output(void); +/* Переоткрыть текущий путь в append-режиме: 0 — успех, -1 — ошибка с диагностикой. + * При ошибке открытия сохраняет прежний поток; console_enabled не меняет. */ int debug_reopen_log(void); +/* Вывод в консоль разрешён только при отсутствии открытого файла. */ void debug_enable_console(int enable); @@ -137,7 +145,7 @@ typedef struct { ip_str_t ip_to_str(const void *addr, int family);// big endian addr ip_str_t sockaddr_storage_to_str(const struct sockaddr_storage *addr);// автоопределение v4 или v6 -// hex dump в лог +// Hex dump: первые min(len, 128) байт; при len > 128 добавляет "...". Применяется фильтр уровня/категории. void log_dump(int level, int category, const char* prefix, const uint8_t* data, size_t len); /* Check if debug output should be shown for given level and category */ @@ -204,8 +212,8 @@ int debug_parse_config(const char* config_string); debug_output(DEBUG_LEVEL_TRACE, category, __FUNCTION__, __FILE__, __LINE__, fmt, ##__VA_ARGS__); \ } } while(0) -/* Backward compatibility - default to ERROR level if not specified */ -#define DEBUG_OUTPUT(fmt, ...) DEBUG_ERROR(DEBUG_CATEGORY_ALL, fmt, ##__VA_ARGS__) +/* Сообщение без явной категории: ERROR в категории GENERAL, с обычной фильтрацией. */ +#define DEBUG_OUTPUT(fmt, ...) DEBUG_ERROR(DEBUG_CATEGORY_GENERAL, fmt, ##__VA_ARGS__) #ifdef __cplusplus } diff --git a/tests/test_config_debug.c b/tests/test_config_debug.c index 3f2d2a9d..f2617cc2 100644 --- a/tests/test_config_debug.c +++ b/tests/test_config_debug.c @@ -105,6 +105,111 @@ static void test_all_debug_categories(void) { printf("All %d debug categories preserved by file and buffer parsers\n", count); } +static int captured_count; +static char captured_category[32]; +static char captured_message[4096]; + +/* Снимок фактически выведенного сообщения, включая форматирование. */ +static void capture_debug_message(int level, const char* category, const char* message) { + assert(level >= DEBUG_LEVEL_ERROR && level <= DEBUG_LEVEL_TRACE); + captured_count++; + snprintf(captured_category, sizeof(captured_category), "%s", category); + snprintf(captured_message, sizeof(captured_message), "%s", message); +} + +/* Проверить реальный вывод через макрос, переключатель времени и ограничение дампа. */ +static void test_debug_output_contract(void) { + debug_config_init(); + debug_enable_console(0); + debug_enable_timestamp(0); + debug_enable_function_name(0); + debug_enable_file_line(0); + debug_set_log_hook(capture_debug_message); + captured_count = 0; + DEBUG_OUTPUT("plain-marker"); + assert(captured_count == 1); + assert(strcmp(captured_category, "general") == 0); + assert(strcmp(captured_message, "[ERROR] [general] plain-marker\n") == 0); + + debug_enable_timestamp(1); + DEBUG_OUTPUT("timed-marker"); + assert(captured_count == 2); + assert(strncmp(captured_message, "[ERROR]", 7) != 0); + assert(strstr(captured_message, "[ERROR] [general] timed-marker\n")); + debug_set_category_level(DEBUG_CATEGORY_GENERAL, DEBUG_LEVEL_DISABLED); + DEBUG_OUTPUT("suppressed-marker"); + assert(captured_count == 2); + + debug_set_category_level(DEBUG_CATEGORY_GENERAL, DEBUG_LEVEL_ERROR); + uint8_t bytes[129]; + memset(bytes, 0x5a, sizeof(bytes)); + bytes[128] = 0xff; + log_dump(DEBUG_LEVEL_ERROR, DEBUG_CATEGORY_GENERAL, "dump-marker", bytes, sizeof(bytes)); + assert(captured_count == 3); + const char* hex = strstr(captured_message, "len=129 hex="); + assert(hex); + hex += strlen("len=129 hex="); + assert(strlen(hex) == 128 * 2 + 3 + 3 + 1); // hex, три пробела, многоточие, newline + assert(!strstr(hex, "ff")); + assert(strstr(hex, "...\n")); + debug_set_log_hook(NULL); + debug_set_level(DEBUG_LEVEL_INFO); + debug_enable_console(1); + DEBUG_INFO(DEBUG_CATEGORY_CONFIG, "Debug output, timestamp, filter and hex limit: PASS"); +} + +/* Неудачное переоткрытие оставляет рабочий поток; успешное сохраняет append и выбор консоли. */ +static void test_debug_log_reopen(void) { + char log_path[512], missing_path[512]; + snprintf(log_path, sizeof(log_path), "%s/runtime.log", temp_dir); + snprintf(missing_path, sizeof(missing_path), "%s/missing/runtime.log", temp_dir); + debug_config_init(); + debug_set_level(DEBUG_LEVEL_INFO); + debug_enable_timestamp(0); + debug_set_log_hook(capture_debug_message); + debug_enable_file_output(log_path, 1); + assert(g_debug_config.file_output && g_debug_config.output_file == log_path); + assert(g_debug_config.console_enabled == 0); + FILE* original = g_debug_config.file_output; + DEBUG_ERROR(DEBUG_CATEGORY_CONFIG, "before-reopen-marker"); + + g_debug_config.output_file = missing_path; + captured_count = 0; + assert(debug_reopen_log() == -1); + assert(g_debug_config.file_output == original); + assert(captured_count == 1 && strstr(captured_message, "Cannot reopen log")); + DEBUG_ERROR(DEBUG_CATEGORY_CONFIG, "still-writable-marker"); + + g_debug_config.output_file = log_path; + debug_enable_console(1); + assert(debug_reopen_log() == 0); + assert(g_debug_config.file_output); + assert(g_debug_config.console_enabled == 1); + assert(strstr(captured_message, "Log reopened:")); + DEBUG_ERROR(DEBUG_CATEGORY_CONFIG, "after-reopen-marker"); + debug_enable_console(0); + debug_disable_file_output(); + assert(!g_debug_config.file_output && !g_debug_config.output_file); + assert(g_debug_config.console_enabled == 0); + assert(debug_reopen_log() == -1); + debug_set_log_hook(NULL); + + FILE* file = fopen(log_path, "r"); + assert(file); + char text[8192]; + size_t length = fread(text, 1, sizeof(text) - 1, file); + assert(!ferror(file) && fclose(file) == 0); + text[length] = '\0'; + assert(strstr(text, "before-reopen-marker")); + assert(strstr(text, "Cannot reopen log")); + assert(strstr(text, "still-writable-marker")); + assert(strstr(text, "after-reopen-marker")); + assert(test_unlink(log_path) == 0); + debug_config_init(); + debug_set_level(DEBUG_LEVEL_INFO); + DEBUG_INFO(DEBUG_CATEGORY_CONFIG, "Log reopen success/failure and append preservation: PASS"); +} + int main() { // Initialize socket platform (required for getaddrinfo on Windows) if (socket_platform_init() != 0) { @@ -163,6 +268,8 @@ int main() { // Освобождение ресурсов free_config(config); test_all_debug_categories(); + test_debug_output_contract(); + test_debug_log_reopen(); // Cleanup temp config file cleanup_temp_config();