log/logging.c

Go to the documentation of this file.

 
#include "common.h"
#include "options/options.h"
#include "options/rcu.h" // For RCU-based options access
#include "platform/abstraction.h"
#include "platform/system.h"
#include "util/path.h"
#include <stdarg.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <time.h>
#include <fcntl.h>
#include <sys/stat.h>
 
#include "logging.h"
#include "log/mmap.h"
#include "platform/terminal.h"
#include "platform/thread.h"
#include "platform/mutex.h"
#include "network/packet.h"
 
/* ============================================================================
 * Logging System Internal State
 * ============================================================================ */
 
/* Log context struct - Lock-free logging with mutex-protected rotation
 *
 * Design: Logging itself is lock-free using atomic operations and atomic write() syscalls.
 * Only log rotation uses a mutex, since it involves multiple file operations that must
 * be atomic as a group (close, read tail, write temp, rename, reopen).
 */
#pragma GCC diagnostic push
#pragma GCC diagnostic ignored "-Wmissing-field-initializers"
static struct log_context_t {
  _Atomic int file;                        /* File descriptor (atomic for safe access) */
  _Atomic int level;                       /* Log level as int for atomic ops */
  _Atomic bool initialized;                /* Initialization flag */
  char filename[LOG_MSG_BUFFER_SIZE];      /* Store filename (set once at init) */
  _Atomic size_t current_size;             /* Track current file size */
  _Atomic bool terminal_output_enabled;    /* Control stderr output to terminal */
  _Atomic bool level_manually_set;         /* Track if level was set manually */
  _Atomic bool force_stderr;               /* Force all terminal logs to stderr (client mode) */
  _Atomic bool terminal_locked;            /* True when a thread has exclusive terminal access */
  _Atomic uint64_t terminal_owner_thread;  /* Thread that owns terminal output (stored as uint64) */
  _Atomic unsigned int flush_delay_ms;     /* Delay between each buffered log flush (0 = disabled) */
  mutex_t rotation_mutex;                  /* Mutex for log rotation only (not for logging!) */
  _Atomic bool rotation_mutex_initialized; /* Track if rotation mutex is ready */
} g_log = {
    .file = 2, /* STDERR_FILENO - fd 0 is STDIN (read-only!) */
    .level = DEFAULT_LOG_LEVEL,
    .initialized = false,
    .filename = {0},
    .current_size = 0,
    .terminal_output_enabled = true,
    .level_manually_set = false,
    .force_stderr = false,
    .terminal_locked = false,
    .terminal_owner_thread = 0,
    .flush_delay_ms = 0,
    .rotation_mutex_initialized = false,
};
#pragma GCC diagnostic pop
 
/* Level strings for log output */
static const char *level_strings[] = {"DEV", "DEBUG", "INFO", "WARN", "ERROR", "FATAL"};
 
/* Internal color mode enum for indexing into 2D color array */
/* NOTE: Uses LOG_CMODE_ prefix to avoid conflict with public terminal_color_mode_t in options.h */
typedef enum { LOG_CMODE_16 = 0, LOG_CMODE_256 = 1, LOG_CMODE_TRUECOLOR = 2, LOG_CMODE_COUNT = 3 } log_color_mode_t;
 
#define LOG_COLOR_COUNT 7 /* DEV, DEBUG, INFO, WARN, ERROR, FATAL, RESET */
 
/* 2D color array: [color_mode][log_color] */
static const char *level_colors[LOG_CMODE_COUNT][LOG_COLOR_COUNT] = {
    /* LOG_CMODE_16 */
    {"\x1b[34m", "\x1b[36m", "\x1b[32m", "\x1b[33m", "\x1b[31m", "\x1b[35m", "\x1b[0m"},
    /* LOG_CMODE_256 */
    {"\x1b[94m", "\x1b[96m", "\x1b[92m", "\x1b[33m", "\x1b[31m", "\x1b[35m", "\x1b[0m"},
    /* LOG_CMODE_TRUECOLOR */
    {"\x1b[38;2;150;100;205m", "\x1b[38;2;30;205;255m", "\x1b[38;2;50;205;100m", "\x1b[38;2;205;185;40m",
     "\x1b[38;2;205;30;100m", "\x1b[38;2;205;80;205m", "\x1b[0m"},
};
 
/* Internal error macro - uses g_log directly, only used in this file */
#ifdef NDEBUG
#define LOGGING_INTERNAL_ERROR(error, message, ...)                                                                    \
  do {                                                                                                                 \
    asciichat_set_errno_with_message(error, NULL, 0, NULL, message, ##__VA_ARGS__);                                    \
    static const char *msg_header = "CRITICAL LOGGING SYSTEM ERROR: ";                                                 \
    safe_fprintf(stderr, "%s%s%s: %s", log_level_color(LOG_COLOR_ERROR), msg_header, log_level_color(LOG_COLOR_RESET), \
                 message);                                                                                             \
    platform_write(g_log.file, msg_header, strlen(msg_header));                                                        \
    platform_write(g_log.file, message, strlen(message));                                                              \
    platform_write(g_log.file, "\n", 1);                                                                               \
    platform_print_backtrace(0);                                                                                       \
  } while (0)
#else
#define LOGGING_INTERNAL_ERROR(error, message, ...)                                                                    \
  do {                                                                                                                 \
    asciichat_set_errno_with_message(error, __FILE__, __LINE__, __func__, message, ##__VA_ARGS__);                     \
    static const char *msg_header = "CRITICAL LOGGING SYSTEM ERROR: ";                                                 \
    safe_fprintf(stderr, "%s%s%s: %s", log_level_color(LOG_COLOR_ERROR), msg_header, log_level_color(LOG_COLOR_RESET), \
                 message);                                                                                             \
    platform_write(g_log.file, msg_header, strlen(msg_header));                                                        \
    platform_write(g_log.file, message, strlen(message));                                                              \
    platform_write(g_log.file, "\n", 1);                                                                               \
    platform_print_backtrace(0);                                                                                       \
  } while (0)
#endif
 
/* Terminal capabilities cache */
static terminal_capabilities_t g_terminal_caps = {0};
static bool g_terminal_caps_initialized = false;
static bool g_terminal_caps_detecting = false; /* Guard against recursion */
 
/* Shutdown logging state */
static bool g_shutdown_saved_terminal_output = true; /* Saved state for log_shutdown_begin/end */
static bool g_shutdown_in_progress = false;          /* Track if shutdown phase is active */
 
size_t get_current_time_formatted(char *time_buf) {
  /* Log the rotation event */
  struct timespec ts;
  (void)clock_gettime(CLOCK_REALTIME, &ts);
  struct tm tm_info;
  platform_localtime(&ts.tv_sec, &tm_info);
 
  // Format the time part first
  // strftime returns 0 on error, not negative (and len is size_t/unsigned)
  size_t len = strftime(time_buf, 32, "%H:%M:%S", &tm_info);
  if (len == 0 || len >= 32) {
    LOGGING_INTERNAL_ERROR(ERROR_INVALID_STATE, "Failed to format time");
    return 0;
  }
 
  // Add microseconds manually
  long microseconds = ts.tv_nsec / 1000;
  if (microseconds < 0)
    microseconds = 0;
  if (microseconds > 999999)
    microseconds = 999999;
 
  int result = snprintf(time_buf + len, 32 - len, ".%06ld", microseconds);
  if (result < 0 || result >= (int)(32 - len)) {
    LOGGING_INTERNAL_ERROR(ERROR_INVALID_STATE, "Failed to format microseconds");
    return 0;
  }
 
  return len + (size_t)result;
}
 
char *format_message(const char *format, va_list args) {
  if (!format) {
    return NULL;
  }
 
  // First, determine the size needed
  va_list args_copy;
  va_copy(args_copy, args);
  int size = vsnprintf(NULL, 0, format, args_copy);
  va_end(args_copy);
 
  if (size < 0) {
    LOGGING_INTERNAL_ERROR(ERROR_INVALID_STATE, "Failed to format context message");
    return NULL;
  }
 
  // Allocate and format the message
  char *message = SAFE_MALLOC(size + 1, char *);
  int result = vsnprintf(message, (size_t)size + 1, format, args);
  if (result < 0) {
    SAFE_FREE(message);
    LOGGING_INTERNAL_ERROR(ERROR_INVALID_STATE, "Failed to format context message");
    return NULL;
  }
 
  return message;
}
 
/* ============================================================================
 * Logging Implementation
 * ============================================================================
 */
 
/* Parse LOG_LEVEL environment variable */
static log_level_t parse_log_level_from_env(void) {
  const char *env_level = SAFE_GETENV("LOG_LEVEL");
  if (!env_level) {
    return DEFAULT_LOG_LEVEL; // Default level based on build type
  }
 
  // Case-insensitive comparison
  if (platform_strcasecmp(env_level, "DEV") == 0 || strcmp(env_level, "0") == 0) {
    return LOG_DEV;
  }
  if (platform_strcasecmp(env_level, "DEBUG") == 0 || strcmp(env_level, "1") == 0) {
    return LOG_DEBUG;
  }
  if (platform_strcasecmp(env_level, "INFO") == 0 || strcmp(env_level, "2") == 0) {
    return LOG_INFO;
  }
  if (platform_strcasecmp(env_level, "WARN") == 0 || strcmp(env_level, "3") == 0) {
    return LOG_WARN;
  }
  if (platform_strcasecmp(env_level, "ERROR") == 0 || strcmp(env_level, "4") == 0) {
    return LOG_ERROR;
  }
  if (platform_strcasecmp(env_level, "FATAL") == 0 || strcmp(env_level, "5") == 0) {
    return LOG_FATAL;
  }
 
  // Invalid value - return default
  log_warn("Invalid LOG_LEVEL: %s", env_level);
  return DEFAULT_LOG_LEVEL;
}
 
/* Log rotation function - keeps the tail (recent entries)
 * REQUIRES: rotation_mutex must be held by caller
 * This is the only operation that uses a mutex - regular logging is lock-free.
 */
static void rotate_log_locked(void) {
  int file = atomic_load(&g_log.file);
  size_t current_size = atomic_load(&g_log.current_size);
 
  if (file < 0 || file == STDERR_FILENO || strlen(g_log.filename) == 0) {
    return;
  }
 
  if (current_size < MAX_LOG_SIZE) {
    return;
  }
 
  platform_close(file);
  atomic_store(&g_log.file, -1);
 
  /* Open file for reading to get the tail */
  int read_file = platform_open(g_log.filename, O_RDONLY, 0);
  if (read_file < 0) {
    safe_fprintf(stderr, "Failed to open log file for tail rotation: %s\n", g_log.filename);
    /* Fall back to regular truncation */
    int fd = platform_open(g_log.filename, O_CREAT | O_RDWR | O_TRUNC, FILE_PERM_PRIVATE);
    atomic_store(&g_log.file, fd);
    atomic_store(&g_log.current_size, 0);
    return;
  }
 
  /* Seek to position where we want to start keeping data (keep last 2MB) */
  size_t keep_size = MAX_LOG_SIZE * 2 / 3; /* Keep last 2MB of 3MB file */
  if (current_size < keep_size) {
    platform_close(read_file);
    /* Fall back to truncation since we don't have enough data to rotate */
    int fd = platform_open(g_log.filename, O_CREAT | O_RDWR | O_TRUNC, FILE_PERM_PRIVATE);
    atomic_store(&g_log.file, fd);
    atomic_store(&g_log.current_size, 0);
    return;
  }
  if (lseek(read_file, (off_t)(current_size - keep_size), SEEK_SET) == (off_t)-1) {
    platform_close(read_file);
    /* Fall back to truncation */
    int fd = platform_open(g_log.filename, O_CREAT | O_RDWR | O_TRUNC, FILE_PERM_PRIVATE);
    atomic_store(&g_log.file, fd);
    atomic_store(&g_log.current_size, 0);
    return;
  }
 
  /* Skip to next line boundary to avoid partial lines */
  char c;
  while (platform_read(read_file, &c, 1) > 0 && c != '\n') {
    /* Skip characters until newline */
  }
 
  /* Read the tail into a temporary file */
  char temp_filename[PLATFORM_MAX_PATH_LENGTH];
  int result = snprintf(temp_filename, sizeof(temp_filename), "%s.tmp", g_log.filename);
  if (result <= 0 || result >= (int)sizeof(temp_filename)) {
    LOGGING_INTERNAL_ERROR(ERROR_INVALID_STATE, "Failed to format temp filename");
    platform_close(read_file);
    int fd = platform_open(g_log.filename, O_CREAT | O_RDWR | O_APPEND, FILE_PERM_PRIVATE);
    atomic_store(&g_log.file, fd);
    return;
  }
 
  int temp_file = platform_open(temp_filename, O_CREAT | O_WRONLY | O_TRUNC, FILE_PERM_PRIVATE);
  if (temp_file < 0) {
    platform_close(read_file);
    /* Fall back to truncation */
    int fd = platform_open(g_log.filename, O_CREAT | O_RDWR | O_TRUNC, FILE_PERM_PRIVATE);
    atomic_store(&g_log.file, fd);
    atomic_store(&g_log.current_size, 0);
    return;
  }
 
  /* Copy tail to temp file */
  char buffer[8192];
  ssize_t bytes_read;
  size_t new_size = 0;
  while ((bytes_read = platform_read(read_file, buffer, sizeof(buffer))) > 0) {
    ssize_t written = platform_write(temp_file, buffer, (size_t)bytes_read);
    if (written != bytes_read) {
      platform_close(read_file);
      platform_close(temp_file);
      unlink(temp_filename);
      /* Fall back to truncation */
      int fd = platform_open(g_log.filename, O_CREAT | O_RDWR | O_TRUNC, FILE_PERM_PRIVATE);
      atomic_store(&g_log.file, fd);
      atomic_store(&g_log.current_size, 0);
      return;
    }
    new_size += (size_t)bytes_read;
  }
 
  platform_close(read_file);
  platform_close(temp_file);
 
  /* Replace original with temp file */
  if (rename(temp_filename, g_log.filename) != 0) {
    unlink(temp_filename); /* Clean up temp file */
    /* Fall back to truncation */
    int fd = platform_open(g_log.filename, O_CREAT | O_RDWR | O_TRUNC, FILE_PERM_PRIVATE);
    atomic_store(&g_log.file, fd);
    atomic_store(&g_log.current_size, 0);
    return;
  }
 
  /* Reopen for appending */
  int new_fd = platform_open(g_log.filename, O_CREAT | O_RDWR | O_APPEND, FILE_PERM_PRIVATE);
  if (new_fd < 0) {
    LOGGING_INTERNAL_ERROR(ERROR_INVALID_STATE, "Failed to reopen rotated log file: %s", g_log.filename);
    atomic_store(&g_log.file, STDERR_FILENO);
    g_log.filename[0] = '\0';
    atomic_store(&g_log.current_size, 0);
    return;
  }
  atomic_store(&g_log.file, new_fd);
  atomic_store(&g_log.current_size, new_size);
 
  char time_buf[LOG_TIMESTAMP_BUFFER_SIZE];
  get_current_time_formatted(time_buf);
 
  char log_msg[256];
  int log_msg_len =
      safe_snprintf(log_msg, sizeof(log_msg), "[%s] [INFO] Log tail-rotated (kept %zu bytes)\n", time_buf, new_size);
  if (log_msg_len > 0 && log_msg_len < (int)sizeof(log_msg)) {
    (void)platform_write(new_fd, log_msg, (size_t)log_msg_len);
  }
}
 
/* Check if rotation is needed and perform it (acquires mutex only if needed) */
static void maybe_rotate_log(void) {
  /* Rotation mutex not initialized - skip rotation */
  if (!atomic_load(&g_log.rotation_mutex_initialized)) {
    return;
  }
 
  /* Check mmap path first */
  if (log_mmap_is_active()) {
    size_t used = 0, capacity = 0;
    if (log_mmap_get_usage(&used, &capacity) && capacity > 0) {
      /* Rotate when 90% full to leave room for writes */
      if (used > capacity * 9 / 10) {
        mutex_lock(&g_log.rotation_mutex);
        log_mmap_rotate();
        mutex_unlock(&g_log.rotation_mutex);
      }
    }
    return;
  }
 
  /* File path: quick atomic check - avoid mutex if not needed */
  size_t current_size = atomic_load(&g_log.current_size);
  if (current_size < MAX_LOG_SIZE) {
    return;
  }
 
  /* Size exceeded - acquire mutex and rotate */
  mutex_lock(&g_log.rotation_mutex);
  rotate_log_locked();
  mutex_unlock(&g_log.rotation_mutex);
}
 
void log_init(const char *filename, log_level_t level, bool force_stderr, bool use_mmap) {
  // Initialize rotation mutex (only operation that uses a mutex)
  if (!atomic_load(&g_log.rotation_mutex_initialized)) {
    mutex_init(&g_log.rotation_mutex);
    atomic_store(&g_log.rotation_mutex_initialized, true);
  }
 
  // Set basic config using atomic stores
  atomic_store(&g_log.force_stderr, force_stderr);
  bool preserve_terminal_output = atomic_load(&g_log.terminal_output_enabled);
 
  // Close any existing file (atomic load/store)
  int old_file = atomic_load(&g_log.file);
  if (atomic_load(&g_log.initialized) && old_file >= 0 && old_file != STDERR_FILENO) {
    platform_close(old_file);
    atomic_store(&g_log.file, -1);
  }
 
  // Check LOG_LEVEL environment variable
  const char *env_level_str = SAFE_GETENV("LOG_LEVEL");
  if (env_level_str) {
    atomic_store(&g_log.level, (int)parse_log_level_from_env());
  } else {
    atomic_store(&g_log.level, (int)level);
  }
 
  atomic_store(&g_log.level_manually_set, false);
  atomic_store(&g_log.current_size, 0);
 
  if (filename) {
    SAFE_STRNCPY(g_log.filename, filename, sizeof(g_log.filename) - 1);
 
    if (use_mmap) {
      // Lock-free mmap path - writes go to mmap'd file
      asciichat_error_t mmap_result = log_mmap_init_simple(filename, 0);
      if (mmap_result == ASCIICHAT_OK) {
        atomic_store(&g_log.file, -1); // No regular fd - using mmap for file output
      } else {
        // Mmap failed - use stderr only (atomic writes, lock-free)
        if (preserve_terminal_output) {
          safe_fprintf(stderr, "Mmap logging failed for %s, using stderr only (lock-free)\n", filename);
        }
        atomic_store(&g_log.file, STDERR_FILENO);
        g_log.filename[0] = '\0';
      }
    } else {
      // Lock-free file I/O path - uses atomic write() syscalls
      int fd = platform_open(filename, O_CREAT | O_RDWR | O_TRUNC, FILE_PERM_PRIVATE);
      atomic_store(&g_log.file, (fd >= 0) ? fd : STDERR_FILENO);
      if (fd < 0) {
        if (preserve_terminal_output) {
          safe_fprintf(stderr, "Failed to open log file: %s\n", filename);
        }
        g_log.filename[0] = '\0';
      }
    }
  } else {
    atomic_store(&g_log.file, STDERR_FILENO);
    g_log.filename[0] = '\0';
  }
 
  atomic_store(&g_log.initialized, true);
  atomic_store(&g_log.terminal_output_enabled, preserve_terminal_output);
 
  // Reset terminal detection if needed
  if (g_terminal_caps_initialized && !g_terminal_caps.detection_reliable) {
    g_terminal_caps_initialized = false;
  }
 
  // Detect terminal capabilities
  log_redetect_terminal_capabilities();
}
 
void log_destroy(void) {
  // Destroy mmap logging first (if active)
  if (log_mmap_is_active()) {
    log_mmap_destroy();
  }
 
  // Lock-free cleanup using atomic operations
  int old_file = atomic_load(&g_log.file);
  if (old_file >= 0 && old_file != STDERR_FILENO) {
    platform_close(old_file);
  }
  atomic_store(&g_log.file, -1);
  atomic_store(&g_log.initialized, false);
 
  // Destroy rotation mutex
  if (atomic_load(&g_log.rotation_mutex_initialized)) {
    mutex_destroy(&g_log.rotation_mutex);
    atomic_store(&g_log.rotation_mutex_initialized, false);
  }
}
 
void log_set_level(log_level_t level) {
  atomic_store(&g_log.level, (int)level);
  atomic_store(&g_log.level_manually_set, true);
}
 
log_level_t log_get_level(void) {
  return (log_level_t)atomic_load(&g_log.level);
}
 
void log_set_terminal_output(bool enabled) {
  // Respect --quiet flag: if quiet is set, never enable terminal output
  const options_t *opts = options_get();
  if (!opts) {
    log_error("Options not initialized");
    return;
  }
  if (enabled && opts && opts->quiet) {
    return; // Silently ignore attempts to enable terminal output when --quiet is set
  }
  atomic_store(&g_log.terminal_output_enabled, enabled);
}
 
bool log_get_terminal_output(void) {
  return atomic_load(&g_log.terminal_output_enabled);
}
 
void log_set_force_stderr(bool enabled) {
  atomic_store(&g_log.force_stderr, enabled);
}
 
bool log_get_force_stderr(void) {
  return atomic_load(&g_log.force_stderr);
}
 
bool log_lock_terminal(void) {
  bool previous_state = atomic_exchange(&g_log.terminal_locked, true);
  atomic_store(&g_log.terminal_owner_thread, (uint64_t)asciichat_thread_self());
  return previous_state;
}
 
void log_unlock_terminal(bool previous_state) {
  atomic_store(&g_log.terminal_locked, previous_state);
  if (!previous_state) {
    atomic_store(&g_log.terminal_owner_thread, 0);
  }
}
 
void log_set_flush_delay(unsigned int delay_ms) {
  atomic_store(&g_log.flush_delay_ms, delay_ms);
}
 
void log_truncate_if_large(void) {
  // Log rotation is inherently racy without locks - best-effort only
  // For reliable rotation, use mmap mode or external logrotate
  int file = atomic_load(&g_log.file);
  if (file >= 0 && file != STDERR_FILENO && strlen(g_log.filename) > 0) {
    struct stat st;
    if (fstat(file, &st) == 0 && st.st_size > MAX_LOG_SIZE) {
      atomic_store(&g_log.current_size, (size_t)st.st_size);
    }
  }
}
 
/* Helper: Write formatted log entry to file using atomic write() syscall
 * POSIX guarantees write() is atomic for sizes <= PIPE_BUF (typically 4096 bytes)
 */
static void write_to_log_file_atomic(const char *buffer, int length) {
  if (length <= 0 || buffer == NULL) {
    return;
  }
 
  if (length > MAX_LOG_SIZE) {
    return;
  }
 
  int file = atomic_load(&g_log.file);
  if (file < 0 || file == STDERR_FILENO) {
    return;
  }
 
  // Single atomic write() call - no locking needed
  ssize_t written = platform_write(file, buffer, (size_t)length);
  if (written > 0) {
    atomic_fetch_add(&g_log.current_size, (size_t)written);
    maybe_rotate_log();
  }
}
 
/* Helper: Format log message header (timestamp, level, location info)
 * Returns the number of characters written to the buffer
 */
static int format_log_header(char *buffer, size_t buffer_size, log_level_t level, const char *timestamp,
                             const char *file, int line, const char *func, bool use_colors, bool newline) {
  const char **colors = use_colors ? log_get_color_array() : NULL;
  // Safety check: if colors is NULL, disable colors to prevent crashes
  if (use_colors && colors == NULL) {
    use_colors = false;
  }
  const char *color = use_colors ? colors[level] : "";
  const char *reset = use_colors ? colors[LOG_COLOR_RESET] : "";
 
  const char *level_string = level_strings[level];
  if (level_string == level_strings[LOG_INFO]) {
    level_string = "INFO ";
  } else if (level_string == level_strings[LOG_WARN]) {
    level_string = "WARN ";
  } else if (level_string == level_strings[LOG_DEV]) {
    level_string = "DEV  ";
  }
 
  const char *newline_or_not = newline ? "\n" : "";
 
  int result = 0;
 
#ifdef NDEBUG
  (void)newline_or_not;
  (void)file;
  (void)line;
  (void)func;
 
  // Release mode: Simple one-line format without file/line/function
  if (use_colors) {
    result = snprintf(buffer, buffer_size, "[%s%s%s] [%s%s%s] ", color, timestamp, reset, color, level_string, reset);
  } else {
    result = snprintf(buffer, buffer_size, "[%s] [%s] ", timestamp, level_strings[level]);
  }
#else
  // Debug mode: full format with file location and function
  const char *rel_file = extract_project_relative_path(file);
  if (use_colors) {
    // Use specific colors for file/function info: file=yellow, line=magenta, function=blue
    // Array indices: 0=DEV(Blue), 1=DEBUG(Cyan), 2=INFO(Green), 3=WARN(Yellow), 4=ERROR(Red), 5=FATAL(Magenta)
    const char *file_color = colors[3]; // WARN: Yellow for file paths
    const char *line_color = colors[5]; // FATAL: Magenta for line numbers
    const char *func_color = colors[0]; // DEV: Blue for function names
    result = snprintf(buffer, buffer_size, "[%s%s%s] [%s%s%s] %s%s%s:%s%d%s in %s%s%s(): %s%s", color, timestamp, reset,
                      color, level_string, reset, file_color, rel_file, reset, line_color, line, reset, func_color,
                      func, reset, reset, newline_or_not);
  } else {
    result = snprintf(buffer, buffer_size, "[%s] [%s] %s:%d in %s(): %s", timestamp, level_strings[level], rel_file,
                      line, func, newline_or_not);
  }
#endif
 
  if (result <= 0 || result >= (int)buffer_size) {
    LOGGING_INTERNAL_ERROR(ERROR_INVALID_STATE, "Failed to format log header");
    return -1;
  }
 
  return result;
}
 
/* Note: Terminal buffering removed for lock-free design.
 * When terminal is locked, other threads' output goes to file only.
 */
 
/* Helper: Write colored log entry to terminal (lock-free)
 * Uses atomic loads for state checks, skips output if terminal is locked by another thread
 */
static void write_to_terminal_atomic(log_level_t level, const char *timestamp, const char *file, int line,
                                     const char *func, const char *fmt, va_list args) {
  // Choose output stream: errors/warnings to stderr, info/debug to stdout
  // When force_stderr is enabled (client mode), ALL logs go to stderr to keep stdout clean
  FILE *output_stream;
  if (atomic_load(&g_log.force_stderr)) {
    output_stream = stderr;
  } else {
    output_stream = (level == LOG_ERROR || level == LOG_WARN || level == LOG_FATAL) ? stderr : stdout;
  }
  int fd = output_stream == stderr ? STDERR_FILENO : STDOUT_FILENO;
 
  // Format the header using centralized formatting
  char header_buffer[512];
  bool use_colors = isatty(fd);
 
  int header_len =
      format_log_header(header_buffer, sizeof(header_buffer), level, timestamp, file, line, func, use_colors, false);
  if (header_len <= 0 || header_len >= (int)sizeof(header_buffer)) {
    LOGGING_INTERNAL_ERROR(ERROR_INVALID_STATE, "Failed to format log header");
    return;
  }
 
  // Check if terminal output is enabled (atomic load)
  if (!atomic_load(&g_log.terminal_output_enabled)) {
    return; // Terminal output disabled - skip (no buffering in lock-free mode)
  }
 
  // Check if terminal is locked by another thread
  if (atomic_load(&g_log.terminal_locked)) {
    uint64_t owner = atomic_load(&g_log.terminal_owner_thread);
    if (owner != (uint64_t)asciichat_thread_self()) {
      return; // Terminal locked by another thread - skip
    }
  }
 
  if (use_colors) {
    const char **colors = log_get_color_array();
    if (colors == NULL) {
      safe_fprintf(output_stream, "%s", header_buffer);
      (void)vfprintf(output_stream, fmt, args);
      safe_fprintf(output_stream, "\n");
    } else {
      safe_fprintf(output_stream, "%s", header_buffer);
      safe_fprintf(output_stream, "%s", colors[LOG_COLOR_RESET]);
      (void)vfprintf(output_stream, fmt, args);
      safe_fprintf(output_stream, "%s\n", colors[LOG_COLOR_RESET]);
    }
  } else {
    safe_fprintf(output_stream, "%s", header_buffer);
    (void)vfprintf(output_stream, fmt, args);
    safe_fprintf(output_stream, "\n");
  }
  (void)fflush(output_stream);
}
 
void log_msg(log_level_t level, const char *file, int line, const char *func, const char *fmt, ...) {
  // All state access uses atomic operations - fully lock-free
  if (!atomic_load(&g_log.initialized)) {
    return;
  }
 
  if (level < (log_level_t)atomic_load(&g_log.level)) {
    return;
  }
 
  /* =========================================================================
   * MMAP PATH: When mmap logging is active, writes go to mmap'd file
   * ========================================================================= */
  if (log_mmap_is_active()) {
    maybe_rotate_log();
 
    va_list args;
    va_start(args, fmt);
    char msg_buffer[LOG_MMAP_MSG_BUFFER_SIZE];
    vsnprintf(msg_buffer, sizeof(msg_buffer), fmt, args);
    va_end(args);
 
    log_mmap_write(level, file, line, func, "%s", msg_buffer);
 
    // Terminal output (check with atomic loads)
    if (atomic_load(&g_log.terminal_output_enabled) && !atomic_load(&g_log.terminal_locked)) {
      char time_buf[LOG_TIMESTAMP_BUFFER_SIZE];
      get_current_time_formatted(time_buf);
 
      FILE *output_stream;
      if (atomic_load(&g_log.force_stderr)) {
        output_stream = stderr;
      } else {
        output_stream = (level == LOG_ERROR || level == LOG_WARN || level == LOG_FATAL) ? stderr : stdout;
      }
      int fd = output_stream == stderr ? STDERR_FILENO : STDOUT_FILENO;
      bool use_colors = isatty(fd);
 
      char header_buffer[512];
      int header_len =
          format_log_header(header_buffer, sizeof(header_buffer), level, time_buf, file, line, func, use_colors, false);
 
      if (header_len > 0 && header_len < (int)sizeof(header_buffer)) {
        if (use_colors) {
          const char **colors = log_get_color_array();
          if (colors) {
            safe_fprintf(output_stream, "%s%s%s%s\n", header_buffer, colors[LOG_COLOR_RESET], msg_buffer,
                         colors[LOG_COLOR_RESET]);
          } else {
            safe_fprintf(output_stream, "%s%s\n", header_buffer, msg_buffer);
          }
        } else {
          safe_fprintf(output_stream, "%s%s\n", header_buffer, msg_buffer);
        }
        (void)fflush(output_stream);
      }
    }
    return;
  }
 
  /* =========================================================================
   * FILE I/O PATH: Lock-free using atomic write() syscalls
   * ========================================================================= */
  char time_buf[LOG_TIMESTAMP_BUFFER_SIZE];
  get_current_time_formatted(time_buf);
 
  // Format message for file output
  char log_buffer[LOG_MSG_BUFFER_SIZE];
  va_list args;
  va_start(args, fmt);
 
  int header_len = format_log_header(log_buffer, sizeof(log_buffer), level, time_buf, file, line, func, false, false);
  if (header_len <= 0 || header_len >= (int)sizeof(log_buffer)) {
    LOGGING_INTERNAL_ERROR(ERROR_INVALID_STATE, "Failed to format log header");
    va_end(args);
    return;
  }
 
  int msg_len = header_len;
  int formatted_len = vsnprintf(log_buffer + header_len, sizeof(log_buffer) - (size_t)header_len, fmt, args);
  if (formatted_len < 0) {
    LOGGING_INTERNAL_ERROR(ERROR_INVALID_STATE, "Failed to format log message");
    va_end(args);
    return;
  }
 
  msg_len += formatted_len;
  if (msg_len >= (int)sizeof(log_buffer)) {
    msg_len = sizeof(log_buffer) - 1;
    log_buffer[msg_len] = '\0';
  }
 
  if (msg_len > 0 && msg_len < (int)sizeof(log_buffer) - 1) {
    log_buffer[msg_len++] = '\n';
    log_buffer[msg_len] = '\0';
  }
 
  va_end(args);
 
  // Write to file (atomic write syscall)
  int file_fd = atomic_load(&g_log.file);
  if (file_fd >= 0 && file_fd != STDERR_FILENO) {
    write_to_log_file_atomic(log_buffer, msg_len);
  }
 
  // Write to terminal (atomic state checks)
  va_list args_terminal;
  va_start(args_terminal, fmt);
  write_to_terminal_atomic(level, time_buf, file, line, func, fmt, args_terminal);
  va_end(args_terminal);
}
 
void log_plain_msg(const char *fmt, ...) {
  if (!atomic_load(&g_log.initialized)) {
    return;
  }
 
  if (shutdown_is_requested()) {
    return;
  }
 
  char log_buffer[LOG_MSG_BUFFER_SIZE];
  va_list args;
  va_start(args, fmt);
  int msg_len = vsnprintf(log_buffer, sizeof(log_buffer), fmt, args);
  va_end(args);
 
  if (msg_len <= 0 || msg_len >= (int)sizeof(log_buffer)) {
    return;
  }
 
  // Write to mmap if active
  if (log_mmap_is_active()) {
    log_mmap_write(LOG_INFO, NULL, 0, NULL, "%s", log_buffer);
  } else {
    // Write to file (atomic write syscall)
    int file_fd = atomic_load(&g_log.file);
    if (file_fd >= 0 && file_fd != STDERR_FILENO) {
      write_to_log_file_atomic(log_buffer, msg_len);
      write_to_log_file_atomic("\n", 1);
    }
  }
 
  // Terminal output (atomic state checks)
  if (!atomic_load(&g_log.terminal_output_enabled)) {
    return;
  }
  if (atomic_load(&g_log.terminal_locked)) {
    uint64_t owner = atomic_load(&g_log.terminal_owner_thread);
    if (owner != (uint64_t)asciichat_thread_self()) {
      return;
    }
  }
 
  safe_fprintf(stdout, "%s\n", log_buffer);
  (void)fflush(stdout);
}
 
// Helper for log_plain_stderr variants (lock-free)
static void log_plain_stderr_internal_atomic(const char *fmt, va_list args, bool add_newline) {
  char log_buffer[LOG_MSG_BUFFER_SIZE];
  int msg_len = vsnprintf(log_buffer, sizeof(log_buffer), fmt, args);
 
  if (msg_len <= 0 || msg_len >= (int)sizeof(log_buffer)) {
    return;
  }
 
  // Write to mmap if active
  if (log_mmap_is_active()) {
    log_mmap_write(LOG_INFO, NULL, 0, NULL, "%s", log_buffer);
  } else {
    // Write to file (atomic write syscall)
    int file_fd = atomic_load(&g_log.file);
    if (file_fd >= 0 && file_fd != STDERR_FILENO) {
      write_to_log_file_atomic(log_buffer, msg_len);
      if (add_newline) {
        write_to_log_file_atomic("\n", 1);
      }
    }
  }
 
  // Terminal output (atomic state checks)
  if (!atomic_load(&g_log.terminal_output_enabled)) {
    return;
  }
  if (atomic_load(&g_log.terminal_locked)) {
    uint64_t owner = atomic_load(&g_log.terminal_owner_thread);
    if (owner != (uint64_t)asciichat_thread_self()) {
      return;
    }
  }
 
  if (add_newline) {
    safe_fprintf(stderr, "%s\n", log_buffer);
  } else {
    safe_fprintf(stderr, "%s", log_buffer);
  }
  (void)fflush(stderr);
}
 
void log_plain_stderr_msg(const char *fmt, ...) {
  if (!atomic_load(&g_log.initialized)) {
    return;
  }
  if (shutdown_is_requested()) {
    return;
  }
 
  va_list args;
  va_start(args, fmt);
  log_plain_stderr_internal_atomic(fmt, args, true);
  va_end(args);
}
 
void log_plain_stderr_nonewline_msg(const char *fmt, ...) {
  if (!atomic_load(&g_log.initialized)) {
    return;
  }
  if (shutdown_is_requested()) {
    return;
  }
 
  va_list args;
  va_start(args, fmt);
  log_plain_stderr_internal_atomic(fmt, args, false);
  va_end(args);
}
 
void log_file_msg(const char *fmt, ...) {
  if (!atomic_load(&g_log.initialized)) {
    return;
  }
 
  char log_buffer[LOG_MSG_BUFFER_SIZE];
  va_list args;
  va_start(args, fmt);
  int msg_len = vsnprintf(log_buffer, sizeof(log_buffer), fmt, args);
  va_end(args);
 
  if (msg_len <= 0 || msg_len >= (int)sizeof(log_buffer)) {
    return;
  }
 
  // Write to mmap if active, else to file
  if (log_mmap_is_active()) {
    log_mmap_write(LOG_INFO, NULL, 0, NULL, "%s", log_buffer);
  } else {
    int file_fd = atomic_load(&g_log.file);
    if (file_fd >= 0 && file_fd != STDERR_FILENO) {
      write_to_log_file_atomic(log_buffer, msg_len);
      write_to_log_file_atomic("\n", 1);
    }
  }
}
 
static const char *log_network_direction_label(remote_log_direction_t direction) {
  switch (direction) {
  case REMOTE_LOG_DIRECTION_SERVER_TO_CLIENT:
    return "server→client";
  case REMOTE_LOG_DIRECTION_CLIENT_TO_SERVER:
    return "client→server";
  default:
    return "network";
  }
}
 
static asciichat_error_t log_network_message_internal(socket_t sockfd, const struct crypto_context_t *crypto_ctx,
                                                      log_level_t level, remote_log_direction_t direction,
                                                      const char *file, int line, const char *func, const char *fmt,
                                                      va_list args) {
  if (!fmt) {
    return SET_ERRNO(ERROR_INVALID_PARAM, "Format string is NULL");
  }
 
  va_list args_copy;
  va_copy(args_copy, args);
  char *formatted = format_message(fmt, args_copy);
  va_end(args_copy);
 
  if (!formatted) {
    asciichat_error_t current_error = GET_ERRNO();
    if (current_error == ASCIICHAT_OK) {
      current_error = SET_ERRNO(ERROR_MEMORY, "Failed to format network log message");
    }
    return current_error;
  }
 
  asciichat_error_t send_result = ASCIICHAT_OK;
  if (sockfd == INVALID_SOCKET_VALUE) {
    send_result = SET_ERRNO(ERROR_INVALID_PARAM, "Invalid socket descriptor");
    log_msg(LOG_WARN, file, line, func, "Skipping remote log message: invalid socket descriptor");
  } else {
    send_result = packet_send_remote_log(sockfd, (const crypto_context_t *)crypto_ctx, level, direction, 0, formatted);
    if (send_result != ASCIICHAT_OK) {
      log_msg(LOG_WARN, file, line, func, "Failed to send remote log message: %s", asciichat_error_string(send_result));
    }
  }
 
  const char *direction_label = log_network_direction_label(direction);
  log_msg(level, file, line, func, "[NET %s] %s", direction_label, formatted);
 
  SAFE_FREE(formatted);
  return send_result;
}
 
asciichat_error_t log_network_message(socket_t sockfd, const struct crypto_context_t *crypto_ctx, log_level_t level,
                                      remote_log_direction_t direction, const char *fmt, ...) {
  va_list args;
  va_start(args, fmt);
  asciichat_error_t result =
      log_network_message_internal(sockfd, crypto_ctx, level, direction, NULL, 0, NULL, fmt, args);
  va_end(args);
  return result;
}
 
asciichat_error_t log_net_message(socket_t sockfd, const struct crypto_context_t *crypto_ctx, log_level_t level,
                                  remote_log_direction_t direction, const char *file, int line, const char *func,
                                  const char *fmt, ...) {
  va_list args;
  va_start(args, fmt);
  asciichat_error_t result =
      log_network_message_internal(sockfd, crypto_ctx, level, direction, file, line, func, fmt, args);
  va_end(args);
  return result;
}
 
/* ============================================================================
 * Color Helper Functions
 * ============================================================================ */
 
/* Initialize terminal capabilities if not already done */
static void init_terminal_capabilities(void) {
  // Guard against recursion - this can be called indirectly via log_get_color_array()
  // from detect_terminal_capabilities() which uses logging
  if (g_terminal_caps_detecting) {
    return;
  }
 
  if (!g_terminal_caps_initialized) {
    // Set detecting flag to prevent recursion
    g_terminal_caps_detecting = true;
 
    // NEVER call detect_terminal_capabilities() from here - it causes infinite recursion
    // because detect_terminal_capabilities() uses log_debug() which calls log_get_color_array()
    // which calls init_terminal_capabilities() again.
    // Always use defaults here - log_redetect_terminal_capabilities() will do the actual detection
    // Use safe fallback during logging initialization to avoid recursion
    g_terminal_caps.color_level = TERM_COLOR_16;
    g_terminal_caps.capabilities = TERM_CAP_COLOR_16;
    g_terminal_caps.color_count = 16;
    g_terminal_caps.detection_reliable = false;
    g_terminal_caps_initialized = true;
 
    // Clear detecting flag
    g_terminal_caps_detecting = false;
  }
}
 
/* Re-detect terminal capabilities after logging is initialized */
void log_redetect_terminal_capabilities(void) {
  // Guard against recursion
  if (g_terminal_caps_detecting) {
    return;
  }
 
  // Detect if not initialized, or if we're using defaults (not reliably detected)
  // This ensures we get proper detection after logging is ready, replacing any defaults
  // Once we have reliable detection, never re-detect to keep colors consistent
  if (!g_terminal_caps_initialized || !g_terminal_caps.detection_reliable) {
    g_terminal_caps_detecting = true;
    g_terminal_caps = detect_terminal_capabilities();
    g_terminal_caps_detecting = false;
    g_terminal_caps_initialized = true;
 
    // Now log the capabilities AFTER colors are set, so this log uses the correct colors
    log_debug("Terminal capabilities: color_level=%d, capabilities=0x%x, utf8=%s, fps=%d", g_terminal_caps.color_level,
              g_terminal_caps.capabilities, g_terminal_caps.utf8_support ? "yes" : "no", g_terminal_caps.desired_fps);
 
    // Now that we've detected once with reliable results, keep these colors consistent for all future logs
  }
  // Once initialized with reliable detection, never re-detect to keep colors consistent
}
 
/* Get the appropriate color array based on terminal capabilities */
const char **log_get_color_array(void) {
  init_terminal_capabilities();
 
  log_color_mode_t mode;
  if (g_terminal_caps.color_level >= TERM_COLOR_TRUECOLOR) {
    mode = LOG_CMODE_TRUECOLOR;
  } else if (g_terminal_caps.color_level >= TERM_COLOR_256) {
    mode = LOG_CMODE_256;
  } else {
    mode = LOG_CMODE_16;
  }
 
  /* Cast away const for the pointer-to-pointer return - the array is still const */
  return (const char **)level_colors[mode];
}
 
const char *log_level_color(log_color_t color) {
  const char **colors = log_get_color_array();
  if (colors == NULL) {
    return ""; /* Return empty string if colors not available */
  }
  if (color >= 0 && color <= LOG_COLOR_RESET) {
    return colors[color];
  }
  return colors[LOG_COLOR_RESET]; /* Return reset color if invalid */
}
 
/* ============================================================================
 * Lock-Free MMAP Logging Integration
 * ============================================================================ */
 
asciichat_error_t log_enable_mmap(const char *log_path) {
  return log_enable_mmap_sized(log_path, 0); /* Use default size */
}
 
asciichat_error_t log_enable_mmap_sized(const char *log_path, size_t max_size) {
  if (!log_path) {
    return SET_ERRNO(ERROR_INVALID_PARAM, "log_path is required");
  }
 
  // Initialize mmap logging - text is written directly to the mmap'd file
  asciichat_error_t result = log_mmap_init_simple(log_path, max_size);
  if (result != ASCIICHAT_OK) {
    return result;
  }
 
  log_info("Lock-free mmap logging enabled: %s", log_path);
  return ASCIICHAT_OK;
}
 
void log_disable_mmap(void) {
  if (log_mmap_is_active()) {
    log_mmap_destroy();
    log_info("Lock-free mmap logging disabled");
  }
}
 
/* ============================================================================
 * Shutdown Logging Control
 * ============================================================================ */
 
void log_shutdown_begin(void) {
  if (g_shutdown_in_progress) {
    return; /* Already in shutdown phase */
  }
 
  /* Save current terminal output state and disable console output */
  g_shutdown_saved_terminal_output = atomic_load(&g_log.terminal_output_enabled);
  atomic_store(&g_log.terminal_output_enabled, false);
  g_shutdown_in_progress = true;
}
 
void log_shutdown_end(void) {
  if (!g_shutdown_in_progress) {
    return; /* Not in shutdown phase */
  }
 
  /* Restore previous terminal output state */
  atomic_store(&g_log.terminal_output_enabled, g_shutdown_saved_terminal_output);
  g_shutdown_in_progress = false;
}