1 /* log - a generic logging facility in the spirit of log4j */
3 /* Copyright (c) 2004-2018. The SimGrid Team. All rights reserved. */
5 /* This program is free software; you can redistribute it and/or modify it
6 * under the terms of the license (GNU LGPL) which comes with this package. */
10 #include <stdio.h> /* snprintf */
11 #include <stdlib.h> /* snprintf */
13 #include "src/internal_config.h"
15 #include "src/xbt_modinter.h"
17 #include "src/xbt/log_private.h"
18 #include "xbt/asserts.h"
19 #include "xbt/dynar.h"
23 #include "xbt/sysdep.h"
24 #include "xbt/xbt_os_thread.h"
27 #define MIN(a, b) ((a) < (b) ? (a) : (b))
30 #define MAX(a, b) ((a) > (b) ? (a) : (b))
33 int xbt_log_no_loc = 0; /* if set to true (with --log=no_loc), file localization will be omitted (for tesh tests) */
34 static xbt_os_mutex_t log_cat_init_mutex = NULL;
36 /** @addtogroup XBT_log
38 * For more information, please refer to @ref outcomes_logs Section.
41 xbt_log_appender_t xbt_log_default_appender = NULL; /* set in log_init */
42 xbt_log_layout_t xbt_log_default_layout = NULL; /* set in log_init */
47 e_xbt_log_priority_t thresh;
49 xbt_log_appender_t appender;
50 } s_xbt_log_setting_t;
52 typedef s_xbt_log_setting_t* xbt_log_setting_t;
54 static xbt_dynar_t xbt_log_settings = NULL;
56 static void _free_setting(void *s)
58 xbt_log_setting_t set = *(xbt_log_setting_t *) s;
66 static void _xbt_log_cat_apply_set(xbt_log_category_t category, xbt_log_setting_t setting);
68 const char *xbt_log_priority_names[8] = {
79 s_xbt_log_category_t _XBT_LOGV(XBT_LOG_ROOT_CAT) = {
80 NULL /*parent */ , NULL /* firstChild */ , NULL /* nextSibling */ ,
81 "root", "The common ancestor for all categories",
82 0 /*initialized */, xbt_log_priority_uninitialized /* threshold */ ,
83 0 /* isThreshInherited */ ,
84 NULL /* appender */ , NULL /* layout */ ,
88 XBT_LOG_NEW_DEFAULT_SUBCATEGORY(log, xbt, "Loggings from the logging mechanism itself");
90 /* create the default appender and install it in the root category,
91 which were already created (damnit. Too slow little beetle) */
92 void xbt_log_preinit(void)
94 xbt_log_default_appender = xbt_log_appender_file_new(NULL);
95 xbt_log_default_layout = xbt_log_layout_simple_new(NULL);
96 _XBT_LOGV(XBT_LOG_ROOT_CAT).appender = xbt_log_default_appender;
97 _XBT_LOGV(XBT_LOG_ROOT_CAT).layout = xbt_log_default_layout;
98 log_cat_init_mutex = xbt_os_mutex_init();
101 static void xbt_log_help(void);
102 static void xbt_log_help_categories(void);
104 /** @brief Get all logging settings from the command line
106 * xbt_log_control_set() is called on each string we got from cmd line
108 void xbt_log_init(int *argc, char **argv)
110 unsigned help_requested = 0; /* 1: logs; 2: categories */
112 int parse_args = 1; // Stop parsing the parameters once we found '--'
114 /* Set logs and init log submodule */
115 for (int i = 1; i < *argc; i++) {
116 if (!strcmp("--", argv[i])) {
118 argv[j++] = argv[i]; // Keep the '--' for sg_config
119 } else if (parse_args && !strncmp(argv[i], "--log=", strlen("--log="))) {
120 char* opt = strchr(argv[i], '=');
122 xbt_log_control_set(opt);
123 XBT_DEBUG("Did apply '%s' as log setting", opt);
124 } else if (parse_args && !strcmp(argv[i], "--help-logs")) {
125 help_requested |= 1U;
126 } else if (parse_args && !strcmp(argv[i], "--help-log-categories")) {
127 help_requested |= 2U;
137 if (help_requested) {
138 if (help_requested & 1)
140 if (help_requested & 2)
141 xbt_log_help_categories();
146 static void log_cat_exit(xbt_log_category_t cat)
148 xbt_log_category_t child;
151 if (cat->appender->free_)
152 cat->appender->free_(cat->appender);
156 if (cat->layout->free_)
157 cat->layout->free_(cat->layout);
161 for (child = cat->firstChild; child != NULL; child = child->nextSibling)
165 void xbt_log_postexit(void)
167 XBT_VERB("Exiting log");
168 xbt_os_mutex_destroy(log_cat_init_mutex);
169 xbt_dynar_free(&xbt_log_settings);
170 log_cat_exit(&_XBT_LOGV(XBT_LOG_ROOT_CAT));
173 /* Size of the static string in which we build the log string */
174 #define XBT_LOG_STATIC_BUFFER_SIZE 2048
175 /* Minimum size of the dynamic string in which we build the log string
176 (should be greater than XBT_LOG_STATIC_BUFFER_SIZE) */
177 #define XBT_LOG_DYNAMIC_BUFFER_SIZE 4096
179 void _xbt_log_event_log(xbt_log_event_t ev, const char *fmt, ...)
181 xbt_log_category_t cat = ev->cat;
183 xbt_assert(ev->priority >= 0, "Negative logging priority naturally forbidden");
184 xbt_assert(ev->priority < sizeof(xbt_log_priority_names), "Priority %d is greater than the biggest allowed value",
188 xbt_log_appender_t appender = cat->appender;
190 if (appender != NULL) {
191 xbt_assert(cat->layout, "No valid layout for the appender of category %s", cat->name);
193 /* First, try with a static buffer */
195 char buff[XBT_LOG_STATIC_BUFFER_SIZE];
197 ev->buffer_size = sizeof buff;
198 va_start(ev->ap, fmt);
199 done = cat->layout->do_layout(cat->layout, ev, fmt);
202 appender->do_append(appender, buff);
205 /* The static buffer was too small, use a dynamically expanded one */
206 ev->buffer_size = XBT_LOG_DYNAMIC_BUFFER_SIZE;
207 ev->buffer = xbt_malloc(ev->buffer_size);
209 va_start(ev->ap, fmt);
210 done = cat->layout->do_layout(cat->layout, ev, fmt);
214 ev->buffer_size *= 2;
215 ev->buffer = xbt_realloc(ev->buffer, ev->buffer_size);
217 appender->do_append(appender, ev->buffer);
218 xbt_free(ev->buffer);
222 if (!cat->additivity)
230 * The standard logging macros use _XBT_LOG_ISENABLED, which calls _xbt_log_cat_init(). Thus, if we want to avoid an
231 * infinite recursion, we can not use the standard logging macros in _xbt_log_cat_init(), and in all functions called
234 * To circumvent the problem, we define the macro DISABLE_XBT_LOG_CAT_INIT() to hide the real _xbt_log_cat_init(). The
235 * macro has to be called at the beginning of the affected functions.
237 static int fake_xbt_log_cat_init(xbt_log_category_t XBT_ATTRIB_UNUSED category,
238 e_xbt_log_priority_t XBT_ATTRIB_UNUSED priority)
242 #define DISABLE_XBT_LOG_CAT_INIT() \
243 int (*_xbt_log_cat_init)(xbt_log_category_t, e_xbt_log_priority_t) XBT_ATTRIB_UNUSED = fake_xbt_log_cat_init;
245 static void _xbt_log_cat_apply_set(xbt_log_category_t category, xbt_log_setting_t setting)
247 DISABLE_XBT_LOG_CAT_INIT();
248 if (setting->thresh != xbt_log_priority_uninitialized) {
249 xbt_log_threshold_set(category, setting->thresh);
251 XBT_DEBUG("Apply settings for category '%s': set threshold to %s (=%d)",
252 category->name, xbt_log_priority_names[category->threshold], category->threshold);
256 xbt_log_layout_set(category, xbt_log_layout_format_new(setting->fmt));
258 XBT_DEBUG("Apply settings for category '%s': set format to %s", category->name, setting->fmt);
261 if (setting->additivity != -1) {
262 xbt_log_additivity_set(category, setting->additivity);
264 XBT_DEBUG("Apply settings for category '%s': set additivity to %s",
265 category->name, (setting->additivity ? "on" : "off"));
267 if (setting->appender) {
268 xbt_log_appender_set(category, setting->appender);
269 if (!category->layout)
270 xbt_log_layout_set(category, xbt_log_layout_simple_new(NULL));
271 category->additivity = 0;
272 XBT_DEBUG("Set %p as appender of category '%s'", setting->appender, category->name);
277 * This gets called the first time a category is referenced and performs the initialization.
278 * Also resets threshold to inherited!
280 int _xbt_log_cat_init(xbt_log_category_t category, e_xbt_log_priority_t priority)
282 DISABLE_XBT_LOG_CAT_INIT();
283 if (log_cat_init_mutex != NULL)
284 xbt_os_mutex_acquire(log_cat_init_mutex);
286 if (category->initialized) {
287 if (log_cat_init_mutex != NULL)
288 xbt_os_mutex_release(log_cat_init_mutex);
289 return priority >= category->threshold;
293 xbt_log_setting_t setting = NULL;
295 XBT_DEBUG("Initializing category '%s' (firstChild=%s, nextSibling=%s)", category->name,
296 (category->firstChild ? category->firstChild->name : "none"),
297 (category->nextSibling ? category->nextSibling->name : "none"));
299 if (category == &_XBT_LOGV(XBT_LOG_ROOT_CAT)) {
300 category->threshold = xbt_log_priority_info;
301 category->appender = xbt_log_default_appender;
302 category->layout = xbt_log_default_layout;
304 if (!category->parent)
305 category->parent = &_XBT_LOGV(XBT_LOG_ROOT_CAT);
307 XBT_DEBUG("Set %s (%s) as father of %s ", category->parent->name,
308 (category->parent->initialized ? xbt_log_priority_names[category->parent->threshold] : "uninited"),
310 xbt_log_parent_set(category, category->parent);
312 if (XBT_LOG_ISENABLED(log, xbt_log_priority_debug)) {
315 xbt_log_category_t cpp = category->parent->firstChild;
318 buf = bprintf("%s %s", res, cpp->name);
322 res = xbt_strdup(cpp->name);
324 cpp = cpp->nextSibling;
327 XBT_DEBUG("Children of %s: %s; nextSibling: %s", category->parent->name, res,
328 (category->parent->nextSibling ? category->parent->nextSibling->name : "none"));
334 /* Apply the control */
335 if (xbt_log_settings) {
336 xbt_assert(category, "NULL category");
337 xbt_assert(category->name);
340 xbt_dynar_foreach(xbt_log_settings, cursor, setting) {
341 xbt_assert(setting, "Damnit, NULL cat in the list");
342 xbt_assert(setting->catname, "NULL setting(=%p)->catname", (void *) setting);
344 if (!strcmp(setting->catname, category->name)) {
346 _xbt_log_cat_apply_set(category, setting);
347 xbt_dynar_cursor_rm(xbt_log_settings, &cursor);
352 XBT_DEBUG("Category '%s': inherited threshold = %s (=%d)",
353 category->name, xbt_log_priority_names[category->threshold], category->threshold);
356 category->initialized = 1;
357 if (log_cat_init_mutex != NULL)
358 xbt_os_mutex_release(log_cat_init_mutex);
359 return priority >= category->threshold;
362 void xbt_log_parent_set(xbt_log_category_t cat, xbt_log_category_t parent)
364 xbt_assert(cat, "NULL category to be given a parent");
365 xbt_assert(parent, "The parent category of %s is NULL", cat->name);
367 /* if the category is initialized, unlink from current parent */
368 if (cat->initialized) {
369 xbt_log_category_t *cpp = &cat->parent->firstChild;
371 while (*cpp != cat && *cpp != NULL) {
372 cpp = &(*cpp)->nextSibling;
375 xbt_assert(*cpp == cat);
376 *cpp = cat->nextSibling;
379 cat->parent = parent;
380 cat->nextSibling = parent->firstChild;
382 parent->firstChild = cat;
384 if (!parent->initialized)
385 _xbt_log_cat_init(parent, xbt_log_priority_uninitialized /* ignored */ );
387 cat->threshold = parent->threshold;
389 cat->isThreshInherited = 1;
392 static void _set_inherited_thresholds(xbt_log_category_t cat)
394 xbt_log_category_t child = cat->firstChild;
396 for (; child != NULL; child = child->nextSibling) {
397 if (child->isThreshInherited) {
398 if (cat != &_XBT_LOGV(log))
399 XBT_VERB("Set category threshold of %s to %s (=%d)",
400 child->name, xbt_log_priority_names[cat->threshold], cat->threshold);
401 child->threshold = cat->threshold;
402 _set_inherited_thresholds(child);
407 void xbt_log_threshold_set(xbt_log_category_t cat, e_xbt_log_priority_t threshold)
409 cat->threshold = threshold;
410 cat->isThreshInherited = 0;
412 _set_inherited_thresholds(cat);
415 static xbt_log_setting_t _xbt_log_parse_setting(const char *control_string)
417 const char *orig_control_string = control_string;
418 xbt_log_setting_t set = xbt_new(s_xbt_log_setting_t, 1);
421 set->thresh = xbt_log_priority_uninitialized;
423 set->additivity = -1;
424 set->appender = NULL;
426 if (!*control_string)
428 XBT_DEBUG("Parse log setting '%s'", control_string);
430 control_string += strspn(control_string, " ");
431 const char *name = control_string;
432 control_string += strcspn(control_string, ".:= ");
433 const char *dot = control_string;
434 control_string += strcspn(control_string, ":= ");
435 const char *eq = control_string;
437 xbt_assert(*dot == '.' || (*eq != '=' && *eq != ':'), "Invalid control string '%s'", orig_control_string);
439 if (!strncmp(dot + 1, "threshold", (size_t) (eq - dot - 1))) {
441 char *neweq = xbt_strdup(eq + 1);
444 while (*(++p) != '\0') {
445 if (*p >= 'a' && *p <= 'z') {
450 XBT_DEBUG("New priority name = %s", neweq);
451 for (i = 0; i < xbt_log_priority_infinite; i++) {
452 if (!strncmp(xbt_log_priority_names[i], neweq, p - eq)) {
453 XBT_DEBUG("This is priority %d", i);
458 if(i<XBT_LOG_STATIC_THRESHOLD){
460 "Priority '%s' (in setting '%s') is above allowed priority '%s'.\n\n"
461 "Compiling SimGrid with -DNDEBUG forbids the levels 'trace' and 'debug'\n"
462 "while -DNLOG forbids any logging, at any level.",
463 eq + 1, name, xbt_log_priority_names[XBT_LOG_STATIC_THRESHOLD]);
465 }else if (i < xbt_log_priority_infinite) {
466 set->thresh = (e_xbt_log_priority_t) i;
469 "Unknown priority name: %s (must be one of: trace,debug,verbose,info,warning,error,critical)", eq + 1);
472 } else if (!strncmp(dot + 1, "add", (size_t) (eq - dot - 1)) ||
473 !strncmp(dot + 1, "additivity", (size_t) (eq - dot - 1))) {
474 char *neweq = xbt_strdup(eq + 1);
477 while (*(++p) != '\0') {
478 if (*p >= 'a' && *p <= 'z') {
482 if (!strcmp(neweq, "ON") || !strcmp(neweq, "YES") || !strcmp(neweq, "1")) {
488 } else if (!strncmp(dot + 1, "app", (size_t) (eq - dot - 1)) ||
489 !strncmp(dot + 1, "appender", (size_t) (eq - dot - 1))) {
490 char *neweq = xbt_strdup(eq + 1);
492 if (!strncmp(neweq, "file:", 5)) {
493 set->appender = xbt_log_appender_file_new(neweq + 5);
494 }else if (!strncmp(neweq, "rollfile:", 9)) {
495 set->appender = xbt_log_appender2_file_new(neweq + 9,1);
496 }else if (!strncmp(neweq, "splitfile:", 10)) {
497 set->appender = xbt_log_appender2_file_new(neweq + 10,0);
499 THROWF(arg_error, 0, "Unknown appender log type: '%s'", neweq);
502 } else if (!strncmp(dot + 1, "fmt", (size_t) (eq - dot - 1))) {
503 set->fmt = xbt_strdup(eq + 1);
506 snprintf(buff, MIN(512, eq - dot), "%s", dot + 1);
507 xbt_die("Unknown setting of the log category: '%s'", buff);
509 set->catname = (char *) xbt_malloc(dot - name + 1);
511 memcpy(set->catname, name, dot - name);
512 set->catname[dot - name] = '\0'; /* Just in case */
513 XBT_DEBUG("This is for cat '%s'", set->catname);
518 static xbt_log_category_t _xbt_log_cat_searchsub(xbt_log_category_t cat, char *name)
520 xbt_log_category_t child;
521 xbt_log_category_t res;
523 XBT_DEBUG("Search '%s' into '%s' (firstChild='%s'; nextSibling='%s')", name,
524 cat->name, (cat->firstChild ? cat->firstChild->name : "none"),
525 (cat->nextSibling ? cat->nextSibling->name : "none"));
526 if (!strcmp(cat->name, name))
529 for (child = cat->firstChild; child != NULL; child = child->nextSibling) {
530 XBT_DEBUG("Dig into %s", child->name);
531 res = _xbt_log_cat_searchsub(child, name);
541 * @param control_string What to parse
543 * Typically passed a command-line argument. The string has the syntax:
545 * ( [category] "." [keyword] ":" value (" ")... )...
547 * where [category] is one the category names (see @ref XBT_log_cats for a complete list of the ones defined in the
548 * SimGrid library) and keyword is one of the following:
550 * - thres: category's threshold priority. Possible values:
551 * TRACE,DEBUG,VERBOSE,INFO,WARNING,ERROR,CRITICAL
552 * - add or additivity: whether the logging actions must be passed to the parent category.
553 * Possible values: 0, 1, no, yes, on, off.
554 * Default value: yes.
555 * - fmt: the format to use. See @ref log_use_conf_fmt for more information.
556 * - app or appender: the appender to use. See @ref log_use_conf_app for more information.
558 void xbt_log_control_set(const char *control_string)
560 xbt_log_setting_t set;
562 /* To split the string in commands, and the cursors */
563 xbt_dynar_t set_strings;
569 XBT_DEBUG("Parse log settings '%s'", control_string);
571 /* Special handling of no_loc request, which asks for any file localization to be omitted (for tesh runs) */
572 if (!strcmp(control_string, "no_loc")) {
576 /* some initialization if this is the first time that this get called */
577 if (xbt_log_settings == NULL)
578 xbt_log_settings = xbt_dynar_new(sizeof(xbt_log_setting_t), _free_setting);
580 /* split the string, and remove empty entries */
581 set_strings = xbt_str_split_quoted(control_string);
583 if (xbt_dynar_is_empty(set_strings)) { /* vicious user! */
584 xbt_dynar_free(&set_strings);
588 /* Parse each entry and either use it right now (if the category was already created), or store it for further use */
589 xbt_dynar_foreach(set_strings, cpt, str) {
590 set = _xbt_log_parse_setting(str);
591 xbt_log_category_t cat = _xbt_log_cat_searchsub(&_XBT_LOGV(XBT_LOG_ROOT_CAT), set->catname);
594 XBT_DEBUG("Apply directly");
595 _xbt_log_cat_apply_set(cat, set);
596 _free_setting((void *) &set);
598 XBT_DEBUG("Store for further application");
599 XBT_DEBUG("push %p to the settings", (void *) set);
600 xbt_dynar_push(xbt_log_settings, &set);
603 xbt_dynar_free(&set_strings);
606 void xbt_log_appender_set(xbt_log_category_t cat, xbt_log_appender_t app)
609 if (cat->appender->free_)
610 cat->appender->free_(cat->appender);
616 void xbt_log_layout_set(xbt_log_category_t cat, xbt_log_layout_t lay)
618 DISABLE_XBT_LOG_CAT_INIT();
619 if (!cat->appender) {
620 XBT_VERB ("No appender to category %s. Setting the file appender as default", cat->name);
621 xbt_log_appender_set(cat, xbt_log_appender_file_new(NULL));
624 if (cat->layout->free_) {
625 cat->layout->free_(cat->layout);
630 xbt_log_additivity_set(cat, 0);
633 void xbt_log_additivity_set(xbt_log_category_t cat, int additivity)
635 cat->additivity = additivity;
638 static void xbt_log_help(void)
640 printf("Description of the logging output:\n"
642 " Threshold configuration: --log=CATEGORY_NAME.thres:PRIORITY_LEVEL\n"
643 " CATEGORY_NAME: defined in code with function 'XBT_LOG_NEW_CATEGORY'\n"
644 " PRIORITY_LEVEL: the level to print (trace,debug,verbose,info,warning,error,critical)\n"
645 " -> trace: enter and return of some functions\n"
646 " -> debug: crufty output\n"
647 " -> verbose: verbose output for the user wanting more\n"
648 " -> info: output about the regular functioning\n"
649 " -> warning: minor issue encountered\n"
650 " -> error: issue encountered\n"
651 " -> critical: major issue encountered\n"
652 " The default priority level is 'info'.\n"
654 " Format configuration: --log=CATEGORY_NAME.fmt:FORMAT\n"
655 " FORMAT string may contain:\n"
656 " -> %%%%: the %% char\n"
657 " -> %%n: platform-dependent line separator (LOG4J compatible)\n"
658 " -> %%e: plain old space (SimGrid extension)\n"
660 " -> %%m: user-provided message\n"
662 " -> %%c: Category name (LOG4J compatible)\n"
663 " -> %%p: Priority name (LOG4J compatible)\n"
665 " -> %%h: Hostname (SimGrid extension)\n"
666 " -> %%P: Process name (SimGrid extension)\n"
667 " -> %%t: Thread \"name\" (LOG4J compatible -- actually the address of the thread in memory)\n"
668 " -> %%i: Process PID (SimGrid extension -- this is a 'i' as in 'i'dea)\n"
670 " -> %%F: file name where the log event was raised (LOG4J compatible)\n"
671 " -> %%l: location where the log event was raised (LOG4J compatible, like '%%F:%%L' -- this is a l as "
673 " -> %%L: line number where the log event was raised (LOG4J compatible)\n"
674 " -> %%M: function name (LOG4J compatible -- called method name here of course).\n"
675 " Defined only when using gcc because there is no __func__ elsewhere.\n"
677 " -> %%b: full backtrace (Called %%throwable in LOG4J). Defined only under windows or when using the "
679 " backtrace() is not defined elsewhere, and we only have a fallback for windows boxes, not "
680 "mac ones for example.\n"
681 " -> %%B: short backtrace (only the first line of the %%b). Called %%throwable{short} in LOG4J; "
682 "defined where %%b is.\n"
684 " -> %%d: date (UNIX-like epoch)\n"
685 " -> %%r: application age (time elapsed since the beginning of the application)\n"
688 " --help-log-categories Display the current hierarchy of log categories.\n"
689 " --log=no_loc Don't print file names in messages (for tesh tests).\n"
693 static int xbt_log_cat_cmp(const void *pa, const void *pb)
695 xbt_log_category_t a = *(xbt_log_category_t *)pa;
696 xbt_log_category_t b = *(xbt_log_category_t *)pb;
697 return strcmp(a->name, b->name);
700 static void xbt_log_help_categories_rec(xbt_log_category_t category, const char *prefix)
705 xbt_log_category_t cat;
710 if (category->parent) {
711 this_prefix = bprintf("%s \\_ ", prefix);
712 child_prefix = bprintf("%s | ", prefix);
714 this_prefix = xbt_strdup(prefix);
715 child_prefix = xbt_strdup(prefix);
718 xbt_dynar_t dynar = xbt_dynar_new(sizeof(xbt_log_category_t), NULL);
719 for (cat = category ; cat != NULL; cat = cat->nextSibling)
720 xbt_dynar_push_as(dynar, xbt_log_category_t, cat);
722 xbt_dynar_sort(dynar, xbt_log_cat_cmp);
724 xbt_dynar_foreach(dynar, i, cat){
725 if (i == xbt_dynar_length(dynar) - 1 && category->parent)
726 *strrchr(child_prefix, '|') = ' ';
727 printf("%s%s: %s\n", this_prefix, cat->name, cat->description);
728 xbt_log_help_categories_rec(cat->firstChild, child_prefix);
731 xbt_dynar_free(&dynar);
732 xbt_free(this_prefix);
733 xbt_free(child_prefix);
736 static void xbt_log_help_categories(void)
738 printf("Current log category hierarchy:\n");
739 xbt_log_help_categories_rec(&_XBT_LOGV(XBT_LOG_ROOT_CAT), " ");