flambda-backend: Ensure GC logs are printed atomically (ocaml-flambda…

…#2874)

(cherry picked from commit 7e1b316)

runtime/caml/osdeps.h

@@ -97,8 +97,12 @@ extern char_os *caml_secure_getenv(char_os const *var);
    cannot be determined, return -1. */
 extern int caml_num_rows_fd(int fd);
 
-/* Print a timestamp for verbose GC logs */
-extern void caml_print_timestamp(FILE* channel, int formatted);
+/* Print a timestamp for verbose GC logs.
+
+   Arguments as per snprintf: takes a buf and size, returns the length
+   of the formatted string (which may be greater than sz, in which
+   case the string is truncated) */
+extern int caml_format_timestamp(char* buf, size_t sz, int formatted);
 
 /* Memory management platform-specific operations */
 

runtime/misc.c

@@ -79,20 +79,32 @@ void caml_alloc_point_here(void)
 
 atomic_uintnat caml_verb_gc = 0;
 
+static void print_log(char* msg, int newline, va_list ap)
+{
+  char buf[GC_LOG_LENGTH];
+  int pos = 0;
+  if (caml_verb_gc & 0x1000) {
+    pos += caml_format_timestamp(buf, sizeof(buf),
+                                 caml_verb_gc & 0x2000);
+  }
+  pos += snprintf(buf+pos, sizeof(buf)-pos,
+                  "[%02d] ",
+                  (Caml_state_opt != NULL) ? Caml_state_opt->id : -1);
+  pos += vsnprintf(buf+pos, sizeof(buf)-pos, msg, ap);
+  /* truncate if too long */
+  if (pos >= sizeof(buf) - 1) pos = sizeof(buf) - 1;
+  if (newline) buf[pos++] = '\n';
+  fwrite(buf, 1, pos, stderr);
+  fflush(stderr);
+}
+
 void caml_gc_log (char *msg, ...)
 {
   if ((atomic_load_relaxed(&caml_verb_gc) & 0x800) != 0) {
-    char fmtbuf[GC_LOG_LENGTH];
-    va_list args;
-    va_start (args, msg);
-    if (caml_verb_gc & 0x1000) {
-      caml_print_timestamp(stderr, caml_verb_gc & 0x2000);
-    }
-    snprintf(fmtbuf, GC_LOG_LENGTH, "[%02d] %s\n",
-             (Caml_state_opt != NULL) ? Caml_state_opt->id : -1, msg);
-    vfprintf(stderr, fmtbuf, args);
-    va_end (args);
-    fflush(stderr);
+    va_list ap;
+    va_start (ap, msg);
+    print_log(msg, 1, ap);
+    va_end (ap);
   }
 }
 
@@ -101,12 +113,8 @@ void caml_gc_message (int level, char *msg, ...)
   if ((atomic_load_relaxed(&caml_verb_gc) & level) != 0){
     va_list ap;
     va_start(ap, msg);
-    if (caml_verb_gc & 0x1000) {
-      caml_print_timestamp(stderr, caml_verb_gc & 0x2000);
-    }
-    vfprintf (stderr, msg, ap);
+    print_log(msg, 0, ap);
     va_end(ap);
-    fflush (stderr);
   }
 }
 

runtime/unix.c

@@ -464,12 +464,12 @@ int caml_num_rows_fd(int fd)
 #endif
 }
 
-void caml_print_timestamp(FILE* channel, int formatted)
+int caml_format_timestamp(char* buf, size_t sz, int formatted)
 {
   struct timeval tv;
   gettimeofday(&tv, NULL);
   if (!formatted) {
-    fprintf(channel, "%ld.%06d ", (long)tv.tv_sec, (int)tv.tv_usec);
+    return snprintf(buf, sz, "%ld.%06d ", (long)tv.tv_sec, (int)tv.tv_usec);
   } else {
     struct tm tm;
     char tz[64] = "Z";
@@ -480,7 +480,7 @@ void caml_print_timestamp(FILE* channel, int formatted)
       if (tzmin < 0) {tzmin += 60; tzhour--;}
       sprintf(tz, "%+03ld:%02ld", tzhour, tzmin);
     }
-    fprintf(channel,
+    return snprintf(buf, sz,
             "[%04d-%02d-%02d %02d:%02d:%02d.%06d%s] ",
             1900 + tm.tm_year,
             tm.tm_mon + 1,