Logo AND Algorithmique Numérique Distribuée

Public GIT Repository
kill defaultlog
[simgrid.git] / src / xbt / log.c
1 /* $Id$ */
2
3 /* log - a generic logging facility in the spirit of log4j                  */
4
5 /* Copyright (c) 2003, 2004 Martin Quinson. All rights reserved.            */
6
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. */
9
10 #include <stdarg.h>
11 #include <ctype.h>
12
13 #include "xbt_modinter.h"
14
15 #include "xbt/misc.h"
16 #include "xbt/sysdep.h"
17 #include "xbt/log.h"
18 #include "xbt/error.h"
19 #include "xbt/dynar.h"
20
21 /** \addtogroup XBT_log
22  *
23  *  This section describes the API to the log functions used 
24  *  everywhere in this project.
25      
26 \section log_overview Overview
27      
28 This is an adaptation of the log4c project, which is dead upstream, and
29 which I was given the permission to fork under the LGPL licence by the
30 authors. log4c itself was loosely based on the Apache project's Log4J,
31 Log4CC, etc. project. Because C is not object oriented, a lot had to change.
32     
33 There is 3 main concepts: category, priority and appender. These three
34 concepts work together to enable developers to log messages according to
35 message type and priority, and to control at runtime how these messages are
36 formatted and where they are reported.
37
38 \section log_cat Category hierarchy
39
40 The first and foremost advantage of any logging API over plain printf()
41 resides in its ability to disable certain log statements while allowing
42 others to print unhindered. This capability assumes that the logging space,
43 that is, the space of all possible logging statements, is categorized
44 according to some developer-chosen criteria. 
45           
46 This observation led to choosing category as the central concept of the
47 system. Every category is declared by providing a name and an optional
48 parent. If no parent is explicitly named, the root category, LOG_ROOT_CAT is
49 the category's parent. 
50       
51 A category is created by a macro call at the top level of a file.  A
52 category can be created with any one of the following macros:
53
54  - \ref XBT_LOG_NEW_CATEGORY(MyCat); Create a new root
55  - \ref XBT_LOG_NEW_SUBCATEGORY(MyCat, ParentCat);
56     Create a new category being child of the category ParentCat
57  - \ref XBT_LOG_NEW_DEFAULT_CATEGORY(MyCat);
58     Like XBT_LOG_NEW_CATEGORY, but the new category is the default one
59       in this file
60  -  \ref XBT_LOG_NEW_DEFAULT_SUBCATEGORY(MyCat, ParentCat);
61     Like XBT_LOG_NEW_SUBCATEGORY, but the new category is the default one
62       in this file
63             
64 The parent cat can be defined in the same file or in another file (in
65 which case you want to use the \ref XBT_LOG_EXTERNAL_CATEGORY macro to make
66 it visible in the current file), but each category may have only one
67 definition.
68       
69 Typically, there will be a Category for each module and sub-module, so you
70 can independently control logging for each module.
71
72 For a list of all existing categories, please refer to the \ref XBT_log_cats section.
73
74 \section log_pri Priority
75
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.
79           
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.
84
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.
90
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.
94         
95 Here is an example of the most basic type of macro. This is a logging
96 request with priority <i>warning</i>.
97
98 <code>CLOG5(MyCat, gras_log_priority_warning, "Values are: %d and '%s'", 5,
99 "oops");</code>
100
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. 
105       
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:
110
111 <code>CWARN4(MyCat, "Values are: %d and '%s'", 5, "oops");</code>
112
113 \subsection log_subcat Using a default category
114   
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:
118
119 <code>WARN3("Values are: %d and '%s'", 5, "oops");</code>
120
121 Only one default category can be created per file, though multiple
122 non-defaults can be created and used.
123
124 \section log_example Example
125
126 Here is a more complete example:
127
128 \verbatim
129 #include "xbt/log.h"
130
131 / * create a category and a default subcategory * /
132 XBT_LOG_NEW_CATEGORY(VSS);
133 XBT_LOG_NEW_DEFAULT_SUBCATEGORY(SA, VSS);
134
135 int main() {
136        / * Now set the parent's priority.  (the string would typcially be a runtime option) * /
137        xbt_log_control_set("SA.thresh=3");
138
139        / * This request is enabled, because WARNING &gt;= INFO. * /
140        CWARN2(VSS, "Low fuel level.");
141
142        / * This request is disabled, because DEBUG &lt; INFO. * /
143        CDEBUG2(VSS, "Starting search for nearest gas station.");
144
145        / * The default category SA inherits its priority from VSS. Thus,
146           the following request is enabled because INFO &gt;= INFO.  * /
147        INFO1("Located nearest gas station.");
148
149        / * This request is disabled, because DEBUG &lt; INFO. * /
150        DEBUG1("Exiting gas station search"); 
151 }
152 \endverbatim
153
154 \section log_conf Configuration
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.
159
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.
164
165 \section log_perf Performance
166
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.
170
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
177
178 Compiling with the \verbatim-DNLOG\endverbatim option disables all logging 
179 requests at compilation time while the \verbatim-DNDEBUG\endverbatim disables 
180 the requests of priority below INFO.
181  
182 \section log_app Appenders
183
184 Each category has an optional appender. An appender is a pointer to a
185 structure which starts with a pointer to a doAppend() function. DoAppend()
186 prints a message to a log.
187
188 When a category is passed a message by one of the logging macros, the
189 category performs the following actions:
190
191   - if the category has an appender, the message is passed to the
192     appender's doAppend() function,
193   - if 'willLogToParent' is true for the category, the message is passed
194     to the category's parent.
195     
196 By default, only the root category have an appender, and 'willLogToParent'
197 is true for any other category. This situation causes all messages to be
198 logged by the root category's appender.
199
200 The default appender function currently prints to stderr, and no other one
201 exist, even if more would be needed, like the one able to send the logs to a
202 remote dedicated server, or other ones offering different output formats.
203 This is on our TODO list for quite a while now, but your help would be
204 welcome here.
205
206 \section log_misc Misc and Caveats
207
208   - Do not use any of the macros that start with '_'.
209   - Log4J has a 'rolling file appender' which you can select with a run-time
210     option and specify the max file size. This would be a nice default for
211     non-kernel applications.
212   - Careful, category names are global variables.
213
214 */
215
216 /*
217 FAIRE DES ZOLIS LOGS
218 --------------------
219 Pour utiliser les logs, tu déjà faire, non ? Tu colle sur la ligne de
220 commande un ou plusieurs arguments de la forme
221   --gras-log="<réglage> [<reglage>+]" (ou sans " si t'as pas d'espace)
222 chaque réglage étant de la forme:
223   <canal>.thres=<priorité>
224 Les différents réglages sont lus de gauche à droite.
225 "root.thres=debug root.thres=critical" ferme tout, normalement.
226
227 */
228
229 typedef struct {
230   char *catname;
231   e_xbt_log_priority_t thresh;
232 } s_xbt_log_setting_t,*xbt_log_setting_t;
233
234 static xbt_dynar_t xbt_log_settings=NULL;
235 static void _free_setting(void *s) {
236   xbt_log_setting_t set=(xbt_log_setting_t)s;
237   if (set) {
238     free(set->catname);
239 /*    free(set); FIXME: uncommenting this leads to segfault when more than one chunk is passed as gras-log */
240   }
241 }
242
243 const char *xbt_log_priority_names[8] = {
244   "NONE",
245   "TRACE",
246   "DEBUG",
247   "VERBOSE",
248   "INFO",
249   "WARNING",
250   "ERROR",
251   "CRITICAL"
252 };
253
254 s_xbt_log_category_t _XBT_LOGV(XBT_LOG_ROOT_CAT) = {
255   0, 0, 0,
256   "root", xbt_log_priority_uninitialized, 0,
257   NULL, 0
258 };
259
260 XBT_LOG_NEW_CATEGORY(xbt,"All XBT categories (simgrid toolbox)");
261 XBT_LOG_NEW_CATEGORY(surf,"All SURF categories");
262 XBT_LOG_NEW_CATEGORY(msg,"All MSG categories");
263 XBT_LOG_NEW_DEFAULT_SUBCATEGORY(log,xbt,"Loggings from the logging mechanism itself");
264
265 void xbt_log_init(int *argc,char **argv) {
266   int i,j;
267   char *opt;
268
269   /* Set logs and init log submodule */
270   for (i=1; i<*argc; i++) {
271     if (!strncmp(argv[i],"--gras-log=",strlen("--gras-log=")) ||
272         !strncmp(argv[i],"--surf-log=",strlen("--surf-log=")) ||
273         !strncmp(argv[i],"--msg-log=",strlen("--msg-log=")) ||
274         !strncmp(argv[i],"--xbt-log=",strlen("--xbt-log="))) {
275       opt=strchr(argv[i],'=');
276       opt++;
277       xbt_log_control_set(opt);
278       DEBUG1("Did apply '%s' as log setting",opt);
279       /*remove this from argv*/
280       for (j=i+1; j<*argc; j++) {
281         argv[j-1] = argv[j];
282       } 
283       argv[j-1] = NULL;
284       (*argc)--;
285       i--; /* compensate effect of next loop incrementation */
286     }
287   }
288 }
289
290 void xbt_log_exit(void) {
291   VERB0("Exiting log");
292   xbt_dynar_free(&xbt_log_settings);
293   VERB0("Exited log");
294 }
295
296 static void _apply_control(xbt_log_category_t cat) {
297   int cursor;
298   xbt_log_setting_t setting=NULL;
299   int found = 0;
300
301   if (!xbt_log_settings)
302     return;
303
304   xbt_assert0(cat,"NULL category");
305   xbt_assert(cat->name);
306
307   xbt_dynar_foreach(xbt_log_settings,cursor,setting) {
308     xbt_assert0(setting,"Damnit, NULL cat in the list");
309     xbt_assert1(setting->catname,"NULL setting(=%p)->catname",(void*)setting);
310
311     if (!strcmp(setting->catname,cat->name)) {
312       found = 1;
313
314       xbt_log_threshold_set(cat, setting->thresh);
315       xbt_dynar_cursor_rm(xbt_log_settings,&cursor);
316
317       if (cat->threshold <= xbt_log_priority_debug) {
318         s_xbt_log_event_t _log_ev = 
319           {cat,xbt_log_priority_debug,__FILE__,_XBT_GNUC_FUNCTION,__LINE__};
320         _xbt_log_event_log(&_log_ev,
321                  "Apply settings for category '%s': set threshold to %s (=%d)",
322                  cat->name, 
323                  xbt_log_priority_names[cat->threshold], cat->threshold);
324       }
325     }
326   }
327   if (!found && cat->threshold <= xbt_log_priority_verbose) {
328     s_xbt_log_event_t _log_ev = 
329       {cat,xbt_log_priority_verbose,__FILE__,_XBT_GNUC_FUNCTION,__LINE__};
330     _xbt_log_event_log(&_log_ev,
331                         "Category '%s': inherited threshold = %s (=%d)",
332                         cat->name,
333                         xbt_log_priority_names[cat->threshold], cat->threshold);
334   }
335
336 }
337
338 void _xbt_log_event_log( xbt_log_event_t ev, const char *fmt, ...) {
339   xbt_log_category_t cat = ev->cat;
340   va_start(ev->ap, fmt);
341   while(1) {
342     xbt_log_appender_t appender = cat->appender;
343     if (appender != NULL) {
344       appender->do_append(appender, ev, fmt);
345     }
346     if (!cat->willLogToParent)
347       break;
348
349     cat = cat->parent;
350   } 
351   va_end(ev->ap);
352 }
353
354 static void _cat_init(xbt_log_category_t category) {
355   if (category == &_XBT_LOGV(XBT_LOG_ROOT_CAT)) {
356     category->threshold = xbt_log_priority_info;
357     category->appender = xbt_log_default_appender;
358   } else {
359     xbt_log_parent_set(category, category->parent);
360   }
361   _apply_control(category);
362 }
363
364 /*
365  * This gets called the first time a category is referenced and performs the
366  * initialization. 
367  * Also resets threshold to inherited!
368  */
369 int _xbt_log_cat_init(e_xbt_log_priority_t priority,
370                        xbt_log_category_t   category) {
371     
372   _cat_init(category);
373         
374   return priority >= category->threshold;
375 }
376
377 void xbt_log_parent_set(xbt_log_category_t cat,
378                          xbt_log_category_t parent) {
379
380   xbt_assert0(cat,"NULL category to be given a parent");
381   xbt_assert1(parent,"The parent category of %s is NULL",cat->name);
382
383   /* unlink from current parent */
384   if (cat->threshold != xbt_log_priority_uninitialized) {
385     xbt_log_category_t* cpp = &parent->firstChild;
386     while(*cpp != cat && *cpp != NULL) {
387       cpp = &(*cpp)->nextSibling;
388     }
389     xbt_assert(*cpp == cat);
390     *cpp = cat->nextSibling;
391   }
392
393   /* Set new parent */
394   cat->parent = parent;
395   cat->nextSibling = parent->firstChild;
396   parent->firstChild = cat;
397
398   /* Make sure parent is initialized */
399   if (parent->threshold == xbt_log_priority_uninitialized) {
400     _cat_init(parent);
401   }
402     
403   /* Reset priority */
404   cat->threshold = parent->threshold;
405   cat->isThreshInherited = 1;
406 } /* log_setParent */
407
408 static void _set_inherited_thresholds(xbt_log_category_t cat) {
409   xbt_log_category_t child = cat->firstChild;
410   for( ; child != NULL; child = child->nextSibling) {
411     if (child->isThreshInherited) {
412       if (cat != &_XBT_LOGV(log))
413         VERB3("Set category threshold of %s to %s (=%d)",
414               child->name,xbt_log_priority_names[cat->threshold],cat->threshold);
415       child->threshold = cat->threshold;
416       _set_inherited_thresholds(child);
417     }
418   }
419 }
420
421 void xbt_log_threshold_set(xbt_log_category_t   cat,
422                             e_xbt_log_priority_t threshold) {
423   cat->threshold = threshold;
424   cat->isThreshInherited = 0;
425   _set_inherited_thresholds(cat);
426 }
427
428 static void _xbt_log_parse_setting(const char*        control_string,
429                                     xbt_log_setting_t set) {
430   const char *name, *dot, *eq;
431   
432   set->catname=NULL;
433   if (!*control_string) 
434     return;
435   DEBUG1("Parse log setting '%s'",control_string);
436
437   control_string += strspn(control_string, " ");
438   name = control_string;
439   control_string += strcspn(control_string, ".= ");
440   dot = control_string;
441   control_string += strcspn(control_string, "= ");
442   eq = control_string;
443   control_string += strcspn(control_string, " ");
444
445   xbt_assert1(*dot == '.' && *eq == '=',
446                "Invalid control string '%s'",control_string);
447
448   if (!strncmp(dot + 1, "thresh", min(eq - dot - 1,strlen("thresh")))) {
449     int i;
450     char *neweq=xbt_strdup(eq+1);
451     char *p=neweq-1;
452     
453     while (*(++p) != '\0') {
454       if (*p >= 'a' && *p <= 'z') {
455         *p-='a'-'A';
456       }
457     }
458     
459     DEBUG1("New priority name = %s",neweq);
460     for (i=0; i<xbt_log_priority_infinite-1; i++) {
461       if (!strncmp(xbt_log_priority_names[i],neweq,p-eq)) {
462         DEBUG1("This is priority %d",i);
463         break;
464       }
465     }
466     if (i<xbt_log_priority_infinite-1) {
467       set->thresh=i;
468     } else {
469       xbt_assert1(FALSE,"Unknown priority name: %s",eq+1);
470     }
471     free(neweq);
472   } else {
473     char buff[512];
474     snprintf(buff,min(512,eq - dot - 1),"%s",dot+1);
475     xbt_assert1(FALSE,"Unknown setting of the log category: %s",buff);
476   }
477   set->catname=(char*)xbt_malloc(dot - name+1);
478     
479   strncpy(set->catname,name,dot-name);
480   set->catname[dot-name]='\0'; /* Just in case */
481   DEBUG1("This is for cat '%s'", set->catname);
482 }
483
484 static xbt_error_t _xbt_log_cat_searchsub(xbt_log_category_t cat,char *name,
485                                             /*OUT*/xbt_log_category_t*whereto) {
486   xbt_error_t errcode;
487   xbt_log_category_t child;
488   
489   if (!strcmp(cat->name,name)) {
490     *whereto=cat;
491     return no_error;
492   }
493   for(child=cat->firstChild ; child != NULL; child = child->nextSibling) {
494     errcode=_xbt_log_cat_searchsub(child,name,whereto);
495     if (errcode==no_error)
496       return no_error;
497   }
498   return mismatch_error;
499 }
500
501 static void _cleanup_double_spaces(char *s) {
502   char *p = s;
503   int   e = 0;
504   
505   while (1) {
506     if (!*p)
507       goto end;
508     
509     if (!isspace(*p))
510       break;
511     
512     p++;
513   }
514   
515   e = 1;
516   
517   do {
518     if (e)
519       *s++ = *p;
520     
521     if (!*++p)
522       goto end;
523     
524     if (e ^ !isspace(*p))
525       if ((e = !e))
526         *s++ = ' ';
527   } while (1);
528
529  end:
530   *s = '\0';
531 }
532
533 /**
534  * \ingroup XBT_log  
535  * \param control_string What to parse
536  *
537  * Typically passed a command-line argument. The string has the syntax:
538  *
539  *      ( [category] "." [keyword] "=" value (" ")... )...
540  *
541  * where [category] is one the category names and keyword is one of the
542  * following:
543  *
544  *      thresh          value is an integer priority level. Sets the category's
545  *                        threshold priority.
546  *
547  * \warning
548  * This routine may only be called once and that must be before any other
549  * logging command! Typically, this is done from main().
550  */
551 void xbt_log_control_set(const char* control_string) {
552   xbt_error_t errcode;
553   xbt_log_setting_t set;
554   char *cs;
555   char *p;
556   int done = 0;
557   
558   DEBUG1("Parse log settings '%s'",control_string);
559   if (control_string == NULL)
560     return;
561   if (xbt_log_settings == NULL)
562     xbt_log_settings = xbt_dynar_new(sizeof(xbt_log_setting_t),
563                                        _free_setting);
564
565   set = xbt_new(s_xbt_log_setting_t,1);
566   cs=xbt_strdup(control_string);
567
568   _cleanup_double_spaces(cs);
569
570   while (!done) {
571     xbt_log_category_t cat;
572     
573     p=strrchr(cs,' ');
574     if (p) {
575       *p='\0';
576       *p++;
577     } else {
578       p=cs;
579       done = 1;
580     }
581     _xbt_log_parse_setting(p,set);
582     
583     errcode = _xbt_log_cat_searchsub(&_XBT_LOGV(root),set->catname,&cat);
584     if (errcode == mismatch_error) {
585       DEBUG0("Store for further application");
586       DEBUG1("push %p to the settings",(void*)set);
587       xbt_dynar_push(xbt_log_settings,&set);
588       /* malloc in advance the next slot */
589       set = xbt_new(s_xbt_log_setting_t,1);
590     } else {
591       DEBUG0("Apply directly");
592       free(set->catname);
593       xbt_log_threshold_set(cat,set->thresh);
594     }
595   }
596   free(set);
597   free(cs);
598
599
600 void xbt_log_appender_set(xbt_log_category_t cat, xbt_log_appender_t app) {
601   cat->appender = app;
602 }
603