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 "xbt_modinter.h"
16 #include "xbt/sysdep.h"
18 #include "xbt/error.h"
19 #include "xbt/dynar.h"
22 /** \defgroup XBT_log Logging support.
23 * \brief A generic logging facility in the spirit of log4j
25 * This section describes the API to the log functions used
26 * everywhere in this project.
30 This is an adaptation of the log4c project, which is dead upstream, and
31 which I was given the permission to fork under the LGPL licence by the
32 authors. log4c itself was loosely based on the Apache project's Log4J,
33 Log4CC, etc. project. Because C is not object oriented, a lot had to change.
35 There is 3 main concepts: category, priority and appender. These three
36 concepts work together to enable developers to log messages according to
37 message type and priority, and to control at runtime how these messages are
38 formatted and where they are reported.
40 <h3>Category hierarchy</h3>
42 The first and foremost advantage of any logging API over plain printf()
43 resides in its ability to disable certain log statements while allowing
44 others to print unhindered. This capability assumes that the logging space,
45 that is, the space of all possible logging statements, is categorized
46 according to some developer-chosen criteria.
48 This observation led to choosing category as the central concept of the
49 system. Every category is declared by providing a name and an optional
50 parent. If no parent is explicitly named, the root category, LOG_ROOT_CAT is
51 the category's parent.
53 A category is created by a macro call at the top level of a file. A
54 category can be created with any one of the following macros:
56 - \ref XBT_LOG_NEW_CATEGORY(MyCat); Create a new root
57 - \ref XBT_LOG_NEW_SUBCATEGORY(MyCat, ParentCat);
58 Create a new category being child of the category ParentCat
59 - \ref XBT_LOG_NEW_DEFAULT_CATEGORY(MyCat);
60 Like XBT_LOG_NEW_CATEGORY, but the new category is the default one
62 - \ref XBT_LOG_NEW_DEFAULT_SUBCATEGORY(MyCat, ParentCat);
63 Like XBT_LOG_NEW_SUBCATEGORY, but the new category is the default one
66 The parent cat can be defined in the same file or in another file (in
67 which case you want to use the \ref XBT_LOG_EXTERNAL_CATEGORY macro to make
68 it visible in the current file), but each category may have only one
71 Typically, there will be a Category for each module and sub-module, so you
72 can independently control logging for each module.
76 A category may be assigned a threshold priorty. The set of priorites are
77 defined by the \ref e_xbt_log_priority_t enum. All logging request under
78 this priority will be discarded.
80 If a given category is not assigned a threshold priority, then it inherits
81 one from its closest ancestor with an assigned threshold. To ensure that all
82 categories can eventually inherit a threshold, the root category always has
83 an assigned threshold priority.
85 Logging requests are made by invoking a logging macro on a category. All of
86 the macros have a printf-style format string followed by arguments. If you
87 compile with the -Wall option, gcc will warn you for unmatched arguments, ie
88 when you pass a pointer to a string where an integer was specified by the
89 format. This is usualy a good idea.
91 Because most C compilers do not support vararg macros, there is a version of
92 the macro for any number of arguments from 0 to 6. The macro name ends with
93 the total number of arguments.
95 Here is an example of the most basic type of macro. This is a logging
96 request with priority <i>warning</i>.
98 <code>CLOG5(MyCat, gras_log_priority_warning, "Values are: %d and '%s'", 5,
101 A logging request is said to be enabled if its priority is higher than or
102 equal to the threshold priority of its category. Otherwise, the request is
103 said to be disabled. A category without an assigned priority will inherit
104 one from the hierarchy.
106 It is possible to use any non-negative integer as a priority. If, as in the
107 example, one of the standard priorites is used, then there is a convenience
108 macro that is typically used instead. For example, the above example is
109 equivalent to the shorter:
111 <code>CWARN4(MyCat, "Values are: %d and '%s'", 5, "oops");</code>
113 <h3>Default category</h3>
115 If \ref XBT_LOG_NEW_DEFAULT_SUBCATEGORY(MyCat, Parent) or
116 \ref XBT_LOG_NEW_DEFAULT_CATEGORY(MyCat) is used to create the
117 category, then the even shorter form can be used:
119 <code>WARN3("Values are: %d and '%s'", 5, "oops");</code>
121 Only one default category can be created per file, though multiple
122 non-defaults can be created and used.
126 Here is a more complete example:
131 / * create a category and a default subcategory * /
132 XBT_LOG_NEW_CATEGORY(VSS);
133 XBT_LOG_NEW_DEFAULT_SUBCATEGORY(SA, VSS);
136 / * Now set the parent's priority. (the string would typcially be a runtime option) * /
137 xbt_log_control_set("SA.thresh=3");
139 / * This request is enabled, because WARNING >= INFO. * /
140 CWARN2(VSS, "Low fuel level.");
142 / * This request is disabled, because DEBUG < INFO. * /
143 CDEBUG2(VSS, "Starting search for nearest gas station.");
145 / * The default category SA inherits its priority from VSS. Thus,
146 the following request is enabled because INFO >= INFO. * /
147 INFO1("Located nearest gas station.");
149 / * This request is disabled, because DEBUG < INFO. * /
150 DEBUG1("Exiting gas station search");
154 <h3>Configuration</h3>
155 Configuration is typically done during program initialization by invoking
156 the xbt_log_control_set() method. The control string passed to it typically
157 comes from the command line. Look at the documentation for that function for
158 the format of the control string.
160 Any SimGrid program can furthermore be configured at run time by passing a
161 --xbt-log argument on the command line (--gras-log, --msg-log and
162 --surf-log are synonyms). You can provide several of those arguments to
163 change the setting of several categories.
167 Clever design insures efficiency. Except for the first invocation, a
168 disabled logging request requires an a single comparison of a static
169 variable to a constant.
171 There is also compile time constant, \ref XBT_LOG_STATIC_THRESHOLD, which
172 causes all logging requests with a lower priority to be optimized to 0 cost
173 by the compiler. By setting it to gras_log_priority_infinite, all logging
174 requests are statically disabled and cost nothing. Released executables
175 might be compiled with
176 \verbatim-DXBT_LOG_STATIC_THRESHOLD=gras_log_priority_infinite\endverbatim
180 Each category has an optional appender. An appender is a pointer to a
181 structure which starts with a pointer to a doAppend() function. DoAppend()
182 prints a message to a log.
184 When a category is passed a message by one of the logging macros, the
185 category performs the following actions:
187 - if the category has an appender, the message is passed to the
188 appender's doAppend() function,
189 - if 'willLogToParent' is true for the category, the message is passed
190 to the category's parent.
192 By default, only the root category have an appender, and 'willLogToParent'
193 is true for any other category. This situation causes all messages to be
194 logged by the root category's appender.
196 The default appender function currently prints to stderr, and no other one
197 exist, even if more would be needed, like the one able to send the logs to a
198 remote dedicated server, or other ones offering different output formats.
199 This is on our TODO list for quite a while now, but your help would be
202 <h3>Misc and Caveats</h3>
204 Do not use any of the macros that start with '_'.
206 Log4J has a 'rolling file appender' which you can select with a run-time
207 option and specify the max file size. This would be a nice default for
208 non-kernel applications.
210 Careful, category names are global variables.
217 Dans gras, tu ne te contente pas d'écrire des choses à l'écran, mais tu
218 écris sur un sujet particulier (notion de canal) des choses d'une gravité
219 particulière. Il y a 7 niveaux de gravité.
220 trace: tracer les entrées dans une fonction, retour de fonction
221 (famille de macros XBT_IN/XBT_OUT)
222 debug: pour t'aider à mettre au point le module, potentiellement tres bavard
223 verbose: quelques infos succintes sur les internals du module
224 info: niveau normal, ton de la conversation
225 warning: problème potentiel, mais auquel on a su faire face
226 error: problème qui t'as empêché de faire ton job
227 critical: juste avant de mourir
229 Quand on compile avec -DNDEBUG (par défaut dans le paquet Debian), tout ce
230 qui est '>= verbose' est supprimé au moment de la compilation. Retiré du
233 Ensuite, tu écris dans un canal particulier. Tous les canaux sont rangés en
234 arbre. Il faudrait faire un ptit script qui fouille les sources à la
235 recherche des macros XBT_LOG_NEW_* utilisées pour créer des canaux. Le
236 dernier argument de ces macros est ignoré dans le source. Il est destiné à
237 être la documentation de la chose en une ligne. En gros, ca fait:
258 +--raw_trp (Je devrais tuer ce module, un jour)
264 Et ensuite les utilisateurs peuvent choisir le niveau de gravité qui les
265 interresse sur tel ou tel sujet.
267 Toute la mécanique de logging repose sur des variables statiques dont le nom
268 dépend du nom du canal.
269 => attention aux conflits de nom de canal
270 => il faut une macro XBT_LOG dans chaque fichier où tu fais des logs.
272 XBT_LOG_NEW_CATEGORY: nouveau canal sous "root". Rare, donc.
273 XBT_LOG_NEW_SUBCATEGORY: nouveau canal dont on précise le père.
274 XBT_LOG_DEFAULT_CATEGORY: indique quel est le canal par défaut dans ce fichier
275 XBT_LOG_NEW_DEFAULT_CATEGORY: Crèe un canal et l'utilise par défaut
276 XBT_LOG_NEW_DEFAULT_SUBCATEGORY: devine
277 XBT_LOG_EXTERNAL_CATEGORY: quand tu veux utiliser par défaut un canal créé
278 dans un autre fichier.
280 Une fois que ton canal est créé, tu l'utilise avec les macros LOG, DEBUG,
281 VERB, WARN, ERROR et CRITICAL. Il faut que tu donne le nombre d'arguments
282 après le nom de macro. Exemple: LOG2("My name is %s %s","Martin","Quinson")
283 Si tu veux préciser explicitement le canal où écrire, ajoute un C devant le
284 nom de la macro. Exemple: CCRITICAL0(module, "Cannot initialize GRAS")
286 Toutes ces macros (enfin, ce en quoi elles se réécrivent) vérifient leurs
287 arguments comme printf le fait lorsqu'on compile avec gcc.
288 LOG1("name: %d","toto"); donne un warning, et donc une erreur en mode
291 Enfin, tu peux tester si un canal est ouvert à une priorité donnée (pour
292 préparer plus de débug, par exemple. Dans le parseur, je fais du pretty
293 printing sur ce qu'il faut parser dans ce cas).
294 XBT_LOG_ISENABLED(catName, priority) Le second argument doit être une valeur
295 de e_xbt_log_priority_t (log.h). Par exemple: xbt_log_priority_verbose
297 Voila sur comment mettre des logs dans ton code. N'hesite pas à faire pleins
298 de canaux différents pour des aspects différents de ton code. En
299 particulier, dans les dict, j'ai un canal pour l'ajout, le retrait, le
300 netoyage du code après suppression et ainsi de suite. De cette façon, je
301 peux choisir qui m'interresse.
304 Pour utiliser les logs, tu déjà faire, non ? Tu colle sur la ligne de
305 commande un ou plusieurs arguments de la forme
306 --gras-log="<réglage> [<reglage>+]" (ou sans " si t'as pas d'espace)
307 chaque réglage étant de la forme:
308 <canal>.thres=<priorité>
309 Les différents réglages sont lus de gauche à droite.
310 "root.thres=debug root.thres=critical" ferme tout, normalement.
316 e_xbt_log_priority_t thresh;
317 } s_xbt_log_setting_t,*xbt_log_setting_t;
319 static xbt_dynar_t xbt_log_settings=NULL;
320 static void _free_setting(void *s) {
321 xbt_log_setting_t set=(xbt_log_setting_t)s;
323 xbt_free(set->catname);
324 /* xbt_free(set); FIXME: uncommenting this leads to segfault when more than one chunk is passed as gras-log */
328 const char *xbt_log_priority_names[8] = {
339 s_xbt_log_category_t _XBT_LOGV(XBT_LOG_ROOT_CAT) = {
341 "root", xbt_log_priority_uninitialized, 0,
345 XBT_LOG_NEW_SUBCATEGORY(xbt,XBT_LOG_ROOT_CAT,"All XBT categories (simgrid toolbox)");
346 XBT_LOG_NEW_SUBCATEGORY(surf,XBT_LOG_ROOT_CAT,"All SURF categories");
347 XBT_LOG_NEW_DEFAULT_SUBCATEGORY(log,xbt,"Loggings from the logging mecanism itself");
349 void xbt_log_init(int *argc,char **argv, const char *defaultlog) {
354 /** Set logs and init log submodule */
355 for (i=1; i<*argc; i++) {
356 if (!strncmp(argv[i],"--gras-log=",strlen("--gras-log=")) ||
357 !strncmp(argv[i],"--surf-log=",strlen("--surf-log=")) ||
358 !strncmp(argv[i],"--msg-log=",strlen("--msg-log=")) ||
359 !strncmp(argv[i],"--xbt-log=",strlen("--xbt-log="))) {
361 opt=strchr(argv[i],'=');
363 xbt_log_control_set(opt);
364 DEBUG1("Did apply '%s' as log setting",opt);
365 /*remove this from argv*/
366 for (j=i+1; j<*argc; j++) {
371 i--; /* compensate effect of next loop incrementation */
374 if (!found && defaultlog) {
375 xbt_log_control_set(defaultlog);
379 void xbt_log_exit(void) {
380 VERB0("Exiting log");
381 xbt_dynar_free(&xbt_log_settings);
385 static void _apply_control(xbt_log_category_t cat) {
387 xbt_log_setting_t setting=NULL;
390 if (!xbt_log_settings)
393 xbt_assert0(cat,"NULL category");
394 xbt_assert(cat->name);
396 xbt_dynar_foreach(xbt_log_settings,cursor,setting) {
397 xbt_assert0(setting,"Damnit, NULL cat in the list");
398 xbt_assert1(setting->catname,"NULL setting(=%p)->catname",(void*)setting);
400 if (!strcmp(setting->catname,cat->name)) {
403 xbt_log_threshold_set(cat, setting->thresh);
404 xbt_dynar_cursor_rm(xbt_log_settings,&cursor);
406 if (cat->threshold <= xbt_log_priority_verbose) {
407 s_xbt_log_event_t _log_ev =
408 {cat,xbt_log_priority_verbose,__FILE__,_XBT_GNUC_FUNCTION,__LINE__};
409 _xbt_log_event_log(&_log_ev,
410 "Apply settings for category '%s': set threshold to %s (=%d)",
412 xbt_log_priority_names[cat->threshold], cat->threshold);
416 if (!found && cat->threshold <= xbt_log_priority_verbose) {
417 s_xbt_log_event_t _log_ev =
418 {cat,xbt_log_priority_verbose,__FILE__,_XBT_GNUC_FUNCTION,__LINE__};
419 _xbt_log_event_log(&_log_ev,
420 "Category '%s': inherited threshold = %s (=%d)",
422 xbt_log_priority_names[cat->threshold], cat->threshold);
427 void _xbt_log_event_log( xbt_log_event_t ev, const char *fmt, ...) {
428 xbt_log_category_t cat = ev->cat;
429 va_start(ev->ap, fmt);
431 xbt_log_appender_t appender = cat->appender;
432 if (appender != NULL) {
433 appender->do_append(appender, ev, fmt);
435 if (!cat->willLogToParent)
443 static void _cat_init(xbt_log_category_t category) {
444 if (category == &_XBT_LOGV(XBT_LOG_ROOT_CAT)) {
445 category->threshold = xbt_log_priority_info;
446 category->appender = xbt_log_default_appender;
448 xbt_log_parent_set(category, category->parent);
450 _apply_control(category);
454 * This gets called the first time a category is referenced and performs the
456 * Also resets threshold to inherited!
458 int _xbt_log_cat_init(e_xbt_log_priority_t priority,
459 xbt_log_category_t category) {
463 return priority >= category->threshold;
466 void xbt_log_parent_set(xbt_log_category_t cat,
467 xbt_log_category_t parent) {
469 xbt_assert0(cat,"NULL category to be given a parent");
470 xbt_assert1(parent,"The parent category of %s is NULL",cat->name);
472 /* unlink from current parent */
473 if (cat->threshold != xbt_log_priority_uninitialized) {
474 xbt_log_category_t* cpp = &parent->firstChild;
475 while(*cpp != cat && *cpp != NULL) {
476 cpp = &(*cpp)->nextSibling;
478 xbt_assert(*cpp == cat);
479 *cpp = cat->nextSibling;
483 cat->parent = parent;
484 cat->nextSibling = parent->firstChild;
485 parent->firstChild = cat;
487 /* Make sure parent is initialized */
488 if (parent->threshold == xbt_log_priority_uninitialized) {
493 cat->threshold = parent->threshold;
494 cat->isThreshInherited = 1;
495 } /* log_setParent */
497 static void _set_inherited_thresholds(xbt_log_category_t cat) {
498 xbt_log_category_t child = cat->firstChild;
499 for( ; child != NULL; child = child->nextSibling) {
500 if (child->isThreshInherited) {
501 if (cat != &_XBT_LOGV(log))
502 VERB3("Set category threshold of %s to %s (=%d)",
503 child->name,xbt_log_priority_names[cat->threshold],cat->threshold);
504 child->threshold = cat->threshold;
505 _set_inherited_thresholds(child);
510 void xbt_log_threshold_set(xbt_log_category_t cat,
511 e_xbt_log_priority_t threshold) {
512 cat->threshold = threshold;
513 cat->isThreshInherited = 0;
514 _set_inherited_thresholds(cat);
517 static void _xbt_log_parse_setting(const char* control_string,
518 xbt_log_setting_t set) {
519 const char *name, *dot, *eq;
522 if (!*control_string)
524 DEBUG1("Parse log setting '%s'",control_string);
526 control_string += strspn(control_string, " ");
527 name = control_string;
528 control_string += strcspn(control_string, ".= ");
529 dot = control_string;
530 control_string += strcspn(control_string, "= ");
532 control_string += strcspn(control_string, " ");
534 xbt_assert1(*dot == '.' && *eq == '=',
535 "Invalid control string '%s'",control_string);
537 if (!strncmp(dot + 1, "thresh", min(eq - dot - 1,strlen("thresh")))) {
539 char *neweq=xbt_strdup(eq+1);
542 while (*(++p) != '\0') {
543 if (*p >= 'a' && *p <= 'z') {
548 DEBUG1("New priority name = %s",neweq);
549 for (i=0; i<xbt_log_priority_infinite-1; i++) {
550 if (!strncmp(xbt_log_priority_names[i],neweq,p-eq)) {
551 DEBUG1("This is priority %d",i);
555 if (i<xbt_log_priority_infinite-1) {
558 xbt_assert1(FALSE,"Unknown priority name: %s",eq+1);
563 snprintf(buff,min(512,eq - dot - 1),"%s",dot+1);
564 xbt_assert1(FALSE,"Unknown setting of the log category: %s",buff);
566 set->catname=(char*)xbt_malloc(dot - name+1);
568 strncpy(set->catname,name,dot-name);
569 set->catname[dot-name]='\0'; /* Just in case */
570 DEBUG1("This is for cat '%s'", set->catname);
573 static xbt_error_t _xbt_log_cat_searchsub(xbt_log_category_t cat,char *name,
574 /*OUT*/xbt_log_category_t*whereto) {
576 xbt_log_category_t child;
578 if (!strcmp(cat->name,name)) {
582 for(child=cat->firstChild ; child != NULL; child = child->nextSibling) {
583 errcode=_xbt_log_cat_searchsub(child,name,whereto);
584 if (errcode==no_error)
587 return mismatch_error;
590 static void _cleanup_double_spaces(char *s) {
613 if (e ^ !isspace(*p))
624 * \param control_string What to parse
626 * Typically passed a command-line argument. The string has the syntax:
628 * ( [category] "." [keyword] "=" value (" ")... )...
630 * where [category] is one the category names and keyword is one of the
633 * thresh value is an integer priority level. Sets the category's
634 * threshold priority.
637 * This routine may only be called once and that must be before any other
638 * logging command! Typically, this is done from main().
640 void xbt_log_control_set(const char* control_string) {
642 xbt_log_setting_t set;
647 DEBUG1("Parse log settings '%s'",control_string);
648 if (control_string == NULL)
650 if (xbt_log_settings == NULL)
651 xbt_log_settings = xbt_dynar_new(sizeof(xbt_log_setting_t),
654 set = xbt_new(s_xbt_log_setting_t,1);
655 cs=xbt_strdup(control_string);
657 _cleanup_double_spaces(cs);
660 xbt_log_category_t cat;
670 _xbt_log_parse_setting(p,set);
672 errcode = _xbt_log_cat_searchsub(&_XBT_LOGV(root),set->catname,&cat);
673 if (errcode == mismatch_error) {
674 DEBUG0("Store for further application");
675 DEBUG1("push %p to the settings",(void*)set);
676 xbt_dynar_push(xbt_log_settings,&set);
677 /* malloc in advance the next slot */
678 set = xbt_new(s_xbt_log_setting_t,1);
680 DEBUG0("Apply directly");
681 xbt_free(set->catname);
682 xbt_log_threshold_set(cat,set->thresh);
689 void xbt_log_appender_set(xbt_log_category_t cat, xbt_log_appender_t app) {