Logo AND Algorithmique Numérique Distribuée

Public GIT Repository
First attempt to display log categoy hierarchy.
[simgrid.git] / src / xbt / log.c
index f985905..2b4f6e2 100644 (file)
@@ -1,8 +1,7 @@
-/* $Id$ */
-
 /* log - a generic logging facility in the spirit of log4j                  */
 
-/* Copyright (c) 2003-2007 Martin Quinson. All rights reserved.             */
+/* Copyright (c) 2004-2011. The SimGrid Team.
+ * All rights reserved.                                                     */
 
 /* This program is free software; you can redistribute it and/or modify it
  * under the terms of the license (GNU LGPL) which comes with this package. */
 #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
  *
@@ -182,14 +184,10 @@ compile with the -Wall option, gcc will warn you for unmatched arguments, ie
 when you pass a pointer to a string where an integer was specified by the
 format. This is usually a good idea.
 
-Because some C compilers do not support vararg macros, there is a version of
-the macro for any number of arguments from 0 to 6. The macro name ends with
-the total number of arguments.
-
 Here is an example of the most basic type of macro. This is a logging
 request with priority <i>warning</i>.
 
-<code>CLOG5(MyCat, gras_log_priority_warning, "Values are: %d and '%s'", 5,
+<code>XBT_CLOG(MyCat, gras_log_priority_warning, "Values are: %d and '%s'", 5,
 "oops");</code>
 
 A logging request is said to be enabled if its priority is higher than or
@@ -202,7 +200,7 @@ example, one of the standard priorities is used, then there is a convenience
 macro that is typically used instead. For example, the above example is
 equivalent to the shorter:
 
-<code>CWARN4(MyCat, "Values are: %d and '%s'", 5, "oops");</code>
+<code>XBT_CWARN(MyCat, "Values are: %d and '%s'", 5, "oops");</code>
 
 \section log_API_isenabled 2.3 Checking if a particular category/priority is enabled
 
@@ -220,7 +218,7 @@ If \ref XBT_LOG_NEW_DEFAULT_SUBCATEGORY(MyCat, Parent) or
 \ref XBT_LOG_NEW_DEFAULT_CATEGORY(MyCat) is used to create the
 category, then the even shorter form can be used:
 
-<code>WARN3("Values are: %s and '%d'", 5, "oops");</code>
+<code>XBT_WARN("Values are: %s and '%d'", 5, "oops");</code>
 
 Only one default category can be created per file, though multiple
 non-defaults can be created and used.
@@ -230,28 +228,21 @@ non-defaults can be created and used.
 First of all, each module should register its own category into the categories
 tree using \ref XBT_LOG_NEW_DEFAULT_SUBCATEGORY.
 
-Then, logging should be done with the DEBUG<n>, VERB<n>, INFO<n>, WARN<n>,
-ERROR<n> or CRITICAL<n> macro families (such as #DEBUG10, #VERB10,
-#INFO10, #WARN10, #ERROR10 and #CRITICAL10). For each group, there is at
-least 11 different macros (like DEBUG0, DEBUG1, DEBUG2, DEBUG3, DEBUG4 and
-DEBUG5, DEBUG6, DEBUG7, DEBUG8, DEBUG9, DEBUG10), only differing in the number of arguments passed along the format.
-This is because we want SimGrid itself to keep compilable on ancient
-compiler not supporting variable number of arguments to macros. But we
-should provide a macro simpler to use for the users not interested in SP3
-machines (FIXME).
+Then, logging should be done with the #XBT_DEBUG, #XBT_VERB, #XBT_INFO,
+#XBT_WARN, #XBT_ERROR and #XBT_CRITICAL macros.
 
 Under GCC, these macro check there arguments the same way than printf does. So,
 if you compile with -Wall, the following code will issue a warning:
-<code>DEBUG2("Found %s (id %f)", some_string, a_double)</code>
+<code>XBT_DEBUG("Found %s (id %d)", some_string, a_double)</code>
 
 If you want to specify the category to log onto (for example because you
 have more than one category per file, add a C before the name of the log
-producing macro (ie, use #CDEBUG10, #CVERB10, #CINFO10, #CWARN10, #CERROR10 and
-#CCRITICAL10 and friends), and pass the category name as first argument.
+producing macro (ie, use #XBT_CDEBUG, #XBT_CVERB, #XBT_CINFO, #XBT_CWARN,
+#XBT_CERROR and #XBT_CCRITICAL and friends), and pass the category name as
+first argument.
 
 The TRACE priority is not used the same way than the other. You should use
-the #XBT_IN, XBT_IN<n> (up to #XBT_IN5), #XBT_OUT and #XBT_HERE macros
-instead.
+the #XBT_IN, #XBT_OUT and #XBT_HERE macros instead.
 
 \section log_API_example 2.6 Example of use
 
@@ -269,17 +260,17 @@ int main() {
        xbt_log_control_set("SA.thresh:3");
 
        / * This request is enabled, because WARNING >= INFO. * /
-       CWARN2(VSS, "Low fuel level.");
+       XBT_CWARN(VSS, "Low fuel level.");
 
        / * This request is disabled, because DEBUG < INFO. * /
-       CDEBUG2(VSS, "Starting search for nearest gas station.");
+       XBT_CDEBUG(VSS, "Starting search for nearest gas station.");
 
        / * The default category SA inherits its priority from VSS. Thus,
           the following request is enabled because INFO >= INFO.  * /
-       INFO1("Located nearest gas station.");
+       XBT_INFO("Located nearest gas station.");
 
        / * This request is disabled, because DEBUG < INFO. * /
-       DEBUG1("Exiting gas station search");
+       XBT_DEBUG("Exiting gas station search");
 }
 \endverbatim
 
@@ -309,7 +300,15 @@ displayed by setting a threshold to each category through the
 For example, \verbatim --log=root.thres:debug\endverbatim will make
 SimGrid <b>extremely</b> verbose while \verbatim
 --log=root.thres:critical\endverbatim should shut it almost
-completely off.
+completely off. The full list of recognized thresholds is the following:
+
+ - trace: enter and return of some functions
+ - debug: crufty output
+ - verbose: verbose output for the user wanting more
+ - info: output about the regular functionning
+ - warning: minor issue encountered
+ - error: issue encountered
+ - critical: major issue encountered 
 
 \subsection log_use_conf_multi 3.1.2 Passing several settings
 
@@ -364,18 +363,25 @@ Here are the existing format directives:
 
 
 If you want to mimic the simple layout with the format one, you would use this
-format: '[%%h:%%i:(%%I) %%r] %%l: [%%c/%%p] %%m%%n'. This is not completely correct
+format: '[%%h:%%i:(%%i) %%r] %%l: [%%c/%%p] %%m%%n'. This is not completely correct
 because the simple layout do not display the message location for messages at
-priority INFO (thus, the fmt is '[%%h:%%i:(%%I) %%r] %%l: [%%c/%%p] %%m%%n' in this
+priority INFO (thus, the fmt is '[%%h:%%i:(%%i) %%r] [%%c/%%p] %%m%%n' in this
 case). Moreover, if there is no process name (ie, messages coming from the
 library itself, or test programs doing strange things) do not display the
 process identity (thus, fmt is '[%%r] %%l: [%%c/%%p] %%m%%n' in that case, and '[%%r]
 [%%c/%%p] %%m%%n' if they are at priority INFO).
 
-For now, there is only one format modifier: the precision field. You
-can for example specify %.4r to get the application age with 4
-numbers after the radix. Another limitation is that you cannot set
-specific layouts to the several priorities.
+For now, there is only two format modifiers: the precision and the
+width fields. You can for example specify %.4r to get the application
+age with 4 numbers after the radix, or %15p to get the process name
+on 15 columns. Finally, you can specify %10.6r to get the time on at
+most 10 columns, with 6 numbers after the radix. 
+
+Note that when specifying the width, it is filled with spaces. That
+is to say that for example %5r in your format is converted to "% 5f"
+for printf (note the extra space); there is no way to fill the empty
+columns with 0 (ie, pass "%05f" to printf). Another limitation is
+that you cannot set specific layouts to the several priorities.
 
 \subsection log_use_conf_app 3.1.4 Category appender
 
@@ -460,20 +466,15 @@ The default appender function currently prints to stderr, and the only other
 existing one writes to the specified file. More would be needed, like the one
 able to send the logs to a remote dedicated server.
 This is on our TODO list for quite a while now, but your help would be
-welcome here, too.
-
-
-                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                                              *//*' */
-
+welcome here, too. */
 
 xbt_log_appender_t xbt_log_default_appender = NULL;     /* set in log_init */
 xbt_log_layout_t xbt_log_default_layout = NULL; /* set in log_init */
-int _log_usable = 0;
 
 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;
@@ -485,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);
   }
 }
@@ -507,20 +507,34 @@ 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 */ ,
-    0 /* isThreshInherited */ ,
-    NULL /* appender */ , NULL /* layout */ ,
-    0                           /* additivity */
+      "root",
+      0 /*initialized */, xbt_log_priority_uninitialized /* threshold */ ,
+      0 /* isThreshInherited */ ,
+      NULL /* appender */ , NULL /* layout */ ,
+      0                         /* additivity */
 };
 
 XBT_LOG_NEW_CATEGORY(xbt, "All XBT categories (simgrid toolbox)");
 XBT_LOG_NEW_CATEGORY(surf, "All SURF categories");
 XBT_LOG_NEW_CATEGORY(msg, "All MSG categories");
 XBT_LOG_NEW_CATEGORY(simix, "All SIMIX categories");
+XBT_LOG_NEW_CATEGORY(mc, "All MC categories");
+XBT_LOG_NEW_CATEGORY(bindings, "All bindings categories");
 
 XBT_LOG_NEW_DEFAULT_SUBCATEGORY(log, xbt,
                                 "Loggings from the logging mechanism itself");
 
+/* create the default appender and install it in the root category,
+   which were already created (damnit. Too slow little beetle) */
+void xbt_log_preinit(void)
+{
+  xbt_log_default_appender = xbt_log_appender_file_new(NULL);
+  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
  *
  * xbt_log_control_set() is called on each string we got from cmd line
@@ -530,18 +544,10 @@ void xbt_log_init(int *argc, char **argv)
   int i, j;
   char *opt;
 
-  /* create the default appender and install it in the root category,
-     which were already created (damnit. Too slow little beetle) */
-  xbt_log_default_appender = xbt_log_appender_file_new(NULL);
-  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_usable = 1;
-
   //    _XBT_LOGV(log).threshold = xbt_log_priority_debug; /* uncomment to set the LOG category to debug directly */
 
   /* Set logs and init log submodule */
-  for (i = 1; i < *argc; i++) {
+  for (j = i = 1; i < *argc; i++) {
     if (!strncmp(argv[i], "--log=", strlen("--log=")) ||
         !strncmp(argv[i], "--gras-log=", strlen("--gras-log=")) ||
         !strncmp(argv[i], "--surf-log=", strlen("--surf-log=")) ||
@@ -550,25 +556,22 @@ void xbt_log_init(int *argc, char **argv)
         !strncmp(argv[i], "--xbt-log=", strlen("--xbt-log="))) {
 
       if (strncmp(argv[i], "--log=", strlen("--log=")))
-        WARN2
-          ("Option %.*s is deprecated and will disapear in the future. Use --log instead.",
-           (int) (strchr(argv[i], '=') - argv[i]), argv[i]);
+        XBT_WARN
+            ("Option %.*s is deprecated and will disapear in the future. Use --log instead.",
+             (int) (strchr(argv[i], '=') - argv[i]), argv[i]);
 
       opt = strchr(argv[i], '=');
       opt++;
       xbt_log_control_set(opt);
-      DEBUG1("Did apply '%s' as log setting", opt);
-      /*remove this from argv */
-
-      for (j = i + 1; j < *argc; j++) {
-        argv[j - 1] = argv[j];
-      }
-
-      argv[j - 1] = NULL;
-      (*argc)--;
-      i--;                      /* compensate effect of next loop incrementation */
+      XBT_DEBUG("Did apply '%s' as log setting", opt);
+    } else {
+      argv[j++] = argv[i];
     }
   }
+  if (j < *argc) {
+    argv[j] = NULL;
+    *argc = j;
+  }
 }
 
 static void log_cat_exit(xbt_log_category_t cat)
@@ -590,124 +593,123 @@ static void log_cat_exit(xbt_log_category_t cat)
     log_cat_exit(child);
 }
 
-void xbt_log_exit(void)
+void xbt_log_postexit(void)
 {
-  VERB0("Exiting log");
+  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));
-  _log_usable = 0;
 }
 
+ /* 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;
-  if (!_log_usable) {
-    /* Make sure that the layouts have been malloced */
-    xbt_log_default_appender = xbt_log_appender_file_new(NULL);
-    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_usable = 1;
-  }
 
-  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_assert1(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 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
+ * _xbt_log_cat_init().  Thus, if we want to avoid an infinite
+ * recursion, we can not use the standard logging macros in
+ * _xbt_log_cat_init(), and in all functions called from it.
+ *
+ * To circumvent the problem, we define the macro_xbt_log_init() as
+ * (0) for the length of the affected functions, and we do not forget
+ * to undefine it at the end!
+ */
+
 static void _xbt_log_cat_apply_set(xbt_log_category_t category,
                                    xbt_log_setting_t setting)
 {
-
-  s_xbt_log_event_t _log_ev;
+#define _xbt_log_cat_init(a, b) (0)
 
   if (setting->thresh != xbt_log_priority_uninitialized) {
     xbt_log_threshold_set(category, setting->thresh);
 
-    if (category->threshold <= xbt_log_priority_debug) {
-      _log_ev.cat = category;
-      _log_ev.priority = xbt_log_priority_debug;
-      _log_ev.fileName = __FILE__;
-      _log_ev.functionName = _XBT_FUNCTION;
-      _log_ev.lineNum = __LINE__;
-
-      _xbt_log_event_log(&_log_ev,
-                         "Apply settings for category '%s': set threshold to %s (=%d)",
-                         category->name,
-                         xbt_log_priority_names[category->threshold],
-                         category->threshold);
-    }
+    XBT_DEBUG("Apply settings for category '%s': set threshold to %s (=%d)",
+           category->name, xbt_log_priority_names[category->threshold],
+           category->threshold);
   }
 
   if (setting->fmt) {
     xbt_log_layout_set(category, xbt_log_layout_format_new(setting->fmt));
 
-    if (category->threshold <= xbt_log_priority_debug) {
-      _log_ev.cat = category;
-      _log_ev.priority = xbt_log_priority_debug;
-      _log_ev.fileName = __FILE__;
-      _log_ev.functionName = _XBT_FUNCTION;
-      _log_ev.lineNum = __LINE__;
-
-      _xbt_log_event_log(&_log_ev,
-                         "Apply settings for category '%s': set format to %s",
-                         category->name, setting->fmt);
-    }
+    XBT_DEBUG("Apply settings for category '%s': set format to %s",
+           category->name, setting->fmt);
   }
 
   if (setting->additivity != -1) {
     xbt_log_additivity_set(category, setting->additivity);
 
-    if (category->threshold <= xbt_log_priority_debug) {
-      _log_ev.cat = category;
-      _log_ev.priority = xbt_log_priority_debug;
-      _log_ev.fileName = __FILE__;
-      _log_ev.functionName = _XBT_FUNCTION;
-      _log_ev.lineNum = __LINE__;
-
-      _xbt_log_event_log(&_log_ev,
-                         "Apply settings for category '%s': set additivity to %s",
-                         category->name,
-                         (setting->additivity ? "on" : "off"));
-    }
+    XBT_DEBUG("Apply settings for category '%s': set additivity to %s",
+           category->name, (setting->additivity ? "on" : "off"));
   }
   if (setting->appender) {
     xbt_log_appender_set(category, setting->appender);
     if (!category->layout)
       xbt_log_layout_set(category, xbt_log_layout_simple_new(NULL));
     category->additivity = 0;
-    if (category->threshold <= xbt_log_priority_debug) {
-      _log_ev.cat = category;
-      _log_ev.priority = xbt_log_priority_debug;
-      _log_ev.fileName = __FILE__;
-      _log_ev.functionName = _XBT_FUNCTION;
-      _log_ev.lineNum = __LINE__;
-
-      _xbt_log_event_log(&_log_ev,
-                         "Set %p as appender of category '%s'",
-                         setting->appender, category->name);
-    }
+    XBT_DEBUG("Set %p as appender of category '%s'",
+           setting->appender, category->name);
   }
-
+#undef _xbt_log_cat_init
 }
 
 /*
@@ -718,30 +720,30 @@ static void _xbt_log_cat_apply_set(xbt_log_category_t category,
 int _xbt_log_cat_init(xbt_log_category_t category,
                       e_xbt_log_priority_t priority)
 {
+#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;
-  s_xbt_log_event_t _log_ev;
-
-  if (_XBT_LOGV(log).threshold <= xbt_log_priority_debug
-      && _XBT_LOGV(log).threshold != xbt_log_priority_uninitialized) {
-    _log_ev.cat = &_XBT_LOGV(log);
-    _log_ev.priority = xbt_log_priority_debug;
-    _log_ev.fileName = __FILE__;
-    _log_ev.functionName = _XBT_FUNCTION;
-    _log_ev.lineNum = __LINE__;
-    _xbt_log_event_log(&_log_ev,
-                       "Initializing category '%s' (firstChild=%s, nextSibling=%s)",
-                       category->name,
-                       (category->firstChild ? category->
-                        firstChild->name : "none"),
-                       (category->nextSibling ? category->
-                        nextSibling->name : "none"));
-  }
+
+  XBT_DEBUG("Initializing category '%s' (firstChild=%s, nextSibling=%s)",
+         category->name,
+         (category->firstChild ? category->firstChild->name : "none"),
+         (category->nextSibling ? category->nextSibling->name : "none"));
 
   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 {
@@ -749,21 +751,14 @@ int _xbt_log_cat_init(xbt_log_category_t category,
     if (!category->parent)
       category->parent = &_XBT_LOGV(XBT_LOG_ROOT_CAT);
 
-    if (_XBT_LOGV(log).threshold <= xbt_log_priority_debug
-        && _XBT_LOGV(log).threshold != xbt_log_priority_uninitialized) {
-      _log_ev.lineNum = __LINE__;
-      _xbt_log_event_log(&_log_ev, "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->name);
-    }
+    XBT_DEBUG("Set %s (%s) as father of %s ",
+           category->parent->name,
+           (category->parent->initialized ?
+            xbt_log_priority_names[category->parent->threshold] : "uninited"),
+           category->name);
     xbt_log_parent_set(category, category->parent);
 
-    if (_XBT_LOGV(log).threshold < xbt_log_priority_info
-        && _XBT_LOGV(log).threshold != xbt_log_priority_uninitialized) {
+    if (XBT_LOG_ISENABLED(log, xbt_log_priority_debug)) {
       char *buf, *res = NULL;
       xbt_log_category_t cpp = category->parent->firstChild;
       while (cpp) {
@@ -777,12 +772,10 @@ int _xbt_log_cat_init(xbt_log_category_t category,
         cpp = cpp->nextSibling;
       }
 
-      _log_ev.lineNum = __LINE__;
-      _xbt_log_event_log(&_log_ev,
-                         "Childs of %s: %s; nextSibling: %s",
-                         category->parent->name, res,
-                         (category->parent->nextSibling ? category->
-                          parent->nextSibling->name : "none"));
+      XBT_DEBUG("Childs of %s: %s; nextSibling: %s",
+             category->parent->name, res,
+             (category->parent->nextSibling ?
+              category->parent->nextSibling->name : "none"));
 
       free(res);
     }
@@ -790,58 +783,46 @@ int _xbt_log_cat_init(xbt_log_category_t category,
   }
 
   /* Apply the control */
-  if (!xbt_log_settings)
-    return priority >= category->threshold;
-
-  xbt_assert0(category, "NULL category");
-  xbt_assert(category->name);
-
-  xbt_dynar_foreach(xbt_log_settings, cursor, setting) {
-    xbt_assert0(setting, "Damnit, NULL cat in the list");
-    xbt_assert1(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 && category->threshold <= xbt_log_priority_verbose) {
 
-    _log_ev.cat = &_XBT_LOGV(log);
-    _log_ev.priority = xbt_log_priority_verbose;
-    _log_ev.fileName = __FILE__;
-    _log_ev.functionName = _XBT_FUNCTION;
-    _log_ev.lineNum = __LINE__;
-
-    _xbt_log_event_log(&_log_ev,
-                       "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
 }
 
 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);
 
-  xbt_assert0(cat, "NULL category to be given a parent");
-  xbt_assert1(parent, "The parent category of %s is NULL", cat->name);
+  /* if the category is initialized, unlink from current parent */
+  if (cat->initialized) {
 
-  /*
-   * if the threshold is initialized
-   * unlink from current parent
-   */
-  if (cat->threshold != xbt_log_priority_uninitialized) {
-
-    xbt_log_category_t *cpp = &parent->firstChild;
+    xbt_log_category_t *cpp = &cat->parent->firstChild;
 
     while (*cpp != cat && *cpp != NULL) {
       cpp = &(*cpp)->nextSibling;
@@ -856,15 +837,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) {
-
+  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)
@@ -875,7 +853,7 @@ static void _set_inherited_thresholds(xbt_log_category_t cat)
   for (; child != NULL; child = child->nextSibling) {
     if (child->isThreshInherited) {
       if (cat != &_XBT_LOGV(log))
-        VERB3("Set category threshold of %s to %s (=%d)",
+        XBT_VERB("Set category threshold of %s to %s (=%d)",
               child->name, xbt_log_priority_names[cat->threshold],
               cat->threshold);
       child->threshold = cat->threshold;
@@ -910,7 +888,7 @@ static xbt_log_setting_t _xbt_log_parse_setting(const char *control_string)
 
   if (!*control_string)
     return set;
-  DEBUG1("Parse log setting '%s'", control_string);
+  XBT_DEBUG("Parse log setting '%s'", control_string);
 
   control_string += strspn(control_string, " ");
   name = control_string;
@@ -920,7 +898,7 @@ static xbt_log_setting_t _xbt_log_parse_setting(const char *control_string)
   eq = control_string;
   control_string += strcspn(control_string, " ");
 
-  xbt_assert1(*dot == '.' && (*eq == '=' || *eq == ':'),
+  xbt_assert(*dot == '.' && (*eq == '=' || *eq == ':'),
               "Invalid control string '%s'", control_string);
 
   if (!strncmp(dot + 1, "thresh", (size_t) (eq - dot - 1))) {
@@ -934,17 +912,17 @@ static xbt_log_setting_t _xbt_log_parse_setting(const char *control_string)
       }
     }
 
-    DEBUG1("New priority name = %s", neweq);
+    XBT_DEBUG("New priority name = %s", neweq);
     for (i = 0; i < xbt_log_priority_infinite; i++) {
       if (!strncmp(xbt_log_priority_names[i], neweq, p - eq)) {
-        DEBUG1("This is priority %d", i);
+        XBT_DEBUG("This is priority %d", i);
         break;
       }
     }
     if (i < xbt_log_priority_infinite) {
       set->thresh = (e_xbt_log_priority_t) i;
     } else {
-      THROW1(arg_error, 0,
+      THROWF(arg_error, 0,
              "Unknown priority name: %s (must be one of: trace,debug,verbose,info,warning,error,critical)",
              eq + 1);
     }
@@ -960,7 +938,8 @@ static xbt_log_setting_t _xbt_log_parse_setting(const char *control_string)
         *p -= 'a' - 'A';
       }
     }
-    if (!strcmp(neweq, "ON") || !strcmp(neweq, "YES") || !strcmp(neweq, "1")) {
+    if (!strcmp(neweq, "ON") || !strcmp(neweq, "YES")
+        || !strcmp(neweq, "1")) {
       set->additivity = 1;
     } else {
       set->additivity = 0;
@@ -974,7 +953,7 @@ static xbt_log_setting_t _xbt_log_parse_setting(const char *control_string)
     if (!strncmp(neweq, "file:", 5)) {
       set->appender = xbt_log_appender_file_new(neweq + 5);
     } else {
-      THROW1(arg_error, 0, "Unknown appender log type: '%s'", neweq);
+      THROWF(arg_error, 0, "Unknown appender log type: '%s'", neweq);
     }
     free(neweq);
   } else if (!strncmp(dot + 1, "fmt", (size_t) (eq - dot - 1))) {
@@ -982,13 +961,14 @@ static xbt_log_setting_t _xbt_log_parse_setting(const char *control_string)
   } else {
     char buff[512];
     snprintf(buff, min(512, eq - dot), "%s", dot + 1);
-    THROW1(arg_error, 0, "Unknown setting of the log category: '%s'", buff);
+    THROWF(arg_error, 0, "Unknown setting of the log category: '%s'",
+           buff);
   }
   set->catname = (char *) xbt_malloc(dot - name + 1);
 
   memcpy(set->catname, name, dot - name);
   set->catname[dot - name] = '\0';      /* Just in case */
-  DEBUG1("This is for cat '%s'", set->catname);
+  XBT_DEBUG("This is for cat '%s'", set->catname);
 
   return set;
 }
@@ -998,14 +978,14 @@ static xbt_log_category_t _xbt_log_cat_searchsub(xbt_log_category_t cat,
 {
   xbt_log_category_t child, res;
 
-  DEBUG4("Search '%s' into '%s' (firstChild='%s'; nextSibling='%s')", name,
+  XBT_DEBUG("Search '%s' into '%s' (firstChild='%s'; nextSibling='%s')", name,
          cat->name, (cat->firstChild ? cat->firstChild->name : "none"),
          (cat->nextSibling ? cat->nextSibling->name : "none"));
   if (!strcmp(cat->name, name))
     return cat;
 
   for (child = cat->firstChild; child != NULL; child = child->nextSibling) {
-    DEBUG1("Dig into %s", child->name);
+    XBT_DEBUG("Dig into %s", child->name);
     res = _xbt_log_cat_searchsub(child, name);
     if (res)
       return res;
@@ -1048,8 +1028,13 @@ void xbt_log_control_set(const char *control_string)
 
   if (!control_string)
     return;
-  DEBUG1("Parse log settings '%s'", control_string);
+  XBT_DEBUG("Parse log settings '%s'", control_string);
 
+  /* Special handling of no_loc request, which asks for any file localization to be omitted (for tesh runs) */
+  if (!strcmp(control_string, "no_loc")) {
+    xbt_log_no_loc = 1;
+    return;
+  }
   /* some initialization if this is the first time that this get called */
   if (xbt_log_settings == NULL)
     xbt_log_settings = xbt_dynar_new(sizeof(xbt_log_setting_t),
@@ -1058,7 +1043,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;
   }
@@ -1069,16 +1054,17 @@ void xbt_log_control_set(const char *control_string)
     xbt_log_category_t cat = NULL;
 
     set = _xbt_log_parse_setting(str);
-    cat = _xbt_log_cat_searchsub(&_XBT_LOGV(XBT_LOG_ROOT_CAT), set->catname);
+    cat =
+        _xbt_log_cat_searchsub(&_XBT_LOGV(XBT_LOG_ROOT_CAT), set->catname);
 
     if (cat) {
-      DEBUG0("Apply directly");
+      XBT_DEBUG("Apply directly");
       _xbt_log_cat_apply_set(cat, set);
       _free_setting((void *) &set);
     } else {
 
-      DEBUG0("Store for further application");
-      DEBUG1("push %p to the settings", (void *) set);
+      XBT_DEBUG("Store for further application");
+      XBT_DEBUG("push %p to the settings", (void *) set);
       xbt_dynar_push(xbt_log_settings, &set);
     }
   }
@@ -1097,24 +1083,126 @@ void xbt_log_appender_set(xbt_log_category_t cat, xbt_log_appender_t app)
 
 void xbt_log_layout_set(xbt_log_category_t cat, xbt_log_layout_t lay)
 {
+#define _xbt_log_cat_init(a, b) (0)
   if (!cat->appender) {
-    VERB1("No appender to category %s. Setting the file appender as default",
-          cat->name);
+    XBT_VERB
+        ("No appender to category %s. Setting the file appender as default",
+         cat->name);
     xbt_log_appender_set(cat, xbt_log_appender_file_new(NULL));
   }
-  if (cat->layout && cat != &_XBT_LOGV(root)) {
-    /* better leak the default layout than check every categories to
-       change it */
+  if (cat->layout) {
     if (cat->layout->free_) {
       cat->layout->free_(cat->layout);
-      free(cat->layout);
     }
+    free(cat->layout);
   }
   cat->layout = lay;
   xbt_log_additivity_set(cat, 0);
+#undef _xbt_log_cat_init
 }
 
 void xbt_log_additivity_set(xbt_log_category_t cat, int additivity)
 {
   cat->additivity = additivity;
 }
+
+void xbt_log_help(void)
+{
+  printf(
+"Description of the logging output:\n"
+"\n"
+"   Threshold configuration: --log=CATEGORY_NAME.thres:PRIORITY_LEVEL\n"
+"      CATEGORY_NAME: defined in code with function 'XBT_LOG_NEW_CATEGORY'\n"
+"      PRIORITY_LEVEL: the level to print (trace,debug,verbose,info,warning,error,critical)\n"
+"         -> trace: enter and return of some functions\n"
+"         -> debug: crufty output\n"
+"         -> verbose: verbose output for the user wanting more\n"
+"         -> info: output about the regular functionning\n"
+"         -> warning: minor issue encountered\n"
+"         -> error: issue encountered\n"
+"         -> critical: major issue encountered\n"
+"\n"
+"   Format configuration: --log=CATEGORY_NAME.fmt:OPTIONS\n"
+"      OPTIONS may be:\n"
+"         -> %%%%: the %% char\n"
+"         -> %%n: platform-dependent line separator (LOG4J compatible)\n"
+"         -> %%e: plain old space (SimGrid extension)\n"
+"\n"
+"         -> %%m: user-provided message\n"
+"\n"
+"         -> %%c: Category name (LOG4J compatible)\n"
+"         -> %%p: Priority name (LOG4J compatible)\n"
+"\n"
+"         -> %%h: Hostname (SimGrid extension)\n"
+"         -> %%P: Process name (SimGrid extension)\n"
+"         -> %%t: Thread \"name\" (LOG4J compatible -- actually the address of the thread in memory)\n"
+"         -> %%i: Process PID (SimGrid extension -- this is a 'i' as in 'i'dea)\n"
+"\n"
+"         -> %%F: file name where the log event was raised (LOG4J compatible)\n"
+"         -> %%l: location where the log event was raised (LOG4J compatible, like '%%F:%%L' -- this is a l as in 'l'etter)\n"
+"         -> %%L: line number where the log event was raised (LOG4J compatible)\n"
+"         -> %%M: function name (LOG4J compatible -- called method name here of course).\n"
+"                 Defined only when using gcc because there is no __FUNCTION__ elsewhere.\n"
+"\n"
+"         -> %%b: full backtrace (Called %%throwable in LOG4J). Defined only under windows or when using the GNU libc because\n"
+"                 backtrace() is not defined elsewhere, and we only have a fallback for windows boxes, not mac ones for example.\n"
+"         -> %%B: short backtrace (only the first line of the %%b). Called %%throwable{short} in LOG4J; defined where %%b is.\n"
+"\n"
+"         -> %%d: date (UNIX-like epoch)\n"
+"         -> %%r: application age (time elapsed since the beginning of the application)\n"
+"\n"
+    );
+}
+
+static int xbt_log_cat_cmp(const void *pa, const void *pb)
+{
+  xbt_log_category_t a = *(xbt_log_category_t *)pa;
+  xbt_log_category_t b = *(xbt_log_category_t *)pb;
+  return strcmp(a->name, b->name);
+}
+
+static void xbt_log_help_categories_rec(xbt_log_category_t category,
+                                        const char *prefix)
+{
+  char *this_prefix;
+  char *child_prefix;
+  xbt_dynar_t dynar;
+  unsigned i;
+  xbt_log_category_t cat;
+
+  if (!category)
+    return;
+
+  if (category->parent) {
+    this_prefix = bprintf("%s \\_ ", prefix);
+    child_prefix = bprintf("%s |  ", prefix);
+  } else {
+    this_prefix = bprintf("%s", prefix);
+    child_prefix = bprintf("%s", prefix);
+  }
+
+  dynar = xbt_dynar_new(sizeof(xbt_log_category_t), NULL);
+  for (cat = category ; cat != NULL; cat = cat->nextSibling)
+    xbt_dynar_push_as(dynar, xbt_log_category_t, cat);
+
+  xbt_dynar_sort(dynar, xbt_log_cat_cmp);
+
+  for (i = 0; i < xbt_dynar_length(dynar); i++) {
+    if (i == xbt_dynar_length(dynar) - 1 && category->parent)
+      *strrchr(child_prefix, '|') = ' ';
+    cat = xbt_dynar_get_as(dynar, i, xbt_log_category_t);
+    printf("%s%s\n", this_prefix, cat->name);
+    xbt_log_help_categories_rec(cat->firstChild, child_prefix);
+  }
+
+  xbt_dynar_free(&dynar);
+  xbt_free(this_prefix);
+  xbt_free(child_prefix);
+}
+
+void xbt_log_help_categories(void)
+{
+  printf("Current log category hierarchy:\n");
+  xbt_log_help_categories_rec(&_XBT_LOGV(XBT_LOG_ROOT_CAT), "   ");
+  printf("\n");
+}