Fix debug timestamps, default output and log reopening
This commit is contained in:
1 parent
7e39f16e0f
commit
9079ab5c24
3 files changed
+150
-20
No files matched your search
+25
-10
@@ -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) {
|
||||
|
||||
+18
-10
@@ -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
|
||||
}
|
||||
|
||||
@@ -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();
|
||||
|
||||
Reference in new issue
Block a user