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       found = 1;
 166       opt=strchr(argv[i],'=');
 167       opt++;
 168       xbt_log_control_set(opt);
 169       DEBUG1("Did apply '%s' as log setting",opt);
 170       /*remove this from argv*/
 171       for (j=i+1; j<*argc; j++) {
 172         argv[j-1] = argv[j];
 173       }
 174       argv[j-1] = NULL;
 175       (*argc)--;
 176       i--; /* compensate effect of next loop incrementation */
 177     }
 178   }
 179   if (!found && defaultlog) {
 180      xbt_log_control_set(defaultlog);
 181   }
 182 }
 183
 184 void xbt_log_exit(void) {
 185   VERB0("Exiting log");
 186   xbt_dynar_free(&xbt_log_settings);
 187   VERB0("Exited log");
 188 }
 189
 190 static void _apply_control(xbt_log_category_t cat) {
 191   int cursor;
 192   xbt_log_setting_t setting=NULL;
 193   int found = 0;
 194
 195   if (!xbt_log_settings)
 196     return;
 197
 198   xbt_assert0(cat,"NULL category");
 199   xbt_assert(cat->name);
 200
 201   xbt_dynar_foreach(xbt_log_settings,cursor,setting) {
 202     xbt_assert0(setting,"Damnit, NULL cat in the list");
 203     xbt_assert1(setting->catname,"NULL setting(=%p)->catname",(void*)setting);
 204
 205     if (!strcmp(setting->catname,cat->name)) {
 206       found = 1;
 207
 208       xbt_log_threshold_set(cat, setting->thresh);
 209       xbt_dynar_cursor_rm(xbt_log_settings,&cursor);
 210
 211       if (cat->threshold <= xbt_log_priority_verbose) {
 212         s_xbt_log_event_t _log_ev =
 213           {cat,xbt_log_priority_verbose,__FILE__,_XBT_GNUC_FUNCTION,__LINE__};
 214         _xbt_log_event_log(&_log_ev,
 215                  "Apply settings for category '%s': set threshold to %s (=%d)",
 216                  cat->name,
 217                  xbt_log_priority_names[cat->threshold], cat->threshold);
 218       }
 219     }
 220   }
 221   if (!found && cat->threshold <= xbt_log_priority_verbose) {
 222     s_xbt_log_event_t _log_ev =
 223       {cat,xbt_log_priority_verbose,__FILE__,_XBT_GNUC_FUNCTION,__LINE__};
 224     _xbt_log_event_log(&_log_ev,
 225                         "Category '%s': inherited threshold = %s (=%d)",
 226                         cat->name,
 227                         xbt_log_priority_names[cat->threshold], cat->threshold);
 228   }
 229
 230 }
 231
 232 void _xbt_log_event_log( xbt_log_event_t ev, const char *fmt, ...) {
 233   xbt_log_category_t cat = ev->cat;
 234   va_start(ev->ap, fmt);
 235   while(1) {
 236     xbt_log_appender_t appender = cat->appender;
 237     if (appender != NULL) {
 238       appender->do_append(appender, ev, fmt);
 239     }
 240     if (!cat->willLogToParent)
 241       break;
 242
 243     cat = cat->parent;
 244   }
 245   va_end(ev->ap);
 246 }
 247
 248 static void _cat_init(xbt_log_category_t category) {
 249   if (category == &_XBT_LOGV(XBT_LOG_ROOT_CAT)) {
 250     category->threshold = xbt_log_priority_info;
 251     category->appender = xbt_log_default_appender;
 252   } else {
 253     xbt_log_parent_set(category, category->parent);
 254   }
 255   _apply_control(category);
 256 }
 257
 258 /*
 259  * This gets called the first time a category is referenced and performs the
 260  * initialization.
 261  * Also resets threshold to inherited!
 262  */
 263 int _xbt_log_cat_init(e_xbt_log_priority_t priority,
 264                        xbt_log_category_t   category) {
 265
 266   _cat_init(category);
 267
 268   return priority >= category->threshold;
 269 }
 270
 271 void xbt_log_parent_set(xbt_log_category_t cat,
 272                          xbt_log_category_t parent) {
 273
 274   xbt_assert0(cat,"NULL category to be given a parent");
 275   xbt_assert1(parent,"The parent category of %s is NULL",cat->name);
 276
 277   /* unlink from current parent */
 278   if (cat->threshold != xbt_log_priority_uninitialized) {
 279     xbt_log_category_t* cpp = &parent->firstChild;
 280     while(*cpp != cat && *cpp != NULL) {
 281       cpp = &(*cpp)->nextSibling;
 282     }
 283     xbt_assert(*cpp == cat);
 284     *cpp = cat->nextSibling;
 285   }
 286
 287   /* Set new parent */
 288   cat->parent = parent;
 289   cat->nextSibling = parent->firstChild;
 290   parent->firstChild = cat;
 291
 292   /* Make sure parent is initialized */
 293   if (parent->threshold == xbt_log_priority_uninitialized) {
 294     _cat_init(parent);
 295   }
 296
 297   /* Reset priority */
 298   cat->threshold = parent->threshold;
 299   cat->isThreshInherited = 1;
 300 } /* log_setParent */
 301
 302 static void _set_inherited_thresholds(xbt_log_category_t cat) {
 303   xbt_log_category_t child = cat->firstChild;
 304   for( ; child != NULL; child = child->nextSibling) {
 305     if (child->isThreshInherited) {
 306       if (cat != &_XBT_LOGV(log))
 307         VERB3("Set category threshold of %s to %s (=%d)",
 308               child->name,xbt_log_priority_names[cat->threshold],cat->threshold);
 309       child->threshold = cat->threshold;
 310       _set_inherited_thresholds(child);
 311     }
 312   }
 313 }
 314
 315 void xbt_log_threshold_set(xbt_log_category_t   cat,
 316                             e_xbt_log_priority_t threshold) {
 317   cat->threshold = threshold;
 318   cat->isThreshInherited = 0;
 319   _set_inherited_thresholds(cat);
 320 }
 321
 322 static void _xbt_log_parse_setting(const char*        control_string,
 323                                     xbt_log_setting_t set) {
 324   const char *name, *dot, *eq;
 325
 326   set->catname=NULL;
 327   if (!*control_string)
 328     return;
 329   DEBUG1("Parse log setting '%s'",control_string);
 330
 331   control_string += strspn(control_string, " ");
 332   name = control_string;
 333   control_string += strcspn(control_string, ".= ");
 334   dot = control_string;
 335   control_string += strcspn(control_string, "= ");
 336   eq = control_string;
 337   control_string += strcspn(control_string, " ");
 338
 339   xbt_assert1(*dot == '.' && *eq == '=',
 340                "Invalid control string '%s'",control_string);
 341
 342   if (!strncmp(dot + 1, "thresh", min(eq - dot - 1,strlen("thresh")))) {
 343     int i;
 344     char *neweq=xbt_strdup(eq+1);
 345     char *p=neweq-1;
 346
 347     while (*(++p) != '\0') {
 348       if (*p >= 'a' && *p <= 'z') {
 349         *p-='a'-'A';
 350       }
 351     }
 352
 353     DEBUG1("New priority name = %s",neweq);
 354     for (i=0; i<xbt_log_priority_infinite-1; i++) {
 355       if (!strncmp(xbt_log_priority_names[i],neweq,p-eq)) {
 356         DEBUG1("This is priority %d",i);
 357         break;
 358       }
 359     }
 360     if (i<xbt_log_priority_infinite-1) {
 361       set->thresh=i;
 362     } else {
 363       xbt_assert1(FALSE,"Unknown priority name: %s",eq+1);
 364     }
 365     xbt_free(neweq);
 366   } else {
 367     char buff[512];
 368     snprintf(buff,min(512,eq - dot - 1),"%s",dot+1);
 369     xbt_assert1(FALSE,"Unknown setting of the log category: %s",buff);
 370   }
 371   set->catname=(char*)xbt_malloc(dot - name+1);
 372
 373   strncpy(set->catname,name,dot-name);
 374   set->catname[dot-name]='\0'; /* Just in case */
 375   DEBUG1("This is for cat '%s'", set->catname);
 376 }
 377
 378 static xbt_error_t _xbt_log_cat_searchsub(xbt_log_category_t cat,char *name,
 379                                             /*OUT*/xbt_log_category_t*whereto) {
 380   xbt_error_t errcode;
 381   xbt_log_category_t child;
 382
 383   if (!strcmp(cat->name,name)) {
 384     *whereto=cat;
 385     return no_error;
 386   }
 387   for(child=cat->firstChild ; child != NULL; child = child->nextSibling) {
 388     errcode=_xbt_log_cat_searchsub(child,name,whereto);
 389     if (errcode==no_error)
 390       return no_error;
 391   }
 392   return mismatch_error;
 393 }
 394
 395 static void _cleanup_double_spaces(char *s) {
 396   char *p = s;
 397   int   e = 0;
 398
 399   while (1) {
 400     if (!*p)
 401       goto end;
 402
 403     if (!isspace(*p))
 404       break;
 405
 406     p++;
 407   }
 408
 409   e = 1;
 410
 411   do {
 412     if (e)
 413       *s++ = *p;
 414
 415     if (!*++p)
 416       goto end;
 417
 418     if (e ^ !isspace(*p))
 419       if ((e = !e))
 420         *s++ = ' ';
 421   } while (1);
 422
 423  end:
 424   *s = '\0';
 425 }
 426
 427 /**
 428  * \ingroup XBT_log
 429  * \param control_string What to parse
 430  *
 431  * Typically passed a command-line argument. The string has the syntax:
 432  *
 433  *      ( [category] "." [keyword] "=" value (" ")... )...
 434  *
 435  * where [category] is one the category names and keyword is one of the
 436  * following:
 437  *
 438  *      thresh          value is an integer priority level. Sets the category's
 439  *                        threshold priority.
 440  *
 441  * \warning
 442  * This routine may only be called once and that must be before any other
 443  * logging command! Typically, this is done from main().
 444  */
 445 void xbt_log_control_set(const char* control_string) {
 446   xbt_error_t errcode;
 447   xbt_log_setting_t set;
 448   char *cs;
 449   char *p;
 450   int done = 0;
 451
 452   DEBUG1("Parse log settings '%s'",control_string);
 453   if (control_string == NULL)
 454     return;
 455   if (xbt_log_settings == NULL)
 456     xbt_log_settings = xbt_dynar_new(sizeof(xbt_log_setting_t),
 457                                        _free_setting);
 458
 459   set = xbt_new(s_xbt_log_setting_t,1);
 460   cs=xbt_strdup(control_string);
 461
 462   _cleanup_double_spaces(cs);
 463
 464   while (!done) {
 465     xbt_log_category_t cat;
 466
 467     p=strrchr(cs,' ');
 468     if (p) {
 469       *p='\0';
 470       *p++;
 471     } else {
 472       p=cs;
 473       done = 1;
 474     }
 475     _xbt_log_parse_setting(p,set);
 476
 477     errcode = _xbt_log_cat_searchsub(&_XBT_LOGV(root),set->catname,&cat);
 478     if (errcode == mismatch_error) {
 479       DEBUG0("Store for further application");
 480       DEBUG1("push %p to the settings",(void*)set);
 481       xbt_dynar_push(xbt_log_settings,&set);
 482       /* malloc in advance the next slot */
 483       set = xbt_new(s_xbt_log_setting_t,1);
 484     } else {
 485       DEBUG0("Apply directly");
 486       xbt_free(set->catname);
 487       xbt_log_threshold_set(cat,set->thresh);
 488     }
 489   }
 490   xbt_free(set);
 491   xbt_free(cs);
 492 }
 493
 494 void xbt_log_appender_set(xbt_log_category_t cat, xbt_log_appender_t app) {
 495   cat->appender = app;
 496 }
 497