Logo AND Algorithmique Numérique Distribuée

Public GIT Repository
More work to move gras->sg
[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
22 /*
23 FAIRE DES ZOLIS LOGS
24 --------------------
25 Dans gras, tu ne te contente pas d'écrire des choses à l'écran, mais tu
26 écris sur un sujet particulier (notion de canal) des choses d'une gravité
27 particulière. Il y a 7 niveaux de gravité.
28  trace: tracer les entrées dans une fonction, retour de fonction
29         (famille de macros XBT_IN/XBT_OUT)
30  debug: pour t'aider à mettre au point le module, potentiellement tres bavard
31  verbose: quelques infos succintes sur les internals du module
32  info: niveau normal, ton de la conversation
33  warning: problème potentiel, mais auquel on a su faire face
34  error: problème qui t'as empêché de faire ton job
35  critical: juste avant de mourir
36
37 Quand on compile avec -DNDEBUG (par défaut dans le paquet Debian), tout ce
38 qui est '>= verbose' est supprimé au moment de la compilation. Retiré du
39 binaire, killé.
40
41 Ensuite, tu écris dans un canal particulier. Tous les canaux sont rangés en
42 arbre. Il faudrait faire un ptit script qui fouille les sources à la
43 recherche des macros XBT_LOG_NEW_* utilisées pour créer des canaux. Le
44 dernier argument de ces macros est ignoré dans le source. Il est destiné à
45 être la documentation de la chose en une ligne. En gros, ca fait:
46 root
47  +--xbt
48  |   +--config
49  |   +--dict
50  |   |   +--dict_cursor
51  |   |   +--dict_elm
52  |   |   ...
53  |   +--dynar
54  |   +--set
55  |   +--log
56  |   +--module
57  +--gras
58      +--datadesc
59      |   +--ddt_cbps
60      |   +--ddt_convert
61      |   +--ddt_exchange
62      |   +--ddt_parse
63      |       +--lexer
64      +--msg
65      +--transport
66          +--raw_trp (Je devrais tuer ce module, un jour)
67          +--trp_buf
68          +--trp_sg
69          +--trp_file
70          +--trp_tcp
71          
72 Et ensuite les utilisateurs peuvent choisir le niveau de gravité qui les
73 interresse sur tel ou tel sujet.
74
75 Toute la mécanique de logging repose sur des variables statiques dont le nom
76 dépend du nom du canal.
77  => attention aux conflits de nom de canal
78  => il faut une macro XBT_LOG dans chaque fichier où tu fais des logs.
79  
80 XBT_LOG_NEW_CATEGORY: nouveau canal sous "root". Rare, donc.
81 XBT_LOG_NEW_SUBCATEGORY: nouveau canal dont on précise le père.
82 XBT_LOG_DEFAULT_CATEGORY: indique quel est le canal par défaut dans ce fichier
83 XBT_LOG_NEW_DEFAULT_CATEGORY: Crèe un canal et l'utilise par défaut
84 XBT_LOG_NEW_DEFAULT_SUBCATEGORY: devine
85 XBT_LOG_EXTERNAL_CATEGORY: quand tu veux utiliser par défaut un canal créé
86                            dans un autre fichier.
87
88 Une fois que ton canal est créé, tu l'utilise avec les macros LOG, DEBUG,
89 VERB, WARN, ERROR et CRITICAL. Il faut que tu donne le nombre d'arguments
90 après le nom de macro. Exemple: LOG2("My name is %s %s","Martin","Quinson")
91 Si tu veux préciser explicitement le canal où écrire, ajoute un C devant le
92 nom de la macro. Exemple: CCRITICAL0(module, "Cannot initialize GRAS")
93
94 Toutes ces macros (enfin, ce en quoi elles se réécrivent) vérifient leurs
95 arguments comme printf le fait lorsqu'on compile avec gcc. 
96 LOG1("name: %d","toto"); donne un warning, et donc une erreur en mode
97 mainteneur.
98
99 Enfin, tu peux tester si un canal est ouvert à une priorité donnée (pour
100 préparer plus de débug, par exemple. Dans le parseur, je fais du pretty
101 printing sur ce qu'il faut parser dans ce cas).
102 XBT_LOG_ISENABLED(catName, priority) Le second argument doit être une valeur
103 de e_xbt_log_priority_t (log.h). Par exemple: xbt_log_priority_verbose
104
105 Voila sur comment mettre des logs dans ton code. N'hesite pas à faire pleins
106 de canaux différents pour des aspects différents de ton code. En
107 particulier, dans les dict, j'ai un canal pour l'ajout, le retrait, le
108 netoyage du code après suppression et ainsi de suite. De cette façon, je
109 peux choisir qui m'interresse.
110
111
112 Pour utiliser les logs, tu déjà faire, non ? Tu colle sur la ligne de
113 commande un ou plusieurs arguments de la forme
114   --gras-log="<réglage> [<reglage>+]" (ou sans " si t'as pas d'espace)
115 chaque réglage étant de la forme:
116   <canal>.thres=<priorité>
117 Les différents réglages sont lus de gauche à droite.
118 "root.thres=debug root.thres=critical" ferme tout, normalement.
119
120 */
121
122 typedef struct {
123   char *catname;
124   e_xbt_log_priority_t thresh;
125 } s_xbt_log_setting_t,*xbt_log_setting_t;
126
127 static xbt_dynar_t xbt_log_settings=NULL;
128 static void _free_setting(void *s) {
129   xbt_log_setting_t set=(xbt_log_setting_t)s;
130   if (set) {
131     xbt_free(set->catname);
132 /*    xbt_free(set); FIXME: uncommenting this leads to segfault when more than one chunk is passed as gras-log */
133   }
134 }
135
136 const char *xbt_log_priority_names[8] = {
137   "NONE",
138   "TRACE",
139   "DEBUG",
140   "VERBOSE",
141   "INFO",
142   "WARNING",
143   "ERROR",
144   "CRITICAL"
145 };
146
147 s_xbt_log_category_t _XBT_LOGV(XBT_LOG_ROOT_CAT) = {
148   0, 0, 0,
149   "root", xbt_log_priority_uninitialized, 0,
150   NULL, 0
151 };
152
153 XBT_LOG_NEW_SUBCATEGORY(xbt,XBT_LOG_ROOT_CAT,"All XBT categories (simgrid toolbox)");
154 XBT_LOG_NEW_SUBCATEGORY(surf,XBT_LOG_ROOT_CAT,"All SURF categories");
155 XBT_LOG_NEW_DEFAULT_SUBCATEGORY(log,xbt,"Loggings from the logging mecanism itself");
156
157 void xbt_log_init(int *argc,char **argv, const char *defaultlog) {
158   int i,j;
159   char *opt;
160   int found=0;
161
162   /** Set logs and init log submodule */
163   for (i=1; i<*argc; i++) {
164     if (!strncmp(argv[i],"--gras-log=",strlen("--gras-log=")) ||
165         !strncmp(argv[i],"--surf-log=",strlen("--surf-log=")) ||
166         !strncmp(argv[i],"--msg-log=",strlen("--msg-log=")) ||
167         !strncmp(argv[i],"--xbt-log=",strlen("--xbt-log="))) {
168       found = 1;
169       opt=strchr(argv[i],'=');
170       opt++;
171       xbt_log_control_set(opt);
172       DEBUG1("Did apply '%s' as log setting",opt);
173       /*remove this from argv*/
174       for (j=i+1; j<*argc; j++) {
175         argv[j-1] = argv[j];
176       } 
177       argv[j-1] = NULL;
178       (*argc)--;
179       i--; /* compensate effect of next loop incrementation */
180     }
181   }
182   if (!found && defaultlog) {
183      xbt_log_control_set(defaultlog);
184   }
185 }
186
187 void xbt_log_exit(void) {
188   VERB0("Exiting log");
189   xbt_dynar_free(&xbt_log_settings);
190   VERB0("Exited log");
191 }
192
193 static void _apply_control(xbt_log_category_t cat) {
194   int cursor;
195   xbt_log_setting_t setting=NULL;
196   int found = 0;
197
198   if (!xbt_log_settings)
199     return;
200
201   xbt_assert0(cat,"NULL category");
202   xbt_assert(cat->name);
203
204   xbt_dynar_foreach(xbt_log_settings,cursor,setting) {
205     xbt_assert0(setting,"Damnit, NULL cat in the list");
206     xbt_assert1(setting->catname,"NULL setting(=%p)->catname",(void*)setting);
207
208     if (!strcmp(setting->catname,cat->name)) {
209       found = 1;
210
211       xbt_log_threshold_set(cat, setting->thresh);
212       xbt_dynar_cursor_rm(xbt_log_settings,&cursor);
213
214       if (cat->threshold <= xbt_log_priority_verbose) {
215         s_xbt_log_event_t _log_ev = 
216           {cat,xbt_log_priority_verbose,__FILE__,_XBT_GNUC_FUNCTION,__LINE__};
217         _xbt_log_event_log(&_log_ev,
218                  "Apply settings for category '%s': set threshold to %s (=%d)",
219                  cat->name, 
220                  xbt_log_priority_names[cat->threshold], cat->threshold);
221       }
222     }
223   }
224   if (!found && cat->threshold <= xbt_log_priority_verbose) {
225     s_xbt_log_event_t _log_ev = 
226       {cat,xbt_log_priority_verbose,__FILE__,_XBT_GNUC_FUNCTION,__LINE__};
227     _xbt_log_event_log(&_log_ev,
228                         "Category '%s': inherited threshold = %s (=%d)",
229                         cat->name,
230                         xbt_log_priority_names[cat->threshold], cat->threshold);
231   }
232
233 }
234
235 void _xbt_log_event_log( xbt_log_event_t ev, const char *fmt, ...) {
236   xbt_log_category_t cat = ev->cat;
237   va_start(ev->ap, fmt);
238   while(1) {
239     xbt_log_appender_t appender = cat->appender;
240     if (appender != NULL) {
241       appender->do_append(appender, ev, fmt);
242     }
243     if (!cat->willLogToParent)
244       break;
245
246     cat = cat->parent;
247   } 
248   va_end(ev->ap);
249 }
250
251 static void _cat_init(xbt_log_category_t category) {
252   if (category == &_XBT_LOGV(XBT_LOG_ROOT_CAT)) {
253     category->threshold = xbt_log_priority_info;
254     category->appender = xbt_log_default_appender;
255   } else {
256     xbt_log_parent_set(category, category->parent);
257   }
258   _apply_control(category);
259 }
260
261 /*
262  * This gets called the first time a category is referenced and performs the
263  * initialization. 
264  * Also resets threshold to inherited!
265  */
266 int _xbt_log_cat_init(e_xbt_log_priority_t priority,
267                        xbt_log_category_t   category) {
268     
269   _cat_init(category);
270         
271   return priority >= category->threshold;
272 }
273
274 void xbt_log_parent_set(xbt_log_category_t cat,
275                          xbt_log_category_t parent) {
276
277   xbt_assert0(cat,"NULL category to be given a parent");
278   xbt_assert1(parent,"The parent category of %s is NULL",cat->name);
279
280   /* unlink from current parent */
281   if (cat->threshold != xbt_log_priority_uninitialized) {
282     xbt_log_category_t* cpp = &parent->firstChild;
283     while(*cpp != cat && *cpp != NULL) {
284       cpp = &(*cpp)->nextSibling;
285     }
286     xbt_assert(*cpp == cat);
287     *cpp = cat->nextSibling;
288   }
289
290   /* Set new parent */
291   cat->parent = parent;
292   cat->nextSibling = parent->firstChild;
293   parent->firstChild = cat;
294
295   /* Make sure parent is initialized */
296   if (parent->threshold == xbt_log_priority_uninitialized) {
297     _cat_init(parent);
298   }
299     
300   /* Reset priority */
301   cat->threshold = parent->threshold;
302   cat->isThreshInherited = 1;
303 } /* log_setParent */
304
305 static void _set_inherited_thresholds(xbt_log_category_t cat) {
306   xbt_log_category_t child = cat->firstChild;
307   for( ; child != NULL; child = child->nextSibling) {
308     if (child->isThreshInherited) {
309       if (cat != &_XBT_LOGV(log))
310         VERB3("Set category threshold of %s to %s (=%d)",
311               child->name,xbt_log_priority_names[cat->threshold],cat->threshold);
312       child->threshold = cat->threshold;
313       _set_inherited_thresholds(child);
314     }
315   }
316 }
317
318 void xbt_log_threshold_set(xbt_log_category_t   cat,
319                             e_xbt_log_priority_t threshold) {
320   cat->threshold = threshold;
321   cat->isThreshInherited = 0;
322   _set_inherited_thresholds(cat);
323 }
324
325 static void _xbt_log_parse_setting(const char*        control_string,
326                                     xbt_log_setting_t set) {
327   const char *name, *dot, *eq;
328   
329   set->catname=NULL;
330   if (!*control_string) 
331     return;
332   DEBUG1("Parse log setting '%s'",control_string);
333
334   control_string += strspn(control_string, " ");
335   name = control_string;
336   control_string += strcspn(control_string, ".= ");
337   dot = control_string;
338   control_string += strcspn(control_string, "= ");
339   eq = control_string;
340   control_string += strcspn(control_string, " ");
341
342   xbt_assert1(*dot == '.' && *eq == '=',
343                "Invalid control string '%s'",control_string);
344
345   if (!strncmp(dot + 1, "thresh", min(eq - dot - 1,strlen("thresh")))) {
346     int i;
347     char *neweq=xbt_strdup(eq+1);
348     char *p=neweq-1;
349     
350     while (*(++p) != '\0') {
351       if (*p >= 'a' && *p <= 'z') {
352         *p-='a'-'A';
353       }
354     }
355     
356     DEBUG1("New priority name = %s",neweq);
357     for (i=0; i<xbt_log_priority_infinite-1; i++) {
358       if (!strncmp(xbt_log_priority_names[i],neweq,p-eq)) {
359         DEBUG1("This is priority %d",i);
360         break;
361       }
362     }
363     if (i<xbt_log_priority_infinite-1) {
364       set->thresh=i;
365     } else {
366       xbt_assert1(FALSE,"Unknown priority name: %s",eq+1);
367     }
368     xbt_free(neweq);
369   } else {
370     char buff[512];
371     snprintf(buff,min(512,eq - dot - 1),"%s",dot+1);
372     xbt_assert1(FALSE,"Unknown setting of the log category: %s",buff);
373   }
374   set->catname=(char*)xbt_malloc(dot - name+1);
375     
376   strncpy(set->catname,name,dot-name);
377   set->catname[dot-name]='\0'; /* Just in case */
378   DEBUG1("This is for cat '%s'", set->catname);
379 }
380
381 static xbt_error_t _xbt_log_cat_searchsub(xbt_log_category_t cat,char *name,
382                                             /*OUT*/xbt_log_category_t*whereto) {
383   xbt_error_t errcode;
384   xbt_log_category_t child;
385   
386   if (!strcmp(cat->name,name)) {
387     *whereto=cat;
388     return no_error;
389   }
390   for(child=cat->firstChild ; child != NULL; child = child->nextSibling) {
391     errcode=_xbt_log_cat_searchsub(child,name,whereto);
392     if (errcode==no_error)
393       return no_error;
394   }
395   return mismatch_error;
396 }
397
398 static void _cleanup_double_spaces(char *s) {
399   char *p = s;
400   int   e = 0;
401   
402   while (1) {
403     if (!*p)
404       goto end;
405     
406     if (!isspace(*p))
407       break;
408     
409     p++;
410   }
411   
412   e = 1;
413   
414   do {
415     if (e)
416       *s++ = *p;
417     
418     if (!*++p)
419       goto end;
420     
421     if (e ^ !isspace(*p))
422       if ((e = !e))
423         *s++ = ' ';
424   } while (1);
425
426  end:
427   *s = '\0';
428 }
429
430 /**
431  * \ingroup XBT_log  
432  * \param control_string What to parse
433  *
434  * Typically passed a command-line argument. The string has the syntax:
435  *
436  *      ( [category] "." [keyword] "=" value (" ")... )...
437  *
438  * where [category] is one the category names and keyword is one of the
439  * following:
440  *
441  *      thresh          value is an integer priority level. Sets the category's
442  *                        threshold priority.
443  *
444  * \warning
445  * This routine may only be called once and that must be before any other
446  * logging command! Typically, this is done from main().
447  */
448 void xbt_log_control_set(const char* control_string) {
449   xbt_error_t errcode;
450   xbt_log_setting_t set;
451   char *cs;
452   char *p;
453   int done = 0;
454   
455   DEBUG1("Parse log settings '%s'",control_string);
456   if (control_string == NULL)
457     return;
458   if (xbt_log_settings == NULL)
459     xbt_log_settings = xbt_dynar_new(sizeof(xbt_log_setting_t),
460                                        _free_setting);
461
462   set = xbt_new(s_xbt_log_setting_t,1);
463   cs=xbt_strdup(control_string);
464
465   _cleanup_double_spaces(cs);
466
467   while (!done) {
468     xbt_log_category_t cat;
469     
470     p=strrchr(cs,' ');
471     if (p) {
472       *p='\0';
473       *p++;
474     } else {
475       p=cs;
476       done = 1;
477     }
478     _xbt_log_parse_setting(p,set);
479     
480     errcode = _xbt_log_cat_searchsub(&_XBT_LOGV(root),set->catname,&cat);
481     if (errcode == mismatch_error) {
482       DEBUG0("Store for further application");
483       DEBUG1("push %p to the settings",(void*)set);
484       xbt_dynar_push(xbt_log_settings,&set);
485       /* malloc in advance the next slot */
486       set = xbt_new(s_xbt_log_setting_t,1);
487     } else {
488       DEBUG0("Apply directly");
489       xbt_free(set->catname);
490       xbt_log_threshold_set(cat,set->thresh);
491     }
492   }
493   xbt_free(set);
494   xbt_free(cs);
495
496
497 void xbt_log_appender_set(xbt_log_category_t cat, xbt_log_appender_t app) {
498   cat->appender = app;
499 }
500