3 /* log - a generic logging facility in the spirit of log4j */
5 /* Copyright (c) 2003, 2004 Martin Quinson. All rights reserved. */
7 /* This program is free software; you can redistribute it and/or modify it
8 * under the terms of the license (GNU LGPL) which comes with this package. */
13 #include <stdio.h> /* snprintf */
14 #include <stdlib.h> /* snprintf */
15 #include "gras_config.h" /* to get a working stdarg.h */
17 #include "xbt_modinter.h"
21 #include "xbt/sysdep.h"
23 #include "xbt/dynar.h"
25 /** \addtogroup XBT_log
27 * This section describes the API to the log functions used
28 * everywhere in this project.
30 \section XBT_log_toc Table of contents
42 - \ref log_API_example
51 \section log_overview 1. Introduction
53 This module is in charge of handling the log messages of every SimGrid
54 program. The main design goal are:
56 - <b>configurability</b>: the user can choose <i>at runtime</i> what messages to show and
57 what to hide, as well as how messages get displayed.
58 - <b>ease of use</b>: both to the programmer (using preprocessor macros black magic)
59 and to the user (with command line options)
60 - <b>performances</b>: logging shouldn't slow down the program when turned off, for example
61 - deal with <b>distributed settings</b>: SimGrid programs are [often] distributed ones,
62 and the logging mecanism allows to syndicate each and every log source into the same place.
63 At least, its design would allow to, once we write the last missing pieces
65 There is three main concepts in SimGrid's logging mecanism: <i>category</i>,
66 <i>priority</i> and <i>appender</i>. These three concepts work together to
67 enable developers to log messages according to message type and priority, and
68 to control at runtime how these messages are formatted and where they are
71 \subsection log_cat 1.1 Category hierarchy
73 The first and foremost advantage of any logging API over plain printf()
74 resides in its ability to disable certain log statements while allowing
75 others to print unhindered. This capability assumes that the logging space,
76 that is, the space of all possible logging statements, is categorized
77 according to some developer-chosen criteria.
79 This observation led to choosing category as the central concept of the
80 system. In a certain sense, they can be considered as logging topics or
83 \subsection log_pri 1.2 Logging priorities
85 The user can naturally declare interest into this or that logging category, but
86 he also can specify the desired level of details for each of them. This is
87 controled by the <i>priority</i> concept (which should maybe be renamed to
90 Empirically, the user can specify that he wants to see every debuging message
91 of GRAS while only being interested into the messages at level "error" or
92 higher about the XBT internals.
94 \subsection log_app 1.3 Message appenders
96 The message appenders are the elements in charge of actually displaying the
97 message to the user. For now, there is only one appender: the one able to print
98 stuff on stderr. But everything is in place internally to write new ones, such
99 as the one able to send the strings to a central server in charge of
100 syndicating the logs of every distributed daemons on a well known location.
102 It should also be possible to pass configuration informations to the appenders,
103 specifying for example that the message location (file and line number) is only
104 relevant to debugging information, not to critical error messages.
108 \subsection log_hist 1.4 History of this module
110 Historically, this module is an adaptation of the log4c project, which is dead
111 upstream, and which I was given the permission to fork under the LGPL licence
112 by the log4c's authors. The log4c project itself was loosely based on the
113 Apache project's Log4J, which also inspired Log4CC, Log4py and so on. Our work
114 differs somehow from these projects anyway, because the C programming language
115 is not object oriented.
117 \section log_API 2. Programmer interface
119 \subsection log_API_cat 2.1 Constructing the category hierarchy
121 Every category is declared by providing a name and an optional
122 parent. If no parent is explicitly named, the root category, LOG_ROOT_CAT is
123 the category's parent.
125 A category is created by a macro call at the top level of a file. A
126 category can be created with any one of the following macros:
128 - \ref XBT_LOG_NEW_CATEGORY(MyCat,desc); Create a new root
129 - \ref XBT_LOG_NEW_SUBCATEGORY(MyCat, ParentCat,desc);
130 Create a new category being child of the category ParentCat
131 - \ref XBT_LOG_NEW_DEFAULT_CATEGORY(MyCat,desc);
132 Like XBT_LOG_NEW_CATEGORY, but the new category is the default one
134 - \ref XBT_LOG_NEW_DEFAULT_SUBCATEGORY(MyCat, ParentCat,desc);
135 Like XBT_LOG_NEW_SUBCATEGORY, but the new category is the default one
138 The parent cat can be defined in the same file or in another file (in
139 which case you want to use the \ref XBT_LOG_EXTERNAL_CATEGORY macro to make
140 it visible in the current file), but each category may have only one
143 Typically, there will be a Category for each module and sub-module, so you
144 can independently control logging for each module.
146 For a list of all existing categories, please refer to the \ref XBT_log_cats
147 section. This file is generated automatically from the SimGrid source code, so
148 it should be complete and accurate.
150 \section log_API_pri 2.2 Declaring message priority
152 A category may be assigned a threshold priorty. The set of priorites are
153 defined by the \ref e_xbt_log_priority_t enum. All logging request under
154 this priority will be discarded.
156 If a given category is not assigned a threshold priority, then it inherits
157 one from its closest ancestor with an assigned threshold. To ensure that all
158 categories can eventually inherit a threshold, the root category always has
159 an assigned threshold priority.
161 Logging requests are made by invoking a logging macro on a category. All of
162 the macros have a printf-style format string followed by arguments. If you
163 compile with the -Wall option, gcc will warn you for unmatched arguments, ie
164 when you pass a pointer to a string where an integer was specified by the
165 format. This is usualy a good idea.
167 Because some C compilers do not support vararg macros, there is a version of
168 the macro for any number of arguments from 0 to 6. The macro name ends with
169 the total number of arguments.
171 Here is an example of the most basic type of macro. This is a logging
172 request with priority <i>warning</i>.
174 <code>CLOG5(MyCat, gras_log_priority_warning, "Values are: %d and '%s'", 5,
177 A logging request is said to be enabled if its priority is higher than or
178 equal to the threshold priority of its category. Otherwise, the request is
179 said to be disabled. A category without an assigned priority will inherit
180 one from the hierarchy.
182 It is possible to use any non-negative integer as a priority. If, as in the
183 example, one of the standard priorites is used, then there is a convenience
184 macro that is typically used instead. For example, the above example is
185 equivalent to the shorter:
187 <code>CWARN4(MyCat, "Values are: %d and '%s'", 5, "oops");</code>
189 \section log_API_subcat 2.3 Using a default category (the easy interface)
191 If \ref XBT_LOG_NEW_DEFAULT_SUBCATEGORY(MyCat, Parent) or
192 \ref XBT_LOG_NEW_DEFAULT_CATEGORY(MyCat) is used to create the
193 category, then the even shorter form can be used:
195 <code>WARN3("Values are: %d and '%s'", 5, "oops");</code>
197 Only one default category can be created per file, though multiple
198 non-defaults can be created and used.
200 \section log_API_easy 2.4 Putting all together: the easy interface
202 First of all, each module should register its own category into the categories
203 tree using \ref XBT_LOG_NEW_DEFAULT_SUBCATEGORY.
205 Then, logging should be done with the DEBUG<n>, VERB<n>, INFO<n>, WARN<n>,
206 ERROR<n> or CRITICAL<n> macro families. For each group, there is 6 different
207 macros (like DEBUG0, DEBUG1, DEBUG2, DEBUG3, DEBUG4 and DEBUG5), only differing
208 in the number of arguments passed along the format. This is because we want
209 SimGrid itself to keep compilable on ancient compiler not supporting variable
210 number of arguments to macros. But we should provide a macro simpler to use for
211 the users not interested in SP3 machines (FIXME).
213 Under GCC, these macro check there arguments the same way than printf does. So,
214 if you compile with -Wall, the folliwing code will issue a warning:
215 <code>DEBUG2("Found %s (id %f)", some_string, a_double)</code>
217 \section log_API_example 2.5 Example of use
219 Here is a more complete example:
224 / * create a category and a default subcategory * /
225 XBT_LOG_NEW_CATEGORY(VSS);
226 XBT_LOG_NEW_DEFAULT_SUBCATEGORY(SA, VSS);
229 / * Now set the parent's priority. (the string would typcially be a runtime option) * /
230 xbt_log_control_set("SA.thresh=3");
232 / * This request is enabled, because WARNING >= INFO. * /
233 CWARN2(VSS, "Low fuel level.");
235 / * This request is disabled, because DEBUG < INFO. * /
236 CDEBUG2(VSS, "Starting search for nearest gas station.");
238 / * The default category SA inherits its priority from VSS. Thus,
239 the following request is enabled because INFO >= INFO. * /
240 INFO1("Located nearest gas station.");
242 / * This request is disabled, because DEBUG < INFO. * /
243 DEBUG1("Exiting gas station search");
248 \section log_user 3. User interface
250 \section log_use_conf 3.1 Configuration
251 Configuration is typically done during program initialization by invoking
252 the xbt_log_control_set() method. The control string passed to it typically
253 comes from the command line. Look at the documentation for that function for
254 the format of the control string.
256 Any SimGrid program can furthermore be configured at run time by passing a
257 --xbt-log argument on the command line (--gras-log, --msg-log and --surf-log
258 are synonyms provided by aestheticism). You can provide several of those
259 arguments to change the setting of several categories, they will be applied
260 from left to right. So,
261 \verbatim --xbt-log="root.thres=debug root.thres=critical"\endverbatim
262 should disable any logging.
264 Note that the quotes on above line are mandatory because there is a space in
265 the argument, so we are protecting ourselves from the shell, not from SimGrid.
266 We could also reach the same effect with this:
267 \verbatim --xbt-log=root.thres=debug --xbt-log=root.thres=critical\endverbatim
269 \section log_use_misc 3.2 Misc and Caveats
271 - Do not use any of the macros that start with '_'.
272 - Log4J has a 'rolling file appender' which you can select with a run-time
273 option and specify the max file size. This would be a nice default for
274 non-kernel applications.
275 - Careful, category names are global variables.
277 \section log_internals 4. Internal considerations
279 This module is a mess of macro black magic, and when it goes wrong, SimGrid
280 studently loose its ability to explain its problems. When messing around this
281 module, I often find useful to define XBT_LOG_MAYDAY (which turns it back to
282 good old printf) for the time of finding what's going wrong.
284 \section log_in_perf 4.1 Performance
286 Except for the first invocation of a given category, a disabled logging request
287 requires an a single comparison of a static variable to a constant.
289 There is also compile time constant, \ref XBT_LOG_STATIC_THRESHOLD, which
290 causes all logging requests with a lower priority to be optimized to 0 cost
291 by the compiler. By setting it to gras_log_priority_infinite, all logging
292 requests are statically disabled and cost nothing. Released executables
293 might be compiled with
294 \verbatim-DXBT_LOG_STATIC_THRESHOLD=gras_log_priority_infinite\endverbatim
296 Compiling with the \verbatim-DNLOG\endverbatim option disables all logging
297 requests at compilation time while the \verbatim-DNDEBUG\endverbatim disables
298 the requests of priority below INFO.
300 \todo Logging performance *may* be improved further by improving the message
301 propagation from appender to appender in the category tree.
303 \section log_in_app 4.2 Appenders
305 Each category has an optional appender. An appender is a pointer to a
306 structure which starts with a pointer to a doAppend() function. DoAppend()
307 prints a message to a log.
309 When a category is passed a message by one of the logging macros, the
310 category performs the following actions:
312 - if the category has an appender, the message is passed to the
313 appender's doAppend() function,
314 - if 'willLogToParent' is true for the category, the message is passed
315 to the category's parent.
317 By default, only the root category have an appender, and 'willLogToParent'
318 is true for any other category. This situation causes all messages to be
319 logged by the root category's appender.
321 The default appender function currently prints to stderr, and no other one
322 exist, even if more would be needed, like the one able to send the logs to a
323 remote dedicated server, or other ones offering different output formats.
324 This is on our TODO list for quite a while now, but your help would be
333 e_xbt_log_priority_t thresh;
334 } s_xbt_log_setting_t,*xbt_log_setting_t;
336 static xbt_dynar_t xbt_log_settings=NULL;
337 static void _free_setting(void *s) {
338 xbt_log_setting_t set=(xbt_log_setting_t)s;
341 /* free(set); FIXME: uncommenting this leads to segfault when more than one chunk is passed as gras-log */
345 const char *xbt_log_priority_names[8] = {
356 s_xbt_log_category_t _XBT_LOGV(XBT_LOG_ROOT_CAT) = {
358 "root", xbt_log_priority_uninitialized, 0,
362 XBT_LOG_NEW_CATEGORY(xbt,"All XBT categories (simgrid toolbox)");
363 XBT_LOG_NEW_CATEGORY(surf,"All SURF categories");
364 XBT_LOG_NEW_CATEGORY(msg,"All MSG categories");
365 XBT_LOG_NEW_DEFAULT_SUBCATEGORY(log,xbt,"Loggings from the logging mechanism itself");
367 void xbt_log_init(int *argc,char **argv) {
371 /* Set logs and init log submodule */
372 for (i=1; i<*argc; i++) {
373 if (!strncmp(argv[i],"--gras-log=",strlen("--gras-log=")) ||
374 !strncmp(argv[i],"--surf-log=",strlen("--surf-log=")) ||
375 !strncmp(argv[i],"--msg-log=",strlen("--msg-log=")) ||
376 !strncmp(argv[i],"--xbt-log=",strlen("--xbt-log="))) {
377 opt=strchr(argv[i],'=');
379 xbt_log_control_set(opt);
380 DEBUG1("Did apply '%s' as log setting",opt);
381 /*remove this from argv*/
382 for (j=i+1; j<*argc; j++) {
387 i--; /* compensate effect of next loop incrementation */
392 void xbt_log_exit(void) {
393 VERB0("Exiting log");
394 xbt_dynar_free(&xbt_log_settings);
398 static void _apply_control(xbt_log_category_t cat) {
400 xbt_log_setting_t setting=NULL;
403 if (!xbt_log_settings)
406 xbt_assert0(cat,"NULL category");
407 xbt_assert(cat->name);
409 xbt_dynar_foreach(xbt_log_settings,cursor,setting) {
410 xbt_assert0(setting,"Damnit, NULL cat in the list");
411 xbt_assert1(setting->catname,"NULL setting(=%p)->catname",(void*)setting);
413 if (!strcmp(setting->catname,cat->name)) {
416 xbt_log_threshold_set(cat, setting->thresh);
417 xbt_dynar_cursor_rm(xbt_log_settings,&cursor);
419 if (cat->threshold <= xbt_log_priority_debug) {
420 s_xbt_log_event_t _log_ev =
421 {cat,xbt_log_priority_debug,__FILE__,_XBT_FUNCTION,__LINE__};
422 _xbt_log_event_log(&_log_ev,
423 "Apply settings for category '%s': set threshold to %s (=%d)",
425 xbt_log_priority_names[cat->threshold], cat->threshold);
429 if (!found && cat->threshold <= xbt_log_priority_verbose) {
430 s_xbt_log_event_t _log_ev =
431 {cat,xbt_log_priority_verbose,__FILE__,_XBT_FUNCTION,__LINE__};
432 _xbt_log_event_log(&_log_ev,
433 "Category '%s': inherited threshold = %s (=%d)",
435 xbt_log_priority_names[cat->threshold], cat->threshold);
440 void _xbt_log_event_log( xbt_log_event_t ev, const char *fmt, ...) {
441 xbt_log_category_t cat = ev->cat;
442 va_start(ev->ap, fmt);
444 xbt_log_appender_t appender = cat->appender;
445 if (appender != NULL) {
446 appender->do_append(appender, ev, fmt);
448 if (!cat->willLogToParent)
456 static void _cat_init(xbt_log_category_t category) {
457 if (category == &_XBT_LOGV(XBT_LOG_ROOT_CAT)) {
458 category->threshold = xbt_log_priority_info;
459 category->appender = xbt_log_default_appender;
461 xbt_log_parent_set(category, category->parent);
463 _apply_control(category);
467 * This gets called the first time a category is referenced and performs the
469 * Also resets threshold to inherited!
471 int _xbt_log_cat_init(e_xbt_log_priority_t priority,
472 xbt_log_category_t category) {
476 return priority >= category->threshold;
479 void xbt_log_parent_set(xbt_log_category_t cat,
480 xbt_log_category_t parent) {
482 xbt_assert0(cat,"NULL category to be given a parent");
483 xbt_assert1(parent,"The parent category of %s is NULL",cat->name);
485 /* unlink from current parent */
486 if (cat->threshold != xbt_log_priority_uninitialized) {
487 xbt_log_category_t* cpp = &parent->firstChild;
488 while(*cpp != cat && *cpp != NULL) {
489 cpp = &(*cpp)->nextSibling;
491 xbt_assert(*cpp == cat);
492 *cpp = cat->nextSibling;
496 cat->parent = parent;
497 cat->nextSibling = parent->firstChild;
498 parent->firstChild = cat;
500 /* Make sure parent is initialized */
501 if (parent->threshold == xbt_log_priority_uninitialized) {
506 cat->threshold = parent->threshold;
507 cat->isThreshInherited = 1;
508 } /* log_setParent */
510 static void _set_inherited_thresholds(xbt_log_category_t cat) {
511 xbt_log_category_t child = cat->firstChild;
512 for( ; child != NULL; child = child->nextSibling) {
513 if (child->isThreshInherited) {
514 if (cat != &_XBT_LOGV(log))
515 VERB3("Set category threshold of %s to %s (=%d)",
516 child->name,xbt_log_priority_names[cat->threshold],cat->threshold);
517 child->threshold = cat->threshold;
518 _set_inherited_thresholds(child);
523 void xbt_log_threshold_set(xbt_log_category_t cat,
524 e_xbt_log_priority_t threshold) {
525 cat->threshold = threshold;
526 cat->isThreshInherited = 0;
527 _set_inherited_thresholds(cat);
530 static void _xbt_log_parse_setting(const char* control_string,
531 xbt_log_setting_t set) {
532 const char *name, *dot, *eq;
535 if (!*control_string)
537 DEBUG1("Parse log setting '%s'",control_string);
539 control_string += strspn(control_string, " ");
540 name = control_string;
541 control_string += strcspn(control_string, ".= ");
542 dot = control_string;
543 control_string += strcspn(control_string, "= ");
545 control_string += strcspn(control_string, " ");
547 xbt_assert1(*dot == '.' && *eq == '=',
548 "Invalid control string '%s'",control_string);
550 if (!strncmp(dot + 1, "thresh", min(eq - dot - 1,strlen("thresh")))) {
552 char *neweq=xbt_strdup(eq+1);
555 while (*(++p) != '\0') {
556 if (*p >= 'a' && *p <= 'z') {
561 DEBUG1("New priority name = %s",neweq);
562 for (i=0; i<xbt_log_priority_infinite-1; i++) {
563 if (!strncmp(xbt_log_priority_names[i],neweq,p-eq)) {
564 DEBUG1("This is priority %d",i);
568 if (i<xbt_log_priority_infinite-1) {
571 xbt_assert1(FALSE,"Unknown priority name: %s",eq+1);
576 snprintf(buff,min(512,eq - dot - 1),"%s",dot+1);
577 xbt_assert1(FALSE,"Unknown setting of the log category: %s",buff);
579 set->catname=(char*)xbt_malloc(dot - name+1);
581 strncpy(set->catname,name,dot-name);
582 set->catname[dot-name]='\0'; /* Just in case */
583 DEBUG1("This is for cat '%s'", set->catname);
586 static xbt_log_category_t _xbt_log_cat_searchsub(xbt_log_category_t cat,char *name) {
587 xbt_log_category_t child;
589 if (!strcmp(cat->name,name)) {
592 for(child=cat->firstChild ; child != NULL; child = child->nextSibling) {
593 return _xbt_log_cat_searchsub(child,name);
595 THROW0(not_found_error,0,"No such category");
598 static void _cleanup_double_spaces(char *s) {
621 if (e ^ !isspace(*p))
632 * \param control_string What to parse
634 * Typically passed a command-line argument. The string has the syntax:
636 * ( [category] "." [keyword] "=" value (" ")... )...
638 * where [category] is one the category names (see \ref XBT_log_cats for a complete list)
639 * and keyword is one of the following:
641 * - thres: category's threshold priority. Possible values:
642 * TRACE,DEBUG,VERBOSE,INFO,WARNING,ERROR,CRITICAL
646 * This routine may only be called once and that must be before any other
647 * logging command! Typically, this is done from main().
648 * \todo the previous warning seems a bit old and need double checking
650 void xbt_log_control_set(const char* control_string) {
651 xbt_log_setting_t set;
656 DEBUG1("Parse log settings '%s'",control_string);
657 if (control_string == NULL)
659 if (xbt_log_settings == NULL)
660 xbt_log_settings = xbt_dynar_new(sizeof(xbt_log_setting_t),
663 set = xbt_new(s_xbt_log_setting_t,1);
664 cs=xbt_strdup(control_string);
666 _cleanup_double_spaces(cs);
669 xbt_log_category_t cat=NULL;
681 _xbt_log_parse_setting(p,set);
684 cat = _xbt_log_cat_searchsub(&_XBT_LOGV(root),set->catname);
687 if (e.category != not_found_error)
692 DEBUG0("Store for further application");
693 DEBUG1("push %p to the settings",(void*)set);
694 xbt_dynar_push(xbt_log_settings,&set);
695 /* malloc in advance the next slot */
696 set = xbt_new(s_xbt_log_setting_t,1);
700 DEBUG0("Apply directly");
702 xbt_log_threshold_set(cat,set->thresh);
709 void xbt_log_appender_set(xbt_log_category_t cat, xbt_log_appender_t app) {