src/logging.c

   1 /* Debugging/Logging support code */
   2
   3 /* (C) 2008-2010 by Harald Welte <laforge@gnumonks.org>
   4  * (C) 2008 by Holger Hans Peter Freyther <zecke@selfish.org>
   5  * All Rights Reserved
   6  *
   7  * This program is free software; you can redistribute it and/or modify
   8  * it under the terms of the GNU General Public License as published by
   9  * the Free Software Foundation; either version 2 of the License, or
  10  * (at your option) any later version.
  11  *
  12  * This program is distributed in the hope that it will be useful,
  13  * but WITHOUT ANY WARRANTY; without even the implied warranty of
  14  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  15  * GNU General Public License for more details.
  16  *
  17  * You should have received a copy of the GNU General Public License along
  18  * with this program; if not, write to the Free Software Foundation, Inc.,
  19  * 51 Franklin Street, Fifth Floor, Boston, MA 02110-1301 USA.
  20  *
  21  */
  22
  23 #include "../config.h"
  24
  25 #include <stdarg.h>
  26 #include <stdlib.h>
  27 #include <stdio.h>
  28 #include <string.h>
  29 #include <ctype.h>
  30
  31 #ifdef HAVE_STRINGS_H
  32 #include <strings.h>
  33 #endif
  34 #include <time.h>
  35 #include <errno.h>
  36
  37 #include <osmocom/core/talloc.h>
  38 #include <osmocom/core/utils.h>
  39 #include <osmocom/core/logging.h>
  40
  41 #include <osmocom/vty/logging.h>        /* for LOGGING_STR. */
  42
  43 struct log_info *osmo_log_info;
  44
  45 static struct log_context log_context;
  46 static void *tall_log_ctx = NULL;
  47 LLIST_HEAD(osmo_log_target_list);
  48
  49 #define LOGLEVEL_DEFS   6       /* Number of loglevels.*/
  50
  51 static const struct value_string loglevel_strs[LOGLEVEL_DEFS+1] = {
  52         { 0,            "EVERYTHING" },
  53         { LOGL_DEBUG,   "DEBUG" },
  54         { LOGL_INFO,    "INFO" },
  55         { LOGL_NOTICE,  "NOTICE" },
  56         { LOGL_ERROR,   "ERROR" },
  57         { LOGL_FATAL,   "FATAL" },
  58         { 0, NULL },
  59 };
  60
  61 #define INT2IDX(x)      (-1*(x)-1)
  62 static const struct log_info_cat internal_cat[OSMO_NUM_DLIB] = {
  63         [INT2IDX(DLGLOBAL)] = { /* -1 becomes 0 */
  64                 .name = "DLGLOBAL",
  65                 .description = "Library-internal global log family",
  66                 .loglevel = LOGL_NOTICE,
  67                 .enabled = 1,
  68         },
  69 };
  70
  71 /* You have to keep this in sync with the structure loglevel_strs. */
  72 const char *loglevel_descriptions[LOGLEVEL_DEFS+1] = {
  73         "Log simply everything",
  74         "Log debug messages and higher levels",
  75         "Log informational messages and higher levels",
  76         "Log noticable messages and higher levels",
  77         "Log error messages and higher levels",
  78         "Log only fatal messages",
  79         NULL,
  80 };
  81
  82 /* special magic for negative (library-internal) log subsystem numbers */
  83 static int subsys_lib2index(int subsys)
  84 {
  85         return (subsys * -1) + (osmo_log_info->num_cat_user-1);
  86 }
  87
  88 int log_parse_level(const char *lvl)
  89 {
  90         return get_string_value(loglevel_strs, lvl);
  91 }
  92
  93 const char *log_level_str(unsigned int lvl)
  94 {
  95         return get_value_string(loglevel_strs, lvl);
  96 }
  97
  98 int log_parse_category(const char *category)
  99 {
 100         int i;
 101
 102         for (i = 0; i < osmo_log_info->num_cat; ++i) {
 103                 if (osmo_log_info->cat[i].name == NULL)
 104                         continue;
 105                 if (!strcasecmp(osmo_log_info->cat[i].name+1, category))
 106                         return i;
 107         }
 108
 109         return -EINVAL;
 110 }
 111
 112 /*
 113  * Parse the category mask.
 114  * The format can be this: category1:category2:category3
 115  * or category1,2:category2,3:...
 116  */
 117 void log_parse_category_mask(struct log_target* target, const char *_mask)
 118 {
 119         int i = 0;
 120         char *mask = strdup(_mask);
 121         char *category_token = NULL;
 122
 123         /* Disable everything to enable it afterwards */
 124         for (i = 0; i < osmo_log_info->num_cat; ++i)
 125                 target->categories[i].enabled = 0;
 126
 127         category_token = strtok(mask, ":");
 128         do {
 129                 for (i = 0; i < osmo_log_info->num_cat; ++i) {
 130                         char* colon = strstr(category_token, ",");
 131                         int length = strlen(category_token);
 132
 133                         if (!osmo_log_info->cat[i].name)
 134                                 continue;
 135
 136                         if (colon)
 137                             length = colon - category_token;
 138
 139                         if (strncasecmp(osmo_log_info->cat[i].name,
 140                                         category_token, length) == 0) {
 141                                 int level = 0;
 142
 143                                 if (colon)
 144                                         level = atoi(colon+1);
 145
 146                                 target->categories[i].enabled = 1;
 147                                 target->categories[i].loglevel = level;
 148                         }
 149                 }
 150         } while ((category_token = strtok(NULL, ":")));
 151
 152         free(mask);
 153 }
 154
 155 static const char* color(int subsys)
 156 {
 157         if (subsys < osmo_log_info->num_cat)
 158                 return osmo_log_info->cat[subsys].color;
 159
 160         return NULL;
 161 }
 162
 163 static void _output(struct log_target *target, unsigned int subsys,
 164                     unsigned int level, char *file, int line, int cont,
 165                     const char *format, va_list ap)
 166 {
 167         char buf[4096];
 168         int ret, len = 0, offset = 0, rem = sizeof(buf);
 169
 170         /* are we using color */
 171         if (target->use_color) {
 172                 const char *c = color(subsys);
 173                 if (c) {
 174                         ret = snprintf(buf + offset, rem, "%s", color(subsys));
 175                         if (ret < 0)
 176                                 goto err;
 177                         OSMO_SNPRINTF_RET(ret, rem, offset, len);
 178                 }
 179         }
 180         if (!cont) {
 181                 if (target->print_timestamp) {
 182                         char *timestr;
 183                         time_t tm;
 184                         tm = time(NULL);
 185                         timestr = ctime(&tm);
 186                         timestr[strlen(timestr)-1] = '\0';
 187                         ret = snprintf(buf + offset, rem, "%s ", timestr);
 188                         if (ret < 0)
 189                                 goto err;
 190                         OSMO_SNPRINTF_RET(ret, rem, offset, len);
 191                 }
 192                 ret = snprintf(buf + offset, rem, "<%4.4x> %s:%d ",
 193                                 subsys, file, line);
 194                 if (ret < 0)
 195                         goto err;
 196                 OSMO_SNPRINTF_RET(ret, rem, offset, len);
 197         }
 198         ret = vsnprintf(buf + offset, rem, format, ap);
 199         if (ret < 0)
 200                 goto err;
 201         OSMO_SNPRINTF_RET(ret, rem, offset, len);
 202
 203         ret = snprintf(buf + offset, rem, "%s",
 204                         target->use_color ? "\033[0;m" : "");
 205         if (ret < 0)
 206                 goto err;
 207         OSMO_SNPRINTF_RET(ret, rem, offset, len);
 208 err:
 209         buf[sizeof(buf)-1] = '\0';
 210         target->output(target, level, buf);
 211 }
 212
 213 static void _logp(int subsys, int level, char *file, int line,
 214                   int cont, const char *format, va_list ap)
 215 {
 216         struct log_target *tar;
 217
 218         if (subsys < 0)
 219                 subsys = subsys_lib2index(subsys);
 220
 221         if (subsys > osmo_log_info->num_cat)
 222                 subsys = DLGLOBAL;
 223
 224         llist_for_each_entry(tar, &osmo_log_target_list, entry) {
 225                 struct log_category *category;
 226                 int output = 0;
 227                 va_list bp;
 228
 229                 category = &tar->categories[subsys];
 230                 /* subsystem is not supposed to be logged */
 231                 if (!category->enabled)
 232                         continue;
 233
 234                 /* Check the global log level */
 235                 if (tar->loglevel != 0 && level < tar->loglevel)
 236                         continue;
 237
 238                 /* Check the category log level */
 239                 if (tar->loglevel == 0 && category->loglevel != 0 &&
 240                     level < category->loglevel)
 241                         continue;
 242
 243                 /* Apply filters here... if that becomes messy we will
 244                  * need to put filters in a list and each filter will
 245                  * say stop, continue, output */
 246                 if ((tar->filter_map & LOG_FILTER_ALL) != 0)
 247                         output = 1;
 248                 else if (osmo_log_info->filter_fn)
 249                         output = osmo_log_info->filter_fn(&log_context,
 250                                                        tar);
 251                 if (!output)
 252                         continue;
 253
 254                 /* According to the manpage, vsnprintf leaves the value of ap
 255                  * in undefined state. Since _output uses vsnprintf and it may
 256                  * be called several times, we have to pass a copy of ap. */
 257                 va_copy(bp, ap);
 258                 _output(tar, subsys, level, file, line, cont, format, ap);
 259                 va_end(bp);
 260         }
 261 }
 262
 263 void logp(int subsys, char *file, int line, int cont,
 264           const char *format, ...)
 265 {
 266         va_list ap;
 267
 268         va_start(ap, format);
 269         _logp(subsys, LOGL_DEBUG, file, line, cont, format, ap);
 270         va_end(ap);
 271 }
 272
 273 void logp2(int subsys, unsigned int level, char *file, int line, int cont, const char *format, ...)
 274 {
 275         va_list ap;
 276
 277         va_start(ap, format);
 278         _logp(subsys, level, file, line, cont, format, ap);
 279         va_end(ap);
 280 }
 281
 282 void log_add_target(struct log_target *target)
 283 {
 284         llist_add_tail(&target->entry, &osmo_log_target_list);
 285 }
 286
 287 void log_del_target(struct log_target *target)
 288 {
 289         llist_del(&target->entry);
 290 }
 291
 292 void log_reset_context(void)
 293 {
 294         memset(&log_context, 0, sizeof(log_context));
 295 }
 296
 297 int log_set_context(uint8_t ctx_nr, void *value)
 298 {
 299         if (ctx_nr > LOG_MAX_CTX)
 300                 return -EINVAL;
 301
 302         log_context.ctx[ctx_nr] = value;
 303
 304         return 0;
 305 }
 306
 307 void log_set_all_filter(struct log_target *target, int all)
 308 {
 309         if (all)
 310                 target->filter_map |= LOG_FILTER_ALL;
 311         else
 312                 target->filter_map &= ~LOG_FILTER_ALL;
 313 }
 314
 315 void log_set_use_color(struct log_target *target, int use_color)
 316 {
 317         target->use_color = use_color;
 318 }
 319
 320 void log_set_print_timestamp(struct log_target *target, int print_timestamp)
 321 {
 322         target->print_timestamp = print_timestamp;
 323 }
 324
 325 void log_set_log_level(struct log_target *target, int log_level)
 326 {
 327         target->loglevel = log_level;
 328 }
 329
 330 void log_set_category_filter(struct log_target *target, int category,
 331                                int enable, int level)
 332 {
 333         if (category >= osmo_log_info->num_cat)
 334                 return;
 335         target->categories[category].enabled = !!enable;
 336         target->categories[category].loglevel = level;
 337 }
 338
 339 static void _file_output(struct log_target *target, unsigned int level,
 340                          const char *log)
 341 {
 342         fprintf(target->tgt_file.out, "%s", log);
 343         fflush(target->tgt_file.out);
 344 }
 345
 346 struct log_target *log_target_create(void)
 347 {
 348         struct log_target *target;
 349         unsigned int i;
 350
 351         target = talloc_zero(tall_log_ctx, struct log_target);
 352         if (!target)
 353                 return NULL;
 354
 355         target->categories = talloc_zero_array(target,
 356                                                 struct log_category,
 357                                                 osmo_log_info->num_cat);
 358         if (!target->categories) {
 359                 talloc_free(target);
 360                 return NULL;
 361         }
 362
 363         INIT_LLIST_HEAD(&target->entry);
 364
 365         /* initialize the per-category enabled/loglevel from defaults */
 366         for (i = 0; i < osmo_log_info->num_cat; i++) {
 367                 struct log_category *cat = &target->categories[i];
 368                 cat->enabled = osmo_log_info->cat[i].enabled;
 369                 cat->loglevel = osmo_log_info->cat[i].loglevel;
 370         }
 371
 372         /* global settings */
 373         target->use_color = 1;
 374         target->print_timestamp = 0;
 375
 376         /* global log level */
 377         target->loglevel = 0;
 378         return target;
 379 }
 380
 381 struct log_target *log_target_create_stderr(void)
 382 {
 383 /* since C89/C99 says stderr is a macro, we can safely do this! */
 384 #ifdef stderr
 385         struct log_target *target;
 386
 387         target = log_target_create();
 388         if (!target)
 389                 return NULL;
 390
 391         target->type = LOG_TGT_TYPE_STDERR;
 392         target->tgt_file.out = stderr;
 393         target->output = _file_output;
 394         return target;
 395 #else
 396         return NULL;
 397 #endif /* stderr */
 398 }
 399
 400 struct log_target *log_target_create_file(const char *fname)
 401 {
 402         struct log_target *target;
 403
 404         target = log_target_create();
 405         if (!target)
 406                 return NULL;
 407
 408         target->type = LOG_TGT_TYPE_FILE;
 409         target->tgt_file.out = fopen(fname, "a");
 410         if (!target->tgt_file.out)
 411                 return NULL;
 412
 413         target->output = _file_output;
 414
 415         target->tgt_file.fname = talloc_strdup(target, fname);
 416
 417         return target;
 418 }
 419
 420 struct log_target *log_target_find(int type, const char *fname)
 421 {
 422         struct log_target *tgt;
 423
 424         llist_for_each_entry(tgt, &osmo_log_target_list, entry) {
 425                 if (tgt->type != type)
 426                         continue;
 427                 if (tgt->type == LOG_TGT_TYPE_FILE) {
 428                         if (!strcmp(fname, tgt->tgt_file.fname))
 429                                 return tgt;
 430                 } else
 431                         return tgt;
 432         }
 433         return NULL;
 434 }
 435
 436 void log_target_destroy(struct log_target *target)
 437 {
 438
 439         /* just in case, to make sure we don't have any references */
 440         log_del_target(target);
 441
 442         if (target->output == &_file_output) {
 443 /* since C89/C99 says stderr is a macro, we can safely do this! */
 444 #ifdef stderr
 445                 /* don't close stderr */
 446                 if (target->tgt_file.out != stderr)
 447 #endif
 448                 {
 449                         fclose(target->tgt_file.out);
 450                         target->tgt_file.out = NULL;
 451                 }
 452         }
 453
 454         talloc_free(target);
 455 }
 456
 457 /* close and re-open a log file (for log file rotation) */
 458 int log_target_file_reopen(struct log_target *target)
 459 {
 460         fclose(target->tgt_file.out);
 461
 462         target->tgt_file.out = fopen(target->tgt_file.fname, "a");
 463         if (!target->tgt_file.out)
 464                 return -errno;
 465
 466         /* we assume target->output already to be set */
 467
 468         return 0;
 469 }
 470
 471 /* This generates the logging command string for VTY. */
 472 const char *log_vty_command_string(const struct log_info *info)
 473 {
 474         int len = 0, offset = 0, ret, i, rem;
 475         int size = strlen("logging level () ()") + 1;
 476         char *str;
 477
 478         for (i = 0; i < info->num_cat; i++) {
 479                 if (info->cat[i].name == NULL)
 480                         continue;
 481                 size += strlen(info->cat[i].name) + 1;
 482         }
 483
 484         for (i = 0; i < LOGLEVEL_DEFS; i++)
 485                 size += strlen(loglevel_strs[i].str) + 1;
 486
 487         rem = size;
 488         str = talloc_zero_size(tall_log_ctx, size);
 489         if (!str)
 490                 return NULL;
 491
 492         ret = snprintf(str + offset, rem, "logging level (all|");
 493         if (ret < 0)
 494                 goto err;
 495         OSMO_SNPRINTF_RET(ret, rem, offset, len);
 496
 497         for (i = 0; i < info->num_cat; i++) {
 498                 if (info->cat[i].name) {
 499                         int j, name_len = strlen(info->cat[i].name)+1;
 500                         char name[name_len];
 501
 502                         for (j = 0; j < name_len; j++)
 503                                 name[j] = tolower(info->cat[i].name[j]);
 504
 505                         name[name_len-1] = '\0';
 506                         ret = snprintf(str + offset, rem, "%s|", name+1);
 507                         if (ret < 0)
 508                                 goto err;
 509                         OSMO_SNPRINTF_RET(ret, rem, offset, len);
 510                 }
 511         }
 512         offset--;       /* to remove the trailing | */
 513         rem++;
 514
 515         ret = snprintf(str + offset, rem, ") (");
 516         if (ret < 0)
 517                 goto err;
 518         OSMO_SNPRINTF_RET(ret, rem, offset, len);
 519
 520         for (i = 0; i < LOGLEVEL_DEFS; i++) {
 521                 int j, loglevel_str_len = strlen(loglevel_strs[i].str)+1;
 522                 char loglevel_str[loglevel_str_len];
 523
 524                 for (j = 0; j < loglevel_str_len; j++)
 525                         loglevel_str[j] = tolower(loglevel_strs[i].str[j]);
 526
 527                 loglevel_str[loglevel_str_len-1] = '\0';
 528                 ret = snprintf(str + offset, rem, "%s|", loglevel_str);
 529                 if (ret < 0)
 530                         goto err;
 531                 OSMO_SNPRINTF_RET(ret, rem, offset, len);
 532         }
 533         offset--;       /* to remove the trailing | */
 534         rem++;
 535
 536         ret = snprintf(str + offset, rem, ")");
 537         if (ret < 0)
 538                 goto err;
 539         OSMO_SNPRINTF_RET(ret, rem, offset, len);
 540 err:
 541         str[size-1] = '\0';
 542         return str;
 543 }
 544
 545 /* This generates the logging command description for VTY. */
 546 const char *log_vty_command_description(const struct log_info *info)
 547 {
 548         char *str;
 549         int i, ret, len = 0, offset = 0, rem;
 550         unsigned int size =
 551                 strlen(LOGGING_STR
 552                        "Set the log level for a specified category\n") + 1;
 553
 554         for (i = 0; i < info->num_cat; i++) {
 555                 if (info->cat[i].name == NULL)
 556                         continue;
 557                 size += strlen(info->cat[i].description) + 1;
 558         }
 559
 560         for (i = 0; i < LOGLEVEL_DEFS; i++)
 561                 size += strlen(loglevel_descriptions[i]) + 1;
 562
 563         size += strlen("Global setting for all subsystems") + 1;
 564         rem = size;
 565         str = talloc_zero_size(tall_log_ctx, size);
 566         if (!str)
 567                 return NULL;
 568
 569         ret = snprintf(str + offset, rem, LOGGING_STR
 570                         "Set the log level for a specified category\n");
 571         if (ret < 0)
 572                 goto err;
 573         OSMO_SNPRINTF_RET(ret, rem, offset, len);
 574
 575         ret = snprintf(str + offset, rem,
 576                         "Global setting for all subsystems\n");
 577         if (ret < 0)
 578                 goto err;
 579         OSMO_SNPRINTF_RET(ret, rem, offset, len);
 580
 581         for (i = 0; i < info->num_cat; i++) {
 582                 if (info->cat[i].name == NULL)
 583                         continue;
 584                 ret = snprintf(str + offset, rem, "%s\n",
 585                                 info->cat[i].description);
 586                 if (ret < 0)
 587                         goto err;
 588                 OSMO_SNPRINTF_RET(ret, rem, offset, len);
 589         }
 590         for (i = 0; i < LOGLEVEL_DEFS; i++) {
 591                 ret = snprintf(str + offset, rem, "%s\n",
 592                                 loglevel_descriptions[i]);
 593                 if (ret < 0)
 594                         goto err;
 595                 OSMO_SNPRINTF_RET(ret, rem, offset, len);
 596         }
 597 err:
 598         str[size-1] = '\0';
 599         return str;
 600 }
 601
 602 int log_init(const struct log_info *inf, void *ctx)
 603 {
 604         int i;
 605
 606         tall_log_ctx = talloc_named_const(ctx, 1, "logging");
 607         if (!tall_log_ctx)
 608                 return -ENOMEM;
 609
 610         osmo_log_info = talloc_zero(tall_log_ctx, struct log_info);
 611         if (!osmo_log_info)
 612                 return -ENOMEM;
 613
 614         osmo_log_info->num_cat_user = inf->num_cat;
 615         /* total number = number of user cat + library cat */
 616         osmo_log_info->num_cat = inf->num_cat + OSMO_NUM_DLIB;
 617
 618         osmo_log_info->cat = talloc_zero_array(osmo_log_info,
 619                                         struct log_info_cat,
 620                                         osmo_log_info->num_cat);
 621         if (!osmo_log_info->cat) {
 622                 talloc_free(osmo_log_info);
 623                 osmo_log_info = NULL;
 624                 return -ENOMEM;
 625         }
 626
 627         /* copy over the user part */
 628         for (i = 0; i < inf->num_cat; i++) {
 629                 memcpy(&osmo_log_info->cat[i], &inf->cat[i],
 630                         sizeof(struct log_info_cat));
 631         }
 632
 633         /* copy over the library part */
 634 }