Logo AND Algorithmique Numérique Distribuée

Public GIT Repository
Fix another race in log initializations.
[simgrid.git] / src / xbt / log.c
index d712637..23c908b 100644 (file)
@@ -1,6 +1,6 @@
 /* log - a generic logging facility in the spirit of log4j                  */
 
-/* Copyright (c) 2004, 2005, 2006, 2007, 2008, 2009, 2010. The SimGrid Team.
+/* Copyright (c) 2004-2011. The SimGrid Team.
  * All rights reserved.                                                     */
 
 /* This program is free software; you can redistribute it and/or modify it
 #include "xbt/sysdep.h"
 #include "xbt/log_private.h"
 #include "xbt/dynar.h"
+#include "xbt/xbt_os_thread.h"
 
 XBT_PUBLIC_DATA(int) (*xbt_pid) ();
 int xbt_log_no_loc = 0;         /* if set to true (with --log=no_loc), file localization will be omitted (for tesh tests) */
+static xbt_os_rmutex_t log_cat_init_mutex = NULL;
 
 /** \addtogroup XBT_log
  *
@@ -471,8 +473,8 @@ xbt_log_layout_t xbt_log_default_layout = NULL; /* set in log_init */
 
 typedef struct {
   char *catname;
-  e_xbt_log_priority_t thresh;
   char *fmt;
+  e_xbt_log_priority_t thresh;
   int additivity;
   xbt_log_appender_t appender;
 } s_xbt_log_setting_t, *xbt_log_setting_t;
@@ -484,8 +486,7 @@ static void _free_setting(void *s)
   xbt_log_setting_t set = *(xbt_log_setting_t *) s;
   if (set) {
     free(set->catname);
-    if (set->fmt)
-      free(set->fmt);
+    free(set->fmt);
     free(set);
   }
 }
@@ -506,7 +507,8 @@ const char *xbt_log_priority_names[8] = {
 
 s_xbt_log_category_t _XBT_LOGV(XBT_LOG_ROOT_CAT) = {
   NULL /*parent */ , NULL /* firstChild */ , NULL /* nextSibling */ ,
-      "root", xbt_log_priority_uninitialized /* threshold */ ,
+      "root",
+      0 /*initialized */, xbt_log_priority_uninitialized /* threshold */ ,
       0 /* isThreshInherited */ ,
       NULL /* appender */ , NULL /* layout */ ,
       0                         /* additivity */
@@ -530,6 +532,7 @@ void xbt_log_preinit(void)
   xbt_log_default_layout = xbt_log_layout_simple_new(NULL);
   _XBT_LOGV(XBT_LOG_ROOT_CAT).appender = xbt_log_default_appender;
   _XBT_LOGV(XBT_LOG_ROOT_CAT).layout = xbt_log_default_layout;
+  log_cat_init_mutex = xbt_os_rmutex_init();
 }
 
 /** @brief Get all logging settings from the command line
@@ -596,38 +599,73 @@ static void log_cat_exit(xbt_log_category_t cat)
 void xbt_log_postexit(void)
 {
   XBT_VERB("Exiting log");
+  xbt_os_rmutex_destroy(log_cat_init_mutex);
   xbt_dynar_free(&xbt_log_settings);
   log_cat_exit(&_XBT_LOGV(XBT_LOG_ROOT_CAT));
 }
 
+ /* Size of the static string in which we  build the log string */
+#define XBT_LOG_STATIC_BUFFER_SIZE 2048
+/* Minimum size of the dynamic string in which we build the log string
+   (should be greater than XBT_LOG_STATIC_BUFFER_SIZE) */
+#define XBT_LOG_DYNAMIC_BUFFER_SIZE 4096
+
 void _xbt_log_event_log(xbt_log_event_t ev, const char *fmt, ...)
 {
-
   xbt_log_category_t cat = ev->cat;
 
-  va_start(ev->ap, fmt);
-  va_start(ev->ap_copy, fmt);
-  while (1) {
+  xbt_assert(ev->priority >= 0,
+             "Negative logging priority naturally forbidden");
+  xbt_assert(ev->priority < sizeof(xbt_log_priority_names),
+             "Priority %d is greater than the biggest allowed value",
+             ev->priority);
+
+  do {
     xbt_log_appender_t appender = cat->appender;
-    if (appender != NULL) {
-      xbt_assert(cat->layout,
-                  "No valid layout for the appender of category %s",
-                  cat->name);
-      cat->layout->do_layout(cat->layout, ev, fmt, appender);
+
+    if (!appender)
+      continue;                 /* No appender, try next */
+
+    xbt_assert(cat->layout,
+               "No valid layout for the appender of category %s", cat->name);
+
+    /* First, try with a static buffer */
+    if (XBT_LOG_STATIC_BUFFER_SIZE) {
+      char buff[XBT_LOG_STATIC_BUFFER_SIZE];
+      int done;
+      ev->buffer = buff;
+      ev->buffer_size = sizeof buff;
+      va_start(ev->ap, fmt);
+      done = cat->layout->do_layout(cat->layout, ev, fmt);
+      va_end(ev->ap);
+      if (done) {
+        appender->do_append(appender, buff);
+        continue;               /* Ok, that worked: go next */
+      }
     }
-    if (!cat->additivity)
-      break;
 
-    cat = cat->parent;
-  }
-  va_end(ev->ap);
-  va_end(ev->ap_copy);
+    /* The static buffer was too small, use a dynamically expanded one */
+    ev->buffer_size = XBT_LOG_DYNAMIC_BUFFER_SIZE;
+    ev->buffer = xbt_malloc(ev->buffer_size);
+    while (1) {
+      int done;
+      va_start(ev->ap, fmt);
+      done = cat->layout->do_layout(cat->layout, ev, fmt);
+      va_end(ev->ap);
+      if (done)
+        break;                  /* Got it */
+      ev->buffer_size *= 2;
+      ev->buffer = xbt_realloc(ev->buffer, ev->buffer_size);
+    }
+    appender->do_append(appender, ev->buffer);
+    xbt_free(ev->buffer);
 
-#ifdef _XBT_WIN32
-  free(ev->buffer);
-#endif
+  } while (cat->additivity && (cat = cat->parent, 1));
 }
 
+#undef XBT_LOG_DYNAMIC_BUFFER_SIZE
+#undef XBT_LOG_STATIC_BUFFER_SIZE
+
 /* NOTE:
  *
  * The standard logging macros use _XBT_LOG_ISENABLED, which calls
@@ -687,6 +725,17 @@ int _xbt_log_cat_init(xbt_log_category_t category,
 {
 #define _xbt_log_cat_init(a, b) (0)
 
+  if (log_cat_init_mutex != NULL) {
+    xbt_os_rmutex_acquire(log_cat_init_mutex);
+  }
+
+  if (category->initialized) {
+    if (log_cat_init_mutex != NULL) {
+      xbt_os_rmutex_release(log_cat_init_mutex);
+    }
+    return priority >= category->threshold;
+  }
+
   unsigned int cursor;
   xbt_log_setting_t setting = NULL;
   int found = 0;
@@ -698,7 +747,6 @@ int _xbt_log_cat_init(xbt_log_category_t category,
 
   if (category == &_XBT_LOGV(XBT_LOG_ROOT_CAT)) {
     category->threshold = xbt_log_priority_info;
-    /* xbt_log_priority_debug */ ;
     category->appender = xbt_log_default_appender;
     category->layout = xbt_log_default_layout;
   } else {
@@ -708,9 +756,8 @@ int _xbt_log_cat_init(xbt_log_category_t category,
 
     XBT_DEBUG("Set %s (%s) as father of %s ",
            category->parent->name,
-           (category->parent->threshold == xbt_log_priority_uninitialized ?
-            "uninited" : xbt_log_priority_names[category->
-                                                parent->threshold]),
+           (category->parent->initialized ?
+            xbt_log_priority_names[category->parent->threshold] : "uninited"),
            category->name);
     xbt_log_parent_set(category, category->parent);
 
@@ -739,32 +786,32 @@ int _xbt_log_cat_init(xbt_log_category_t category,
   }
 
   /* Apply the control */
-  if (!xbt_log_settings)
-    return priority >= category->threshold;
-
-  xbt_assert(category, "NULL category");
-  xbt_assert(category->name);
-
-  xbt_dynar_foreach(xbt_log_settings, cursor, setting) {
-    xbt_assert(setting, "Damnit, NULL cat in the list");
-    xbt_assert(setting->catname, "NULL setting(=%p)->catname",
-                (void *) setting);
-
-    if (!strcmp(setting->catname, category->name)) {
-
-      found = 1;
-
-      _xbt_log_cat_apply_set(category, setting);
-
-      xbt_dynar_cursor_rm(xbt_log_settings, &cursor);
+  if (xbt_log_settings) {
+    xbt_assert(category, "NULL category");
+    xbt_assert(category->name);
+
+    xbt_dynar_foreach(xbt_log_settings, cursor, setting) {
+      xbt_assert(setting, "Damnit, NULL cat in the list");
+      xbt_assert(setting->catname, "NULL setting(=%p)->catname",
+                 (void *) setting);
+
+      if (!strcmp(setting->catname, category->name)) {
+        found = 1;
+        _xbt_log_cat_apply_set(category, setting);
+        xbt_dynar_cursor_rm(xbt_log_settings, &cursor);
+      }
     }
-  }
 
-  if (!found)
-    XBT_DEBUG("Category '%s': inherited threshold = %s (=%d)",
-           category->name, xbt_log_priority_names[category->threshold],
-           category->threshold);
+    if (!found)
+      XBT_DEBUG("Category '%s': inherited threshold = %s (=%d)",
+                category->name, xbt_log_priority_names[category->threshold],
+                category->threshold);
+  }
 
+  category->initialized = 1;
+  if (log_cat_init_mutex != NULL) {
+    xbt_os_rmutex_release(log_cat_init_mutex);
+  }
   return priority >= category->threshold;
 
 #undef _xbt_log_cat_init
@@ -772,17 +819,13 @@ int _xbt_log_cat_init(xbt_log_category_t category,
 
 void xbt_log_parent_set(xbt_log_category_t cat, xbt_log_category_t parent)
 {
-
   xbt_assert(cat, "NULL category to be given a parent");
   xbt_assert(parent, "The parent category of %s is NULL", cat->name);
 
-  /*
-   * if the threshold is initialized
-   * unlink from current parent
-   */
-  if (cat->threshold != xbt_log_priority_uninitialized) {
+  /* if the category is initialized, unlink from current parent */
+  if (cat->initialized) {
 
-    xbt_log_category_t *cpp = &parent->firstChild;
+    xbt_log_category_t *cpp = &cat->parent->firstChild;
 
     while (*cpp != cat && *cpp != NULL) {
       cpp = &(*cpp)->nextSibling;
@@ -797,16 +840,12 @@ void xbt_log_parent_set(xbt_log_category_t cat, xbt_log_category_t parent)
 
   parent->firstChild = cat;
 
-  if (parent->threshold == xbt_log_priority_uninitialized) {
-
-    _xbt_log_cat_init(parent,
-                      xbt_log_priority_uninitialized /* ignored */ );
-  }
+  if (!parent->initialized)
+    _xbt_log_cat_init(parent, xbt_log_priority_uninitialized /* ignored */ );
 
   cat->threshold = parent->threshold;
 
   cat->isThreshInherited = 1;
-
 }
 
 static void _set_inherited_thresholds(xbt_log_category_t cat)
@@ -1007,7 +1046,7 @@ void xbt_log_control_set(const char *control_string)
   /* split the string, and remove empty entries */
   set_strings = xbt_str_split_quoted(control_string);
 
-  if (xbt_dynar_length(set_strings) == 0) {     /* vicious user! */
+  if (xbt_dynar_is_empty(set_strings)) {     /* vicious user! */
     xbt_dynar_free(&set_strings);
     return;
   }