1 /* log - a generic logging facility in the spirit of log4j */
3 /* Copyright (c) 2004-2019. 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. */
8 #include "src/xbt_modinter.h"
9 #include "src/xbt/log_private.hpp"
10 #include "xbt/asserts.h"
11 #include "xbt/dynar.h"
19 int xbt_log_no_loc = 0; /* if set to true (with --log=no_loc), file localization will be omitted (for tesh tests) */
20 static std::recursive_mutex* log_cat_init_mutex = nullptr;
22 /** @addtogroup XBT_log
24 * For more information, please refer to @ref outcomes_logs Section.
27 xbt_log_appender_t xbt_log_default_appender = nullptr; /* set in log_init */
28 xbt_log_layout_t xbt_log_default_layout = nullptr; /* set in log_init */
30 struct xbt_log_setting_t {
33 e_xbt_log_priority_t thresh = xbt_log_priority_uninitialized;
35 xbt_log_appender_t appender = nullptr;
38 static std::vector<xbt_log_setting_t> xbt_log_settings;
40 const char *xbt_log_priority_names[8] = {
51 s_xbt_log_category_t _XBT_LOGV(XBT_LOG_ROOT_CAT) = {
53 nullptr /* firstChild */,
54 nullptr /* nextSibling */,
56 "The common ancestor for all categories",
58 xbt_log_priority_uninitialized /* threshold */,
59 0 /* isThreshInherited */,
60 nullptr /* appender */,
65 XBT_LOG_NEW_DEFAULT_SUBCATEGORY(log, xbt, "Loggings from the logging mechanism itself");
67 /* create the default appender and install it in the root category,
68 which were already created (damnit. Too slow little beetle) */
69 void xbt_log_preinit(void)
71 xbt_log_default_appender = xbt_log_appender_file_new(nullptr);
72 xbt_log_default_layout = xbt_log_layout_simple_new(nullptr);
73 _XBT_LOGV(XBT_LOG_ROOT_CAT).appender = xbt_log_default_appender;
74 _XBT_LOGV(XBT_LOG_ROOT_CAT).layout = xbt_log_default_layout;
75 log_cat_init_mutex = new std::recursive_mutex();
78 static void xbt_log_help(void);
79 static void xbt_log_help_categories(void);
81 /** @brief Get all logging settings from the command line
83 * xbt_log_control_set() is called on each string we got from cmd line
85 void xbt_log_init(int *argc, char **argv)
87 unsigned help_requested = 0; /* 1: logs; 2: categories */
89 int parse_args = 1; // Stop parsing the parameters once we found '--'
91 /* Set logs and init log submodule */
92 for (int i = 1; i < *argc; i++) {
93 if (strcmp("--", argv[i]) == 0) {
95 argv[j++] = argv[i]; // Keep the '--' for sg_config
96 } else if (parse_args && strncmp(argv[i], "--log=", strlen("--log=")) == 0) {
97 char* opt = strchr(argv[i], '=');
99 xbt_log_control_set(opt);
100 XBT_DEBUG("Did apply '%s' as log setting", opt);
101 } else if (parse_args && strcmp(argv[i], "--help-logs") == 0) {
102 help_requested |= 1U;
103 } else if (parse_args && strcmp(argv[i], "--help-log-categories") == 0) {
104 help_requested |= 2U;
114 if (help_requested) {
115 if (help_requested & 1)
117 if (help_requested & 2)
118 xbt_log_help_categories();
123 static void log_cat_exit(xbt_log_category_t cat)
125 xbt_log_category_t child;
128 if (cat->appender->free_)
129 cat->appender->free_(cat->appender);
130 xbt_free(cat->appender);
133 if (cat->layout->free_)
134 cat->layout->free_(cat->layout);
135 xbt_free(cat->layout);
138 for (child = cat->firstChild; child != nullptr; child = child->nextSibling)
142 void xbt_log_postexit(void)
144 XBT_VERB("Exiting log");
145 delete log_cat_init_mutex;
146 log_cat_exit(&_XBT_LOGV(XBT_LOG_ROOT_CAT));
149 /* Size of the static string in which we build the log string */
150 static constexpr size_t XBT_LOG_STATIC_BUFFER_SIZE = 2048;
151 /* Minimum size of the dynamic string in which we build the log string
152 (should be greater than XBT_LOG_STATIC_BUFFER_SIZE) */
153 static constexpr size_t XBT_LOG_DYNAMIC_BUFFER_SIZE = 4096;
155 void _xbt_log_event_log(xbt_log_event_t ev, const char *fmt, ...)
157 xbt_log_category_t cat = ev->cat;
159 xbt_assert(ev->priority >= 0, "Negative logging priority naturally forbidden");
160 xbt_assert(static_cast<size_t>(ev->priority) < sizeof(xbt_log_priority_names)/sizeof(xbt_log_priority_names[0]),
161 "Priority %d is greater than the biggest allowed value", ev->priority);
164 xbt_log_appender_t appender = cat->appender;
166 if (appender != nullptr) {
167 xbt_assert(cat->layout, "No valid layout for the appender of category %s", cat->name);
169 /* First, try with a static buffer */
171 char buff[XBT_LOG_STATIC_BUFFER_SIZE];
173 ev->buffer_size = sizeof buff;
174 va_start(ev->ap, fmt);
175 done = cat->layout->do_layout(cat->layout, ev, fmt);
178 appender->do_append(appender, buff);
181 /* The static buffer was too small, use a dynamically expanded one */
182 ev->buffer_size = XBT_LOG_DYNAMIC_BUFFER_SIZE;
183 ev->buffer = static_cast<char*>(xbt_malloc(ev->buffer_size));
185 va_start(ev->ap, fmt);
186 done = cat->layout->do_layout(cat->layout, ev, fmt);
190 ev->buffer_size *= 2;
191 ev->buffer = static_cast<char*>(xbt_realloc(ev->buffer, ev->buffer_size));
193 appender->do_append(appender, ev->buffer);
194 xbt_free(ev->buffer);
198 if (!cat->additivity)
206 * The standard logging macros use _XBT_LOG_ISENABLED, which calls _xbt_log_cat_init(). Thus, if we want to avoid an
207 * infinite recursion, we can not use the standard logging macros in _xbt_log_cat_init(), and in all functions called
210 * To circumvent the problem, we define the macro DISABLE_XBT_LOG_CAT_INIT() to hide the real _xbt_log_cat_init(). The
211 * macro has to be called at the beginning of the affected functions.
213 static int fake_xbt_log_cat_init(xbt_log_category_t, e_xbt_log_priority_t)
217 #define DISABLE_XBT_LOG_CAT_INIT() \
218 int (*_xbt_log_cat_init)(xbt_log_category_t, e_xbt_log_priority_t) XBT_ATTRIB_UNUSED = fake_xbt_log_cat_init;
220 static void _xbt_log_cat_apply_set(xbt_log_category_t category, const xbt_log_setting_t& setting)
222 DISABLE_XBT_LOG_CAT_INIT();
223 if (setting.thresh != xbt_log_priority_uninitialized) {
224 xbt_log_threshold_set(category, setting.thresh);
226 XBT_DEBUG("Apply settings for category '%s': set threshold to %s (=%d)",
227 category->name, xbt_log_priority_names[category->threshold], category->threshold);
230 if (not setting.fmt.empty()) {
231 xbt_log_layout_set(category, xbt_log_layout_format_new(setting.fmt.c_str()));
233 XBT_DEBUG("Apply settings for category '%s': set format to %s", category->name, setting.fmt.c_str());
236 if (setting.additivity != -1) {
237 xbt_log_additivity_set(category, setting.additivity);
239 XBT_DEBUG("Apply settings for category '%s': set additivity to %s", category->name,
240 (setting.additivity ? "on" : "off"));
242 if (setting.appender) {
243 xbt_log_appender_set(category, setting.appender);
244 if (!category->layout)
245 xbt_log_layout_set(category, xbt_log_layout_simple_new(nullptr));
246 category->additivity = 0;
247 XBT_DEBUG("Set %p as appender of category '%s'", setting.appender, category->name);
252 * This gets called the first time a category is referenced and performs the initialization.
253 * Also resets threshold to inherited!
255 int _xbt_log_cat_init(xbt_log_category_t category, e_xbt_log_priority_t priority)
257 DISABLE_XBT_LOG_CAT_INIT();
258 if (category->initialized)
259 return priority >= category->threshold;
261 if (log_cat_init_mutex != nullptr)
262 log_cat_init_mutex->lock();
264 XBT_DEBUG("Initializing category '%s' (firstChild=%s, nextSibling=%s)", category->name,
265 (category->firstChild ? category->firstChild->name : "none"),
266 (category->nextSibling ? category->nextSibling->name : "none"));
268 if (category == &_XBT_LOGV(XBT_LOG_ROOT_CAT)) {
269 category->threshold = xbt_log_priority_info;
270 category->appender = xbt_log_default_appender;
271 category->layout = xbt_log_default_layout;
273 if (!category->parent)
274 category->parent = &_XBT_LOGV(XBT_LOG_ROOT_CAT);
276 XBT_DEBUG("Set %s (%s) as father of %s ", category->parent->name,
277 (category->parent->initialized ? xbt_log_priority_names[category->parent->threshold] : "uninited"),
279 xbt_log_parent_set(category, category->parent);
281 if (XBT_LOG_ISENABLED(log, xbt_log_priority_debug)) {
283 xbt_log_category_t cpp = category->parent->firstChild;
285 res += std::string(" ") + cpp->name;
286 cpp = cpp->nextSibling;
289 XBT_DEBUG("Children of %s:%s; nextSibling: %s", category->parent->name, res.c_str(),
290 (category->parent->nextSibling ? category->parent->nextSibling->name : "none"));
294 /* Apply the control */
295 auto iset = std::find_if(begin(xbt_log_settings), end(xbt_log_settings),
296 [category](const xbt_log_setting_t& s) { return s.catname == category->name; });
297 if (iset != xbt_log_settings.end()) {
298 _xbt_log_cat_apply_set(category, *iset);
299 xbt_log_settings.erase(iset);
301 XBT_DEBUG("Category '%s': inherited threshold = %s (=%d)", category->name,
302 xbt_log_priority_names[category->threshold], category->threshold);
305 category->initialized = 1;
306 if (log_cat_init_mutex != nullptr)
307 log_cat_init_mutex->unlock();
308 return priority >= category->threshold;
311 void xbt_log_parent_set(xbt_log_category_t cat, xbt_log_category_t parent)
313 xbt_assert(cat, "NULL category to be given a parent");
314 xbt_assert(parent, "The parent category of %s is NULL", cat->name);
316 /* if the category is initialized, unlink from current parent */
317 if (cat->initialized) {
318 xbt_log_category_t *cpp = &cat->parent->firstChild;
320 while (*cpp != cat && *cpp != nullptr) {
321 cpp = &(*cpp)->nextSibling;
324 xbt_assert(*cpp == cat);
325 *cpp = cat->nextSibling;
328 cat->parent = parent;
329 cat->nextSibling = parent->firstChild;
331 parent->firstChild = cat;
333 if (!parent->initialized)
334 _xbt_log_cat_init(parent, xbt_log_priority_uninitialized /* ignored */ );
336 cat->threshold = parent->threshold;
338 cat->isThreshInherited = 1;
341 static void _set_inherited_thresholds(xbt_log_category_t cat)
343 xbt_log_category_t child = cat->firstChild;
345 for (; child != nullptr; child = child->nextSibling) {
346 if (child->isThreshInherited) {
347 if (cat != &_XBT_LOGV(log))
348 XBT_VERB("Set category threshold of %s to %s (=%d)",
349 child->name, xbt_log_priority_names[cat->threshold], cat->threshold);
350 child->threshold = cat->threshold;
351 _set_inherited_thresholds(child);
356 void xbt_log_threshold_set(xbt_log_category_t cat, e_xbt_log_priority_t threshold)
358 cat->threshold = threshold;
359 cat->isThreshInherited = 0;
361 _set_inherited_thresholds(cat);
364 static xbt_log_setting_t _xbt_log_parse_setting(const char *control_string)
366 const char *orig_control_string = control_string;
367 xbt_log_setting_t set;
369 if (!*control_string)
371 XBT_DEBUG("Parse log setting '%s'", control_string);
373 control_string += strspn(control_string, " ");
374 const char *name = control_string;
375 control_string += strcspn(control_string, ".:= ");
376 const char *dot = control_string;
377 control_string += strcspn(control_string, ":= ");
378 const char *eq = control_string;
380 xbt_assert(*dot == '.' || (*eq != '=' && *eq != ':'), "Invalid control string '%s'", orig_control_string);
382 if (!strncmp(dot + 1, "threshold", (size_t) (eq - dot - 1))) {
384 char *neweq = xbt_strdup(eq + 1);
387 while (*(++p) != '\0') {
388 if (*p >= 'a' && *p <= 'z') {
393 XBT_DEBUG("New priority name = %s", neweq);
394 for (i = 0; i < xbt_log_priority_infinite; i++) {
395 if (!strncmp(xbt_log_priority_names[i], neweq, p - eq)) {
396 XBT_DEBUG("This is priority %d", i);
401 if(i<XBT_LOG_STATIC_THRESHOLD){
403 "Priority '%s' (in setting '%s') is above allowed priority '%s'.\n\n"
404 "Compiling SimGrid with -DNDEBUG forbids the levels 'trace' and 'debug'\n"
405 "while -DNLOG forbids any logging, at any level.",
406 eq + 1, name, xbt_log_priority_names[XBT_LOG_STATIC_THRESHOLD]);
408 }else if (i < xbt_log_priority_infinite) {
409 set.thresh = (e_xbt_log_priority_t)i;
412 "Unknown priority name: %s (must be one of: trace,debug,verbose,info,warning,error,critical)", eq + 1);
415 } else if (!strncmp(dot + 1, "add", (size_t) (eq - dot - 1)) ||
416 !strncmp(dot + 1, "additivity", (size_t) (eq - dot - 1))) {
417 char *neweq = xbt_strdup(eq + 1);
420 while (*(++p) != '\0') {
421 if (*p >= 'a' && *p <= 'z') {
425 if (!strcmp(neweq, "ON") || !strcmp(neweq, "YES") || !strcmp(neweq, "1")) {
431 } else if (!strncmp(dot + 1, "app", (size_t) (eq - dot - 1)) ||
432 !strncmp(dot + 1, "appender", (size_t) (eq - dot - 1))) {
433 char *neweq = xbt_strdup(eq + 1);
435 if (!strncmp(neweq, "file:", 5)) {
436 set.appender = xbt_log_appender_file_new(neweq + 5);
437 }else if (!strncmp(neweq, "rollfile:", 9)) {
438 set.appender = xbt_log_appender2_file_new(neweq + 9, 1);
439 }else if (!strncmp(neweq, "splitfile:", 10)) {
440 set.appender = xbt_log_appender2_file_new(neweq + 10, 0);
442 THROWF(arg_error, 0, "Unknown appender log type: '%s'", neweq);
445 } else if (!strncmp(dot + 1, "fmt", (size_t) (eq - dot - 1))) {
446 set.fmt = std::string(eq + 1);
449 snprintf(buff, std::min<int>(512, eq - dot), "%s", dot + 1);
450 xbt_die("Unknown setting of the log category: '%s'", buff);
452 set.catname = std::string(name, dot - name);
454 XBT_DEBUG("This is for cat '%s'", set.catname.c_str());
459 static xbt_log_category_t _xbt_log_cat_searchsub(xbt_log_category_t cat, const char* name)
461 xbt_log_category_t child;
462 xbt_log_category_t res;
464 XBT_DEBUG("Search '%s' into '%s' (firstChild='%s'; nextSibling='%s')", name,
465 cat->name, (cat->firstChild ? cat->firstChild->name : "none"),
466 (cat->nextSibling ? cat->nextSibling->name : "none"));
467 if (strcmp(cat->name, name) == 0)
470 for (child = cat->firstChild; child != nullptr; child = child->nextSibling) {
471 XBT_DEBUG("Dig into %s", child->name);
472 res = _xbt_log_cat_searchsub(child, name);
482 * @param control_string What to parse
484 * Typically passed a command-line argument. The string has the syntax:
486 * ( [category] "." [keyword] ":" value (" ")... )...
488 * where [category] is one the category names (see @ref XBT_log_cats for a complete list of the ones defined in the
489 * SimGrid library) and keyword is one of the following:
491 * - thres: category's threshold priority. Possible values:
492 * TRACE,DEBUG,VERBOSE,INFO,WARNING,ERROR,CRITICAL
493 * - add or additivity: whether the logging actions must be passed to the parent category.
494 * Possible values: 0, 1, no, yes, on, off.
495 * Default value: yes.
496 * - fmt: the format to use. See @ref log_use_conf_fmt for more information.
497 * - app or appender: the appender to use. See @ref log_use_conf_app for more information.
499 void xbt_log_control_set(const char *control_string)
501 /* To split the string in commands, and the cursors */
502 xbt_dynar_t set_strings;
508 XBT_DEBUG("Parse log settings '%s'", control_string);
510 /* Special handling of no_loc request, which asks for any file localization to be omitted (for tesh runs) */
511 if (strcmp(control_string, "no_loc") == 0) {
515 /* split the string, and remove empty entries */
516 set_strings = xbt_str_split_quoted(control_string);
518 if (xbt_dynar_is_empty(set_strings)) { /* vicious user! */
519 xbt_dynar_free(&set_strings);
523 /* Parse each entry and either use it right now (if the category was already created), or store it for further use */
524 xbt_dynar_foreach(set_strings, cpt, str) {
525 xbt_log_setting_t set = _xbt_log_parse_setting(str);
526 xbt_log_category_t cat = _xbt_log_cat_searchsub(&_XBT_LOGV(XBT_LOG_ROOT_CAT), set.catname.c_str());
529 XBT_DEBUG("Apply directly");
530 _xbt_log_cat_apply_set(cat, set);
532 XBT_DEBUG("Store for further application");
533 XBT_DEBUG("push %p to the settings", &set);
534 xbt_log_settings.emplace_back(std::move(set));
537 xbt_dynar_free(&set_strings);
540 void xbt_log_appender_set(xbt_log_category_t cat, xbt_log_appender_t app)
543 if (cat->appender->free_)
544 cat->appender->free_(cat->appender);
545 xbt_free(cat->appender);
550 void xbt_log_layout_set(xbt_log_category_t cat, xbt_log_layout_t lay)
552 DISABLE_XBT_LOG_CAT_INIT();
553 if (!cat->appender) {
554 XBT_VERB ("No appender to category %s. Setting the file appender as default", cat->name);
555 xbt_log_appender_set(cat, xbt_log_appender_file_new(nullptr));
558 if (cat->layout->free_) {
559 cat->layout->free_(cat->layout);
561 xbt_free(cat->layout);
564 xbt_log_additivity_set(cat, 0);
567 void xbt_log_additivity_set(xbt_log_category_t cat, int additivity)
569 cat->additivity = additivity;
572 static void xbt_log_help(void)
574 printf("Description of the logging output:\n"
576 " Threshold configuration: --log=CATEGORY_NAME.thres:PRIORITY_LEVEL\n"
577 " CATEGORY_NAME: defined in code with function 'XBT_LOG_NEW_CATEGORY'\n"
578 " PRIORITY_LEVEL: the level to print (trace,debug,verbose,info,warning,error,critical)\n"
579 " -> trace: enter and return of some functions\n"
580 " -> debug: crufty output\n"
581 " -> verbose: verbose output for the user wanting more\n"
582 " -> info: output about the regular functioning\n"
583 " -> warning: minor issue encountered\n"
584 " -> error: issue encountered\n"
585 " -> critical: major issue encountered\n"
586 " The default priority level is 'info'.\n"
588 " Format configuration: --log=CATEGORY_NAME.fmt:FORMAT\n"
589 " FORMAT string may contain:\n"
590 " -> %%%%: the %% char\n"
591 " -> %%n: platform-dependent line separator (LOG4J compatible)\n"
592 " -> %%e: plain old space (SimGrid extension)\n"
594 " -> %%m: user-provided message\n"
596 " -> %%c: Category name (LOG4J compatible)\n"
597 " -> %%p: Priority name (LOG4J compatible)\n"
599 " -> %%h: Hostname (SimGrid extension)\n"
600 " -> %%P: Process name (SimGrid extension)\n"
601 " -> %%t: Thread \"name\" (LOG4J compatible -- actually the address of the thread in memory)\n"
602 " -> %%i: Process PID (SimGrid extension -- this is a 'i' as in 'i'dea)\n"
604 " -> %%F: file name where the log event was raised (LOG4J compatible)\n"
605 " -> %%l: location where the log event was raised (LOG4J compatible, like '%%F:%%L' -- this is a l as "
607 " -> %%L: line number where the log event was raised (LOG4J compatible)\n"
608 " -> %%M: function name (LOG4J compatible -- called method name here of course).\n"
609 " Defined only when using gcc because there is no __func__ elsewhere.\n"
611 " -> %%b: full backtrace (Called %%throwable in LOG4J). Defined only under windows or when using the "
613 " backtrace() is not defined elsewhere, and we only have a fallback for windows boxes, not "
614 "mac ones for example.\n"
615 " -> %%B: short backtrace (only the first line of the %%b). Called %%throwable{short} in LOG4J; "
616 "defined where %%b is.\n"
618 " -> %%d: date (UNIX-like epoch)\n"
619 " -> %%r: application age (time elapsed since the beginning of the application)\n"
622 " --help-log-categories Display the current hierarchy of log categories.\n"
623 " --log=no_loc Don't print file names in messages (for tesh tests).\n"
627 static void xbt_log_help_categories_rec(xbt_log_category_t category, const std::string& prefix)
632 std::string this_prefix(prefix);
633 std::string child_prefix(prefix);
634 if (category->parent) {
635 this_prefix += " \\_ ";
636 child_prefix += " | ";
639 std::vector<xbt_log_category_t> cats;
640 for (xbt_log_category_t cat = category; cat != nullptr; cat = cat->nextSibling)
643 std::sort(begin(cats), end(cats),
644 [](xbt_log_category_t a, xbt_log_category_t b) { return strcmp(a->name, b->name) < 0; });
646 for (auto const& cat : cats) {
647 printf("%s%s: %s\n", this_prefix.c_str(), cat->name, cat->description);
648 if (cat == cats.back() && category->parent)
649 child_prefix[child_prefix.rfind('|')] = ' ';
650 xbt_log_help_categories_rec(cat->firstChild, child_prefix);
654 static void xbt_log_help_categories(void)
656 printf("Current log category hierarchy:\n");
657 xbt_log_help_categories_rec(&_XBT_LOGV(XBT_LOG_ROOT_CAT), " ");