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"
21 /** \defgroup XBT_log Logging support
22 * \brief A generic logging facility in the spirit of log4j
24 * This section describes the API to the log functions used
25 * everywhere in this project.
27 \section log_overview Overview
29 This is an adaptation of the log4c project, which is dead upstream, and
30 which I was given the permission to fork under the LGPL licence by the
31 authors. log4c itself was loosely based on the Apache project's Log4J,
32 Log4CC, etc. project. Because C is not object oriented, a lot had to change.
34 There is 3 main concepts: category, priority and appender. These three
35 concepts work together to enable developers to log messages according to
36 message type and priority, and to control at runtime how these messages are
37 formatted and where they are reported.
39 \section log_cat Category hierarchy
41 The first and foremost advantage of any logging API over plain printf()
42 resides in its ability to disable certain log statements while allowing
43 others to print unhindered. This capability assumes that the logging space,
44 that is, the space of all possible logging statements, is categorized
45 according to some developer-chosen criteria.
47 This observation led to choosing category as the central concept of the
48 system. Every category is declared by providing a name and an optional
49 parent. If no parent is explicitly named, the root category, LOG_ROOT_CAT is
50 the category's parent.
52 A category is created by a macro call at the top level of a file. A
53 category can be created with any one of the following macros:
55 - \ref XBT_LOG_NEW_CATEGORY(MyCat); Create a new root
56 - \ref XBT_LOG_NEW_SUBCATEGORY(MyCat, ParentCat);
57 Create a new category being child of the category ParentCat
58 - \ref XBT_LOG_NEW_DEFAULT_CATEGORY(MyCat);
59 Like XBT_LOG_NEW_CATEGORY, but the new category is the default one
61 - \ref XBT_LOG_NEW_DEFAULT_SUBCATEGORY(MyCat, ParentCat);
62 Like XBT_LOG_NEW_SUBCATEGORY, but the new category is the default one
65 The parent cat can be defined in the same file or in another file (in
66 which case you want to use the \ref XBT_LOG_EXTERNAL_CATEGORY macro to make
67 it visible in the current file), but each category may have only one
70 Typically, there will be a Category for each module and sub-module, so you
71 can independently control logging for each module.
73 For a list of all existing categories, please refer to the \ref XBT_log_cats section.
75 \section log_pri Priority
77 A category may be assigned a threshold priorty. The set of priorites are
78 defined by the \ref e_xbt_log_priority_t enum. All logging request under
79 this priority will be discarded.
81 If a given category is not assigned a threshold priority, then it inherits
82 one from its closest ancestor with an assigned threshold. To ensure that all
83 categories can eventually inherit a threshold, the root category always has
84 an assigned threshold priority.
86 Logging requests are made by invoking a logging macro on a category. All of
87 the macros have a printf-style format string followed by arguments. If you
88 compile with the -Wall option, gcc will warn you for unmatched arguments, ie
89 when you pass a pointer to a string where an integer was specified by the
90 format. This is usualy a good idea.
92 Because most C compilers do not support vararg macros, there is a version of
93 the macro for any number of arguments from 0 to 6. The macro name ends with
94 the total number of arguments.
96 Here is an example of the most basic type of macro. This is a logging
97 request with priority <i>warning</i>.
99 <code>CLOG5(MyCat, gras_log_priority_warning, "Values are: %d and '%s'", 5,
102 A logging request is said to be enabled if its priority is higher than or
103 equal to the threshold priority of its category. Otherwise, the request is
104 said to be disabled. A category without an assigned priority will inherit
105 one from the hierarchy.
107 It is possible to use any non-negative integer as a priority. If, as in the
108 example, one of the standard priorites is used, then there is a convenience
109 macro that is typically used instead. For example, the above example is
110 equivalent to the shorter:
112 <code>CWARN4(MyCat, "Values are: %d and '%s'", 5, "oops");</code>
114 \subsection log_subcat Using a default category
116 If \ref XBT_LOG_NEW_DEFAULT_SUBCATEGORY(MyCat, Parent) or
117 \ref XBT_LOG_NEW_DEFAULT_CATEGORY(MyCat) is used to create the
118 category, then the even shorter form can be used:
120 <code>WARN3("Values are: %d and '%s'", 5, "oops");</code>
122 Only one default category can be created per file, though multiple
123 non-defaults can be created and used.
125 \section log_example Example
127 Here is a more complete example:
132 / * create a category and a default subcategory * /
133 XBT_LOG_NEW_CATEGORY(VSS);
134 XBT_LOG_NEW_DEFAULT_SUBCATEGORY(SA, VSS);
137 / * Now set the parent's priority. (the string would typcially be a runtime option) * /
138 xbt_log_control_set("SA.thresh=3");
140 / * This request is enabled, because WARNING >= INFO. * /
141 CWARN2(VSS, "Low fuel level.");
143 / * This request is disabled, because DEBUG < INFO. * /
144 CDEBUG2(VSS, "Starting search for nearest gas station.");
146 / * The default category SA inherits its priority from VSS. Thus,
147 the following request is enabled because INFO >= INFO. * /
148 INFO1("Located nearest gas station.");
150 / * This request is disabled, because DEBUG < INFO. * /
151 DEBUG1("Exiting gas station search");
155 \section log_conf Configuration
156 Configuration is typically done during program initialization by invoking
157 the xbt_log_control_set() method. The control string passed to it typically
158 comes from the command line. Look at the documentation for that function for
159 the format of the control string.
161 Any SimGrid program can furthermore be configured at run time by passing a
162 --xbt-log argument on the command line (--gras-log, --msg-log and
163 --surf-log are synonyms). You can provide several of those arguments to
164 change the setting of several categories.
166 \section log_perf Performance
168 Clever design insures efficiency. Except for the first invocation, a
169 disabled logging request requires an a single comparison of a static
170 variable to a constant.
172 There is also compile time constant, \ref XBT_LOG_STATIC_THRESHOLD, which
173 causes all logging requests with a lower priority to be optimized to 0 cost
174 by the compiler. By setting it to gras_log_priority_infinite, all logging
175 requests are statically disabled and cost nothing. Released executables
176 might be compiled with
177 \verbatim-DXBT_LOG_STATIC_THRESHOLD=gras_log_priority_infinite\endverbatim
179 Compiling with the \verbatim-DNLOG\endverbatim option disables all logging
180 requests at compilation time while the \verbatim-DNDEBUG\endverbatim disables
181 the requests of priority below INFO.
183 \section log_app Appenders
185 Each category has an optional appender. An appender is a pointer to a
186 structure which starts with a pointer to a doAppend() function. DoAppend()
187 prints a message to a log.
189 When a category is passed a message by one of the logging macros, the
190 category performs the following actions:
192 - if the category has an appender, the message is passed to the
193 appender's doAppend() function,
194 - if 'willLogToParent' is true for the category, the message is passed
195 to the category's parent.
197 By default, only the root category have an appender, and 'willLogToParent'
198 is true for any other category. This situation causes all messages to be
199 logged by the root category's appender.
201 The default appender function currently prints to stderr, and no other one
202 exist, even if more would be needed, like the one able to send the logs to a
203 remote dedicated server, or other ones offering different output formats.
204 This is on our TODO list for quite a while now, but your help would be
207 \section log_misc Misc and Caveats
209 - Do not use any of the macros that start with '_'.
210 - Log4J has a 'rolling file appender' which you can select with a run-time
211 option and specify the max file size. This would be a nice default for
212 non-kernel applications.
213 - Careful, category names are global variables.
220 Dans gras, tu ne te contente pas d'écrire des choses à l'écran, mais tu
221 écris sur un sujet particulier (notion de canal) des choses d'une gravité
222 particulière. Il y a 7 niveaux de gravité.
223 trace: tracer les entrées dans une fonction, retour de fonction
224 (famille de macros XBT_IN/XBT_OUT)
225 debug: pour t'aider à mettre au point le module, potentiellement tres bavard
226 verbose: quelques infos succintes sur les internals du module
227 info: niveau normal, ton de la conversation
228 warning: problème potentiel, mais auquel on a su faire face
229 error: problème qui t'as empêché de faire ton job
230 critical: juste avant de mourir
232 Quand on compile avec -DNDEBUG (par défaut dans le paquet Debian), tout ce
233 qui est '>= verbose' est supprimé au moment de la compilation. Retiré du
236 Ensuite, tu écris dans un canal particulier. Tous les canaux sont rangés en
237 arbre. Il faudrait faire un ptit script qui fouille les sources à la
238 recherche des macros XBT_LOG_NEW_* utilisées pour créer des canaux. Le
239 dernier argument de ces macros est ignoré dans le source. Il est destiné à
240 être la documentation de la chose en une ligne. En gros, ca fait:
261 +--raw_trp (Je devrais tuer ce module, un jour)
267 Et ensuite les utilisateurs peuvent choisir le niveau de gravité qui les
268 interresse sur tel ou tel sujet.
270 Toute la mécanique de logging repose sur des variables statiques dont le nom
271 dépend du nom du canal.
272 => attention aux conflits de nom de canal
273 => il faut une macro XBT_LOG dans chaque fichier où tu fais des logs.
275 XBT_LOG_NEW_CATEGORY: nouveau canal sous "root". Rare, donc.
276 XBT_LOG_NEW_SUBCATEGORY: nouveau canal dont on précise le père.
277 XBT_LOG_DEFAULT_CATEGORY: indique quel est le canal par défaut dans ce fichier
278 XBT_LOG_NEW_DEFAULT_CATEGORY: Crèe un canal et l'utilise par défaut
279 XBT_LOG_NEW_DEFAULT_SUBCATEGORY: devine
280 XBT_LOG_EXTERNAL_CATEGORY: quand tu veux utiliser par défaut un canal créé
281 dans un autre fichier.
283 Une fois que ton canal est créé, tu l'utilise avec les macros LOG, DEBUG,
284 VERB, WARN, ERROR et CRITICAL. Il faut que tu donne le nombre d'arguments
285 après le nom de macro. Exemple: LOG2("My name is %s %s","Martin","Quinson")
286 Si tu veux préciser explicitement le canal où écrire, ajoute un C devant le
287 nom de la macro. Exemple: CCRITICAL0(module, "Cannot initialize GRAS")
289 Toutes ces macros (enfin, ce en quoi elles se réécrivent) vérifient leurs
290 arguments comme printf le fait lorsqu'on compile avec gcc.
291 LOG1("name: %d","toto"); donne un warning, et donc une erreur en mode
294 Enfin, tu peux tester si un canal est ouvert à une priorité donnée (pour
295 préparer plus de débug, par exemple. Dans le parseur, je fais du pretty
296 printing sur ce qu'il faut parser dans ce cas).
297 XBT_LOG_ISENABLED(catName, priority) Le second argument doit être une valeur
298 de e_xbt_log_priority_t (log.h). Par exemple: xbt_log_priority_verbose
300 Voila sur comment mettre des logs dans ton code. N'hesite pas à faire pleins
301 de canaux différents pour des aspects différents de ton code. En
302 particulier, dans les dict, j'ai un canal pour l'ajout, le retrait, le
303 netoyage du code après suppression et ainsi de suite. De cette façon, je
304 peux choisir qui m'interresse.
307 Pour utiliser les logs, tu déjà faire, non ? Tu colle sur la ligne de
308 commande un ou plusieurs arguments de la forme
309 --gras-log="<réglage> [<reglage>+]" (ou sans " si t'as pas d'espace)
310 chaque réglage étant de la forme:
311 <canal>.thres=<priorité>
312 Les différents réglages sont lus de gauche à droite.
313 "root.thres=debug root.thres=critical" ferme tout, normalement.
319 e_xbt_log_priority_t thresh;
320 } s_xbt_log_setting_t,*xbt_log_setting_t;
322 static xbt_dynar_t xbt_log_settings=NULL;
323 static void _free_setting(void *s) {
324 xbt_log_setting_t set=(xbt_log_setting_t)s;
326 xbt_free(set->catname);
327 /* xbt_free(set); FIXME: uncommenting this leads to segfault when more than one chunk is passed as gras-log */
331 const char *xbt_log_priority_names[8] = {
342 s_xbt_log_category_t _XBT_LOGV(XBT_LOG_ROOT_CAT) = {
344 "root", xbt_log_priority_uninitialized, 0,
348 XBT_LOG_NEW_CATEGORY(xbt,"All XBT categories (simgrid toolbox)");
349 XBT_LOG_NEW_CATEGORY(surf,"All SURF categories");
350 XBT_LOG_NEW_CATEGORY(msg,"All MSG categories");
351 XBT_LOG_NEW_DEFAULT_SUBCATEGORY(log,xbt,"Loggings from the logging mecanism itself");
353 void xbt_log_init(int *argc,char **argv, const char *defaultlog) {
358 /* Set logs and init log submodule */
359 for (i=1; i<*argc; i++) {
360 if (!strncmp(argv[i],"--gras-log=",strlen("--gras-log=")) ||
361 !strncmp(argv[i],"--surf-log=",strlen("--surf-log=")) ||
362 !strncmp(argv[i],"--msg-log=",strlen("--msg-log=")) ||
363 !strncmp(argv[i],"--xbt-log=",strlen("--xbt-log="))) {
365 opt=strchr(argv[i],'=');
367 xbt_log_control_set(opt);
368 DEBUG1("Did apply '%s' as log setting",opt);
369 /*remove this from argv*/
370 for (j=i+1; j<*argc; j++) {
375 i--; /* compensate effect of next loop incrementation */
378 if (!found && defaultlog) {
379 xbt_log_control_set(defaultlog);
383 void xbt_log_exit(void) {
384 VERB0("Exiting log");
385 xbt_dynar_free(&xbt_log_settings);
389 static void _apply_control(xbt_log_category_t cat) {
391 xbt_log_setting_t setting=NULL;
394 if (!xbt_log_settings)
397 xbt_assert0(cat,"NULL category");
398 xbt_assert(cat->name);
400 xbt_dynar_foreach(xbt_log_settings,cursor,setting) {
401 xbt_assert0(setting,"Damnit, NULL cat in the list");
402 xbt_assert1(setting->catname,"NULL setting(=%p)->catname",(void*)setting);
404 if (!strcmp(setting->catname,cat->name)) {
407 xbt_log_threshold_set(cat, setting->thresh);
408 xbt_dynar_cursor_rm(xbt_log_settings,&cursor);
410 if (cat->threshold <= xbt_log_priority_verbose) {
411 s_xbt_log_event_t _log_ev =
412 {cat,xbt_log_priority_verbose,__FILE__,_XBT_GNUC_FUNCTION,__LINE__};
413 _xbt_log_event_log(&_log_ev,
414 "Apply settings for category '%s': set threshold to %s (=%d)",
416 xbt_log_priority_names[cat->threshold], cat->threshold);
420 if (!found && cat->threshold <= xbt_log_priority_verbose) {
421 s_xbt_log_event_t _log_ev =
422 {cat,xbt_log_priority_verbose,__FILE__,_XBT_GNUC_FUNCTION,__LINE__};
423 _xbt_log_event_log(&_log_ev,
424 "Category '%s': inherited threshold = %s (=%d)",
426 xbt_log_priority_names[cat->threshold], cat->threshold);
431 void _xbt_log_event_log( xbt_log_event_t ev, const char *fmt, ...) {
432 xbt_log_category_t cat = ev->cat;
433 va_start(ev->ap, fmt);
435 xbt_log_appender_t appender = cat->appender;
436 if (appender != NULL) {
437 appender->do_append(appender, ev, fmt);
439 if (!cat->willLogToParent)
447 static void _cat_init(xbt_log_category_t category) {
448 if (category == &_XBT_LOGV(XBT_LOG_ROOT_CAT)) {
449 category->threshold = xbt_log_priority_info;
450 category->appender = xbt_log_default_appender;
452 xbt_log_parent_set(category, category->parent);
454 _apply_control(category);
458 * This gets called the first time a category is referenced and performs the
460 * Also resets threshold to inherited!
462 int _xbt_log_cat_init(e_xbt_log_priority_t priority,
463 xbt_log_category_t category) {
467 return priority >= category->threshold;
470 void xbt_log_parent_set(xbt_log_category_t cat,
471 xbt_log_category_t parent) {
473 xbt_assert0(cat,"NULL category to be given a parent");
474 xbt_assert1(parent,"The parent category of %s is NULL",cat->name);
476 /* unlink from current parent */
477 if (cat->threshold != xbt_log_priority_uninitialized) {
478 xbt_log_category_t* cpp = &parent->firstChild;
479 while(*cpp != cat && *cpp != NULL) {
480 cpp = &(*cpp)->nextSibling;
482 xbt_assert(*cpp == cat);
483 *cpp = cat->nextSibling;
487 cat->parent = parent;
488 cat->nextSibling = parent->firstChild;
489 parent->firstChild = cat;
491 /* Make sure parent is initialized */
492 if (parent->threshold == xbt_log_priority_uninitialized) {
497 cat->threshold = parent->threshold;
498 cat->isThreshInherited = 1;
499 } /* log_setParent */
501 static void _set_inherited_thresholds(xbt_log_category_t cat) {
502 xbt_log_category_t child = cat->firstChild;
503 for( ; child != NULL; child = child->nextSibling) {
504 if (child->isThreshInherited) {
505 if (cat != &_XBT_LOGV(log))
506 VERB3("Set category threshold of %s to %s (=%d)",
507 child->name,xbt_log_priority_names[cat->threshold],cat->threshold);
508 child->threshold = cat->threshold;
509 _set_inherited_thresholds(child);
514 void xbt_log_threshold_set(xbt_log_category_t cat,
515 e_xbt_log_priority_t threshold) {
516 cat->threshold = threshold;
517 cat->isThreshInherited = 0;
518 _set_inherited_thresholds(cat);
521 static void _xbt_log_parse_setting(const char* control_string,
522 xbt_log_setting_t set) {
523 const char *name, *dot, *eq;
526 if (!*control_string)
528 DEBUG1("Parse log setting '%s'",control_string);
530 control_string += strspn(control_string, " ");
531 name = control_string;
532 control_string += strcspn(control_string, ".= ");
533 dot = control_string;
534 control_string += strcspn(control_string, "= ");
536 control_string += strcspn(control_string, " ");
538 xbt_assert1(*dot == '.' && *eq == '=',
539 "Invalid control string '%s'",control_string);
541 if (!strncmp(dot + 1, "thresh", min(eq - dot - 1,strlen("thresh")))) {
543 char *neweq=xbt_strdup(eq+1);
546 while (*(++p) != '\0') {
547 if (*p >= 'a' && *p <= 'z') {
552 DEBUG1("New priority name = %s",neweq);
553 for (i=0; i<xbt_log_priority_infinite-1; i++) {
554 if (!strncmp(xbt_log_priority_names[i],neweq,p-eq)) {
555 DEBUG1("This is priority %d",i);
559 if (i<xbt_log_priority_infinite-1) {
562 xbt_assert1(FALSE,"Unknown priority name: %s",eq+1);
567 snprintf(buff,min(512,eq - dot - 1),"%s",dot+1);
568 xbt_assert1(FALSE,"Unknown setting of the log category: %s",buff);
570 set->catname=(char*)xbt_malloc(dot - name+1);
572 strncpy(set->catname,name,dot-name);
573 set->catname[dot-name]='\0'; /* Just in case */
574 DEBUG1("This is for cat '%s'", set->catname);
577 static xbt_error_t _xbt_log_cat_searchsub(xbt_log_category_t cat,char *name,
578 /*OUT*/xbt_log_category_t*whereto) {
580 xbt_log_category_t child;
582 if (!strcmp(cat->name,name)) {
586 for(child=cat->firstChild ; child != NULL; child = child->nextSibling) {
587 errcode=_xbt_log_cat_searchsub(child,name,whereto);
588 if (errcode==no_error)
591 return mismatch_error;
594 static void _cleanup_double_spaces(char *s) {
617 if (e ^ !isspace(*p))
628 * \param control_string What to parse
630 * Typically passed a command-line argument. The string has the syntax:
632 * ( [category] "." [keyword] "=" value (" ")... )...
634 * where [category] is one the category names and keyword is one of the
637 * thresh value is an integer priority level. Sets the category's
638 * threshold priority.
641 * This routine may only be called once and that must be before any other
642 * logging command! Typically, this is done from main().
644 void xbt_log_control_set(const char* control_string) {
646 xbt_log_setting_t set;
651 DEBUG1("Parse log settings '%s'",control_string);
652 if (control_string == NULL)
654 if (xbt_log_settings == NULL)
655 xbt_log_settings = xbt_dynar_new(sizeof(xbt_log_setting_t),
658 set = xbt_new(s_xbt_log_setting_t,1);
659 cs=xbt_strdup(control_string);
661 _cleanup_double_spaces(cs);
664 xbt_log_category_t cat;
674 _xbt_log_parse_setting(p,set);
676 errcode = _xbt_log_cat_searchsub(&_XBT_LOGV(root),set->catname,&cat);
677 if (errcode == mismatch_error) {
678 DEBUG0("Store for further application");
679 DEBUG1("push %p to the settings",(void*)set);
680 xbt_dynar_push(xbt_log_settings,&set);
681 /* malloc in advance the next slot */
682 set = xbt_new(s_xbt_log_setting_t,1);
684 DEBUG0("Apply directly");
685 xbt_free(set->catname);
686 xbt_log_threshold_set(cat,set->thresh);
693 void xbt_log_appender_set(xbt_log_category_t cat, xbt_log_appender_t app) {