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 += snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%s",
 222                         ev->cat->name);
 223           check_overflow;
 224         } else {
 225           p += sprintf(p, "%.*s",
 226                        (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 227                                  precision), ev->cat->name);
 228           check_overflow;
 229           precision = -1;
 230         }
 231         break;
 232       case 'p':                /* priority name; LOG4J compliant */
 233         if (precision == -1) {
 234           p += snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%s",
 235                         xbt_log_priority_names[ev->priority]);
 236           check_overflow;
 237         } else {
 238           p += sprintf(p, "%.*s",
 239                        (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 240                                  precision),
 241                        xbt_log_priority_names[ev->priority]);
 242           check_overflow;
 243           precision = -1;
 244         }
 245         break;
 246
 247       case 'h':                /* host name; SimGrid extension */
 248         if (precision == -1) {
 249           p += snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%s",
 250                         gras_os_myname());
 251           check_overflow;
 252         } else {
 253           p += sprintf(p, "%.*s",
 254                        (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 255                                  precision), gras_os_myname());
 256           check_overflow;
 257           precision = -1;
 258         }
 259         break;
 260       case 't':                /* thread name; LOG4J compliant */
 261         if (precision == -1) {
 262           p += snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%s",
 263                         xbt_thread_self_name());
 264           check_overflow;
 265         } else {
 266           p += sprintf(p, "%.*s",
 267                        (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 268                                  precision), xbt_thread_self_name());
 269           check_overflow;
 270           precision = -1;
 271         }
 272         break;
 273       case 'P':                /* process name; SimGrid extension */
 274         if (precision == -1) {
 275           p += snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%s",
 276                         xbt_procname());
 277           check_overflow;
 278         } else {
 279           p += sprintf(p, "%.*s",
 280                        (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 281                                  precision), xbt_procname());
 282           check_overflow;
 283           precision = -1;
 284         }
 285         break;
 286       case 'i':                /* process PID name; SimGrid extension */
 287         if (precision == -1) {
 288           p += snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%d",
 289                         (*xbt_getpid) ());
 290           check_overflow;
 291         } else {
 292           p += sprintf(p, "%.*d",
 293                        (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 294                                  precision), (*xbt_getpid) ());
 295           check_overflow;
 296           precision = -1;
 297         }
 298         break;
 299
 300       case 'F':                /* file name; LOG4J compliant */
 301         if (precision == -1) {
 302           p += snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%s",
 303                         ev->fileName);
 304           check_overflow;
 305         } else {
 306           p += sprintf(p, "%.*s",
 307                        (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 308                                  precision), ev->fileName);
 309           check_overflow;
 310           precision = -1;
 311         }
 312         break;
 313       case 'l':                /* location; LOG4J compliant */
 314         if (precision == -1) {
 315           p += snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%s:%d",
 316                         ev->fileName, ev->lineNum);
 317           check_overflow;
 318         } else {
 319           p += snprintf(p,
 320                         (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 321                                   precision), "%s:%d", ev->fileName,
 322                         ev->lineNum);
 323           check_overflow;
 324           precision = -1;
 325         }
 326         break;
 327       case 'L':                /* line number; LOG4J compliant */
 328         if (precision == -1) {
 329           p += snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%d",
 330                         ev->lineNum);
 331           check_overflow;
 332         } else {
 333           p += sprintf(p, "%.*d",
 334                        (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 335                                  precision), ev->lineNum);
 336           check_overflow;
 337           precision = -1;
 338         }
 339         break;
 340       case 'M':                /* method (ie, function) name; LOG4J compliant */
 341         if (precision == -1) {
 342           p += snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%s",
 343                         ev->functionName);
 344           check_overflow;
 345         } else {
 346           p += sprintf(p, "%.*s",
 347                        (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 348                                  precision), ev->functionName);
 349           check_overflow;
 350           precision = -1;
 351         }
 352         break;
 353       case 'b':                /* backtrace; called %throwable in LOG4J */
 354       case 'B':                /* short backtrace; called %throwable{short} in LOG4J */
 355 #if defined(HAVE_EXECINFO_H) && defined(HAVE_POPEN) && defined(ADDR2LINE)
 356         {
 357           xbt_ex_t e;
 358           int i;
 359
 360           e.used = backtrace((void **) e.bt, XBT_BACKTRACE_SIZE);
 361           e.bt_strings = NULL;
 362           e.msg = NULL;
 363           e.remote = 0;
 364           xbt_backtrace_current(&e);
 365           if (*q == 'B') {
 366             if (precision == -1) {
 367               p += snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%s",
 368                             e.bt_strings[2] + 8);
 369               check_overflow;
 370             } else {
 371               p += sprintf(p, "%.*s",
 372                            (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 373                                      precision), e.bt_strings[2] + 8);
 374               check_overflow;
 375               precision = -1;
 376             }
 377           } else {
 378             for (i = 2; i < e.used; i++)
 379               if (precision == -1) {
 380                 p += snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 381                               "%s\n", e.bt_strings[i] + 8);
 382                 check_overflow;
 383               } else {
 384                 p += sprintf(p, "%.*s\n",
 385                              (int) MIN(XBT_LOG_BUFF_SIZE -
 386                                        (p - ev->buffer), precision),
 387                              e.bt_strings[i] + 8);
 388                 check_overflow;
 389                 precision = -1;
 390               }
 391           }
 392
 393           xbt_ex_free(e);
 394         }
 395 #else
 396         p += snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 397                       "(no backtrace on this arch)");
 398         check_overflow;
 399 #endif
 400         break;
 401
 402       case 'd':                /* date; LOG4J compliant */
 403         if (precision == -1) {
 404           p += snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%f",
 405                         gras_os_time());
 406           check_overflow;
 407         } else {
 408           p += sprintf(p, "%.*f",
 409                        (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 410                                  precision), gras_os_time());
 411           check_overflow;
 412           precision = -1;
 413         }
 414         break;
 415       case 'r':                /* application age; LOG4J compliant */
 416         if (precision == -1) {
 417           p += snprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), "%f",
 418                         gras_os_time() - format_begin_of_time);
 419           check_overflow;
 420         } else {
 421           p += sprintf(p, "%.*f",
 422                        (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 423                                  precision),
 424                        gras_os_time() - format_begin_of_time);
 425           check_overflow;
 426           precision = -1;
 427         }
 428         break;
 429
 430       case 'm':                /* user-provided message; LOG4J compliant */
 431         if (precision == -1) {
 432           p += vsnprintf(p, XBT_LOG_BUFF_SIZE - (p - ev->buffer), msg_fmt,
 433                          ev->ap);
 434           check_overflow;
 435         } else {
 436           p += vsnprintf(p,
 437                          (int) MIN(XBT_LOG_BUFF_SIZE - (p - ev->buffer),
 438                                    precision), msg_fmt, ev->ap);
 439           check_overflow;
 440           precision = -1;
 441         }
 442         break;
 443
 444       default:
 445         fprintf(stderr, ERRMSG, *q, (char *) l->data);
 446         abort();
 447       }
 448       q++;
 449     } else {
 450       *(p++) = *(q++);
 451       check_overflow;
 452     }
 453   }
 454   *p = '\0';
 455   app->do_append(app, ev->buffer);
 456 }
 457
 458 static void xbt_log_layout_format_free(xbt_log_layout_t lay)
 459 {
 460   free(lay->data);
 461 }
 462
 463 xbt_log_layout_t xbt_log_layout_format_new(char *arg)
 464 {
 465   xbt_log_layout_t res = xbt_new0(s_xbt_log_layout_t, 1);
 466   res->do_layout = xbt_log_layout_format_doit;
 467   res->free_ = xbt_log_layout_format_free;
 468   res->data = xbt_strdup((char *) arg);
 469
 470   if (format_begin_of_time < 0)
 471     format_begin_of_time = gras_os_time();
 472
 473   return res;
 474 }