src/xbt/xbt_log_layout_format.c

   1 /* layout_simple - a dumb log layout                                        */
   2
   3 /* Copyright (c) 2007, 2008, 2009, 2010. The SimGrid Team.
   4  * All rights reserved.                                                     */
   5
   6 /* This program is free software; you can redistribute it and/or modify it
   7  * under the terms of the license (GNU LGPL) which comes with this package. */
   8
   9 #include "portable.h"           /* execinfo when available */
  10 #include "xbt/sysdep.h"
  11 #include "xbt/strbuff.h"
  12 #include "xbt/log_private.h"
  13 #include "gras/virtu.h"         /* gras_os_myname (KILLME) */
  14 #include "xbt/synchro.h"        /* xbt_thread_self_name */
  15 #include <stdio.h>
  16
  17 extern const char *xbt_log_priority_names[8];
  18
  19 static double format_begin_of_time = -1;
  20
  21 #define append1(fmt,fmt2,elm)                                         \
  22   do {                                                               \
  23     if (precision == -1) {                                        \
  24       xbt_strbuff_append(buff, tmp=bprintf(fmt,elm));            \
  25       free(tmp);                                                 \
  26     } else {                                                      \
  27       xbt_strbuff_append(buff, tmp=bprintf(fmt2,precision,elm)); \
  28       free(tmp);                                                 \
  29       precision = -1;                                            \
  30     }                                                         \
  31   } while (0)
  32 #define append2(fmt,elm,elm2)                                         \
  33   do {                                                               \
  34     xbt_strbuff_append(buff, tmp=bprintf(fmt,elm,elm2));          \
  35     free(tmp);                                                    \
  36     precision = -1;                                               \
  37   } while (0)
  38
  39 #define ERRMSG "Unknown %%%c sequence in layout format (%s).\nKnown sequences:\n"                       \
  40   "  what:        %%m: user message  %%c: log category  %%p: log priority\n"                      \
  41   "  where:\n"                                                                                    \
  42   "    source:    %%F: file          %%L: line          %%M: function  %%l: location (%%F:%%L)\n" \
  43   "    runtime:   %%h: hostname      %%t: thread        %%P: process   %%i: PID\n"                \
  44   "    backtrace: %%b: full          %%B: short\n"                                                \
  45   "  when:        %%d: date          %%r: app. age\n"                                             \
  46   "  other:       %%%%: %%             %%n: new line      %%e: plain space\n"
  47
  48
  49 static void xbt_log_layout_format_dynamic(xbt_log_layout_t l,
  50                                           xbt_log_event_t ev,
  51                                           const char *fmt,
  52                                           xbt_log_appender_t app)
  53 {
  54   xbt_strbuff_t buff = xbt_strbuff_new();
  55   int precision = -1;
  56   char *q = l->data;
  57   char *tmp;
  58   char *tmp2;
  59   int vres;                     /* shut gcc up, but ignored */
  60
  61   while (*q != '\0') {
  62     if (*q == '%') {
  63       q++;
  64     handle_modifier:
  65       switch (*q) {
  66       case '\0':
  67         fprintf(stderr, "Layout format (%s) ending with %%\n",
  68                 (char *) l->data);
  69         abort();
  70       case '%':
  71         xbt_strbuff_append(buff, "%");
  72         break;
  73       case 'n':                /* platform-dependant line separator (LOG4J compliant) */
  74         xbt_strbuff_append(buff, "\n");
  75         break;
  76       case 'e':                /* plain space (SimGrid extension) */
  77         xbt_strbuff_append(buff, " ");
  78         break;
  79
  80       case '.':                /* precision specifyier */
  81         q++;
  82         q += sscanf(q, "%d", &precision);
  83         goto handle_modifier;
  84
  85       case 'c':                /* category name; LOG4J compliant
  86                                    should accept a precision postfix to show the hierarchy */
  87         append1("%s", "%.*s", ev->cat->name);
  88         break;
  89       case 'p':                /* priority name; LOG4J compliant */
  90         append1("%s", "%.*s", xbt_log_priority_names[ev->priority]);
  91         break;
  92
  93       case 'h':                /* host name; SimGrid extension */
  94         append1("%s", "%.*s", gras_os_myname());
  95         break;
  96       case 't':                /* thread name; LOG4J compliant */
  97         append1("%s", "%.*s", xbt_thread_self_name());
  98         break;
  99       case 'P':                /* process name; SimGrid extension */
 100         append1("%s", "%.*s", xbt_procname());
 101         break;
 102       case 'i':                /* process PID name; SimGrid extension */
 103         append1("%d", "%.*d", (*xbt_getpid) ());
 104         break;
 105
 106       case 'F':                /* file name; LOG4J compliant */
 107         append1("%s", "%.*s", ev->fileName);
 108         break;
 109       case 'l':                /* location; LOG4J compliant */
 110         append2("%s:%d", ev->fileName, ev->lineNum);
 111         precision = -1;         /* Ignored */
 112         break;
 113       case 'L':                /* line number; LOG4J compliant */
 114         append1("%d", "%.*d", ev->lineNum);
 115         break;
 116       case 'M':                /* method (ie, function) name; LOG4J compliant */
 117         append1("%s", "%.*s", ev->functionName);
 118         break;
 119       case 'b':                /* backtrace; called %throwable in LOG4J */
 120       case 'B':                /* short backtrace; called %throwable{short} in LOG4J */
 121 #if defined(HAVE_EXECINFO_H) && defined(HAVE_POPEN) && defined(ADDR2LINE)
 122         {
 123           xbt_ex_t e;
 124           int i;
 125
 126           e.used = backtrace((void **) e.bt, XBT_BACKTRACE_SIZE);
 127           e.bt_strings = NULL;
 128           e.msg = NULL;
 129           e.remote = 0;
 130           xbt_backtrace_current(&e);
 131           if (*q == 'B') {
 132             append1("%s", "%.*s", e.bt_strings[2] + 8);
 133           } else {
 134             for (i = 2; i < e.used; i++)
 135               append1("%s\n", "%.*s\n", e.bt_strings[i] + 8);
 136           }
 137
 138           xbt_ex_free(e);
 139         }
 140 #else
 141         append1("%s", "%.*s", "(no backtrace on this arch)");
 142 #endif
 143         break;
 144
 145       case 'd':                /* date; LOG4J compliant */
 146         append1("%f", "%.*f", gras_os_time());
 147         break;
 148       case 'r':                /* application age; LOG4J compliant */
 149         append1("%f", "%.*f", gras_os_time() - format_begin_of_time);
 150         break;
 151
 152       case 'm':                /* user-provided message; LOG4J compliant */
 153         vres = vasprintf(&tmp2, fmt, ev->ap_copy);
 154         append1("%s", "%.*s", tmp2);
 155         free(tmp2);
 156         break;
 157
 158       default:
 159         fprintf(stderr, ERRMSG, *q, (char *) l->data);
 160         abort();
 161       }
 162       q++;
 163     } else {
 164       char tmp2[2];
 165       tmp2[0] = *(q++);
 166       tmp2[1] = '\0';
 167       xbt_strbuff_append(buff, tmp2);
 168     }
 169   }
 170   app->do_append(app, buff->data);
 171   xbt_strbuff_free(buff);
 172 }
 173
 174 #undef check_overflow
 175 #define check_overflow \
 176   if (p-ev->buffer > XBT_LOG_BUFF_SIZE) { /* buffer overflow */ \
 177   xbt_log_layout_format_dynamic(l,ev,msg_fmt,app); \
 178   return;\
 179   }
 180 static void xbt_log_layout_format_doit(xbt_log_layout_t l,
 181                                        xbt_log_event_t ev,
 182                                        const char *msg_fmt,
 183                                        xbt_log_appender_t app)
 184 {
 185   char *p, *q;
 186   int precision = -1;
 187
 188
 189   p = ev->buffer;
 190   q = l->data;
 191
 192   while (*q != '\0') {
 193     if (*q == '%') {
 194       q++;
 195     handle_modifier:
 196       switch (*q) {
 197       case '\0':
 198         fprintf(stderr, "Layout format (%s) ending with %%\n",
 199                 (char *) l->data);
 200         abort();
 201       case '%':
 202         *p++ = '%';
 203         break;
 204       case 'n':                /* platform-dependant line separator (LOG4J compliant) */
 205         p += snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "\n");
 206         check_overflow;
 207         break;
 208       case 'e':                /* plain space (SimGrid extension) */
 209         p += snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), " ");
 210         check_overflow;
 211         break;
 212
 213       case '.':                /* precision specifyier */
 214         q++;
 215         q += sscanf(q, "%d", &precision);
 216         goto handle_modifier;
 217
 218       case 'c':                /* category name; LOG4J compliant
 219                                    should accept a precision postfix to show the hierarchy */
 220         if (precision == -1) {
 221           p +=
 222             snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%s",
 223                      ev->cat->name);
 224           check_overflow;
 225         } else {
 226           p +=
 227             sprintf(p, "%.*s",
 228                     (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 229                               precision), ev->cat->name);
 230           check_overflow;
 231           precision = -1;
 232         }
 233         break;
 234       case 'p':                /* priority name; LOG4J compliant */
 235         if (precision == -1) {
 236           p +=
 237             snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%s",
 238                      xbt_log_priority_names[ev->priority]);
 239           check_overflow;
 240         } else {
 241           p +=
 242             sprintf(p, "%.*s",
 243                     (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 244                               precision),
 245                     xbt_log_priority_names[ev->priority]);
 246           check_overflow;
 247           precision = -1;
 248         }
 249         break;
 250
 251       case 'h':                /* host name; SimGrid extension */
 252         if (precision == -1) {
 253           p +=
 254             snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%s",
 255                      gras_os_myname());
 256           check_overflow;
 257         } else {
 258           p +=
 259             sprintf(p, "%.*s",
 260                     (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 261                               precision), gras_os_myname());
 262           check_overflow;
 263           precision = -1;
 264         }
 265         break;
 266       case 't':                /* thread name; LOG4J compliant */
 267         if (precision == -1) {
 268           p +=
 269             snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%s",
 270                      xbt_thread_self_name());
 271           check_overflow;
 272         } else {
 273           p +=
 274             sprintf(p, "%.*s",
 275                     (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 276                               precision), xbt_thread_self_name());
 277           check_overflow;
 278           precision = -1;
 279         }
 280         break;
 281       case 'P':                /* process name; SimGrid extension */
 282         if (precision == -1) {
 283           p +=
 284             snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%s",
 285                      xbt_procname());
 286           check_overflow;
 287         } else {
 288           p +=
 289             sprintf(p, "%.*s",
 290                     (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 291                               precision), xbt_procname());
 292           check_overflow;
 293           precision = -1;
 294         }
 295         break;
 296       case 'i':                /* process PID name; SimGrid extension */
 297         if (precision == -1) {
 298           p +=
 299             snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%d",
 300                      (*xbt_getpid) ());
 301           check_overflow;
 302         } else {
 303           p +=
 304             sprintf(p, "%.*d",
 305                     (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 306                               precision), (*xbt_getpid) ());
 307           check_overflow;
 308           precision = -1;
 309         }
 310         break;
 311
 312       case 'F':                /* file name; LOG4J compliant */
 313         if (precision == -1) {
 314           p +=
 315             snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%s",
 316                      ev->fileName);
 317           check_overflow;
 318         } else {
 319           p +=
 320             sprintf(p, "%.*s",
 321                     (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 322                               precision), ev->fileName);
 323           check_overflow;
 324           precision = -1;
 325         }
 326         break;
 327       case 'l':                /* location; LOG4J compliant */
 328         if (precision == -1) {
 329           p +=
 330             snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%s:%d",
 331                      ev->fileName, ev->lineNum);
 332           check_overflow;
 333         } else {
 334           p +=
 335             snprintf(p,
 336                      (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 337                                precision), "%s:%d", ev->fileName,
 338                      ev->lineNum);
 339           check_overflow;
 340           precision = -1;
 341         }
 342         break;
 343       case 'L':                /* line number; LOG4J compliant */
 344         if (precision == -1) {
 345           p +=
 346             snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%d",
 347                      ev->lineNum);
 348           check_overflow;
 349         } else {
 350           p +=
 351             sprintf(p, "%.*d",
 352                     (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 353                               precision), ev->lineNum);
 354           check_overflow;
 355           precision = -1;
 356         }
 357         break;
 358       case 'M':                /* method (ie, function) name; LOG4J compliant */
 359         if (precision == -1) {
 360           p +=
 361             snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%s",
 362                      ev->functionName);
 363           check_overflow;
 364         } else {
 365           p +=
 366             sprintf(p, "%.*s",
 367                     (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 368                               precision), ev->functionName);
 369           check_overflow;
 370           precision = -1;
 371         }
 372         break;
 373       case 'b':                /* backtrace; called %throwable in LOG4J */
 374       case 'B':                /* short backtrace; called %throwable{short} in LOG4J */
 375 #if defined(HAVE_EXECINFO_H) && defined(HAVE_POPEN) && defined(ADDR2LINE)
 376         {
 377           xbt_ex_t e;
 378           int i;
 379
 380           e.used = backtrace((void **) e.bt, XBT_BACKTRACE_SIZE);
 381           e.bt_strings = NULL;
 382           e.msg = NULL;
 383           e.remote = 0;
 384           xbt_backtrace_current(&e);
 385           if (*q == 'B') {
 386             if (precision == -1) {
 387               p +=
 388                 snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%s",
 389                          e.bt_strings[2] + 8);
 390               check_overflow;
 391             } else {
 392               p +=
 393                 sprintf(p, "%.*s",
 394                         (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 395                                   precision), e.bt_strings[2] + 8);
 396               check_overflow;
 397               precision = -1;
 398             }
 399           } else {
 400             for (i = 2; i < e.used; i++)
 401               if (precision == -1) {
 402                 p +=
 403                   snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%s\n",
 404                            e.bt_strings[i] + 8);
 405                 check_overflow;
 406               } else {
 407                 p +=
 408                   sprintf(p, "%.*s\n",
 409                           (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 410                                     precision), e.bt_strings[i] + 8);
 411                 check_overflow;
 412                 precision = -1;
 413               }
 414           }
 415
 416           xbt_ex_free(e);
 417         }
 418 #else
 419         p +=
 420           snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 421                    "(no backtrace on this arch)");
 422         check_overflow;
 423 #endif
 424         break;
 425
 426       case 'd':                /* date; LOG4J compliant */
 427         if (precision == -1) {
 428           p +=
 429             snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%f",
 430                      gras_os_time());
 431           check_overflow;
 432         } else {
 433           p +=
 434             sprintf(p, "%.*f",
 435                     (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 436                               precision), gras_os_time());
 437           check_overflow;
 438           precision = -1;
 439         }
 440         break;
 441       case 'r':                /* application age; LOG4J compliant */
 442         if (precision == -1) {
 443           p +=
 444             snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%f",
 445                      gras_os_time() - format_begin_of_time);
 446           check_overflow;
 447         } else {
 448           p +=
 449             sprintf(p, "%.*f",
 450                     (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 451                               precision), gras_os_time() - format_begin_of_time);
 452           check_overflow;
 453           precision = -1;
 454         }
 455         break;
 456
 457       case 'm':                /* user-provided message; LOG4J compliant */
 458         if (precision == -1) {
 459           p +=
 460             vsnprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), msg_fmt,
 461                       ev->ap);
 462           check_overflow;
 463         } else {
 464           p +=
 465             vsnprintf(p,
 466                       (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 467                                 precision), msg_fmt, ev->ap);
 468           check_overflow;
 469           precision = -1;
 470         }
 471         break;
 472
 473       default:
 474         fprintf(stderr, ERRMSG, *q, (char *) l->data);
 475         abort();
 476       }
 477       q++;
 478     } else {
 479       *(p++) = *(q++);
 480       check_overflow;
 481     }
 482   }
 483   *p = '\0';
 484   app->do_append(app, ev->buffer);
 485 }
 486
 487 static void xbt_log_layout_format_free(xbt_log_layout_t lay)
 488 {
 489   free(lay->data);
 490 }
 491
 492 xbt_log_layout_t xbt_log_layout_format_new(char *arg)
 493 {
 494   xbt_log_layout_t res = xbt_new0(s_xbt_log_layout_t, 1);
 495   res->do_layout = xbt_log_layout_format_doit;
 496   res->free_ = xbt_log_layout_format_free;
 497   res->data = xbt_strdup((char *) arg);
 498
 499   if (format_begin_of_time < 0)
 500     format_begin_of_time = gras_os_time();
 501
 502   return res;
 503 }