Merge pull request #380 from dpw13/feat/logging-msec

Add milliseconds to logging output

Author: matteius

src/core/logger.c

@@ -332,59 +332,32 @@ static void build_ctx_prefix(char *buf, size_t bufsz,
 static void do_log_internal(log_level_t level,
                              const char *component, const char *stream,
                              const char *format, va_list args) {
-    // Copy va_list: a va_list may only be traversed once; copying satisfies
-    // static-analysis tools (clang-analyzer-valist.Uninitialized).
-    va_list args_copy;
-    va_copy(args_copy, args);
-
-    // CRITICAL: Check if logger is shutting down or destroyed.
-    // Write directly to console without the mutex to avoid use-after-destroy.
-    if (logger.shutdown) {
-        char message[4096];
-        vsnprintf(message, sizeof(message), format, args_copy); // NOLINT(clang-analyzer-valist.Uninitialized)
-        va_end(args_copy);
-
-        time_t now;
-        struct tm tm_buf;
-        char timestamp[32];
-        time(&now);
-        strftime(timestamp, sizeof(timestamp), "%Y-%m-%d %H:%M:%S",
-                 localtime_r(&now, &tm_buf));
-
-        char ctx_prefix[224] = {0};
-        build_ctx_prefix(ctx_prefix, sizeof(ctx_prefix), component, stream);
-
-        FILE *console = (level == LOG_LEVEL_ERROR) ? stderr : stdout;
-        fprintf(console, "[%s] [%s] %s%s\n",
-                timestamp, log_level_strings[level], ctx_prefix, message);
-        fflush(console);
-        return;
-    }
-
     // Only log messages at or below the configured log level.
     if (level > logger.log_level) {
-        va_end(args_copy);
         return;
     }
 
-    time_t now;
+    // Create timestamp
+    struct timespec now;
+    clock_gettime(CLOCK_REALTIME, &now);
+
     struct tm tm_buf;
+    localtime_r(&now.tv_sec, &tm_buf);
+
     char timestamp[32];
-    char iso_timestamp[32];
+    size_t offset = strftime(timestamp, sizeof(timestamp), "%Y-%m-%d %H:%M:%S", &tm_buf);
 
-    time(&now);
-    localtime_r(&now, &tm_buf);
-    strftime(timestamp,     sizeof(timestamp),     "%Y-%m-%d %H:%M:%S",  &tm_buf);
-    strftime(iso_timestamp, sizeof(iso_timestamp), "%Y-%m-%dT%H:%M:%S",  &tm_buf);
+    unsigned int msec = (unsigned int)(now.tv_nsec / 1000000UL);
+    snprintf(timestamp + offset, sizeof(timestamp) - offset, ".%03u", msec);
 
     char message[4096];
-    vsnprintf(message, sizeof(message), format, args_copy); // NOLINT(clang-analyzer-valist.Uninitialized)
-    va_end(args_copy);
+    vsnprintf(message, sizeof(message), format, args);
 
     char ctx_prefix[224] = {0};
     build_ctx_prefix(ctx_prefix, sizeof(ctx_prefix), component, stream);
 
-    // Double-check shutdown before acquiring mutex.
+    // CRITICAL: Check if logger is shutting down or destroyed.
+    // Write directly to console without the mutex to avoid use-after-destroy.
     if (logger.shutdown) {
         FILE *console = (level == LOG_LEVEL_ERROR) ? stderr : stdout;
         fprintf(console, "[%s] [%s] %s%s\n",
@@ -421,6 +394,9 @@ static void do_log_internal(log_level_t level,
     pthread_mutex_unlock(&logger.mutex);
 
     if (write_json_log) {
+        char iso_timestamp[32];
+
+        strftime(iso_timestamp, sizeof(iso_timestamp), "%Y-%m-%dT%H:%M:%S",  &tm_buf);
         write_json_log(level, iso_timestamp, message);
     }
 }