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         [INT2IDX(DLLAPDM)] = {  /* -2 becomes 1 */
  70                 .name = "DLLAPDM",
  71                 .description = "LAPDm in libosmogsm",
  72                 .loglevel = LOGL_NOTICE,
  73                 .enabled = 1,
  74         },
  75         [INT2IDX(DLINP)] = {
  76                 .name = "DINP",
  77                 .description = "A-bis Intput Subsystem",
  78                 .loglevel = LOGL_NOTICE,
  79                 .enabled = 1,
  80         },
  81         [INT2IDX(DLMUX)] = {
  82                 .name = "DMUX",
  83                 .description = "A-bis B-Subchannel TRAU Frame Multiplex",
  84                 .loglevel = LOGL_NOTICE,
  85                 .enabled = 1,
  86         },
  87         [INT2IDX(DLMI)] = {
  88                 .name = "DMI",
  89                 .description = "A-bis Input Driver for Signalling",
  90                 .enabled = 0, .loglevel = LOGL_NOTICE,
  91         },
  92         [INT2IDX(DLMIB)] = {
  93                 .name = "DMIB",
  94                 .description = "A-bis Input Driver for B-Channels (voice)",
  95                 .enabled = 0, .loglevel = LOGL_NOTICE,
  96         },
  97 };
  98
  99 /* You have to keep this in sync with the structure loglevel_strs. */
 100 const char *loglevel_descriptions[LOGLEVEL_DEFS+1] = {
 101         "Log simply everything",
 102         "Log debug messages and higher levels",
 103         "Log informational messages and higher levels",
 104         "Log noticable messages and higher levels",
 105         "Log error messages and higher levels",
 106         "Log only fatal messages",
 107         NULL,
 108 };
 109
 110 /* special magic for negative (library-internal) log subsystem numbers */
 111 static int subsys_lib2index(int subsys)
 112 {
 113         return (subsys * -1) + (osmo_log_info->num_cat_user-1);
 114 }
 115
 116 int log_parse_level(const char *lvl)
 117 {
 118         return get_string_value(loglevel_strs, lvl);
 119 }
 120
 121 const char *log_level_str(unsigned int lvl)
 122 {
 123         return get_value_string(loglevel_strs, lvl);
 124 }
 125
 126 int log_parse_category(const char *category)
 127 {
 128         int i;
 129
 130         for (i = 0; i < osmo_log_info->num_cat; ++i) {
 131                 if (osmo_log_info->cat[i].name == NULL)
 132                         continue;
 133                 if (!strcasecmp(osmo_log_info->cat[i].name+1, category))
 134                         return i;
 135         }
 136
 137         return -EINVAL;
 138 }
 139
 140 /*
 141  * Parse the category mask.
 142  * The format can be this: category1:category2:category3
 143  * or category1,2:category2,3:...
 144  */
 145 void log_parse_category_mask(struct log_target* target, const char *_mask)
 146 {
 147         int i = 0;
 148         char *mask = strdup(_mask);
 149         char *category_token = NULL;
 150
 151         /* Disable everything to enable it afterwards */
 152         for (i = 0; i < osmo_log_info->num_cat; ++i)
 153                 target->categories[i].enabled = 0;
 154
 155         category_token = strtok(mask, ":");
 156         do {
 157                 for (i = 0; i < osmo_log_info->num_cat; ++i) {
 158                         char* colon = strstr(category_token, ",");
 159                         int length = strlen(category_token);
 160
 161                         if (!osmo_log_info->cat[i].name)
 162                                 continue;
 163
 164                         if (colon)
 165                             length = colon - category_token;
 166
 167                         if (strncasecmp(osmo_log_info->cat[i].name,
 168                                         category_token, length) == 0) {
 169                                 int level = 0;
 170
 171                                 if (colon)
 172                                         level = atoi(colon+1);
 173
 174                                 target->categories[i].enabled = 1;
 175                                 target->categories[i].loglevel = level;
 176                         }
 177                 }
 178         } while ((category_token = strtok(NULL, ":")));
 179
 180         free(mask);
 181 }
 182
 183 static const char* color(int subsys)
 184 {
 185         if (subsys < osmo_log_info->num_cat)
 186                 return osmo_log_info->cat[subsys].color;
 187
 188         return NULL;
 189 }
 190
 191 static void _output(struct log_target *target, unsigned int subsys,
 192                     unsigned int level, char *file, int line, int cont,
 193                     const char *format, va_list ap)
 194 {
 195         char buf[4096];
 196         int ret, len = 0, offset = 0, rem = sizeof(buf);
 197
 198         /* are we using color */
 199         if (target->use_color) {
 200                 const char *c = color(subsys);
 201                 if (c) {
 202                         ret = snprintf(buf + offset, rem, "%s", color(subsys));
 203                         if (ret < 0)
 204                                 goto err;
 205                         OSMO_SNPRINTF_RET(ret, rem, offset, len);
 206                 }
 207         }
 208         if (!cont) {
 209                 if (target->print_timestamp) {
 210                         char *timestr;
 211                         time_t tm;
 212                         tm = time(NULL);
 213                         timestr = ctime(&tm);
 214                         timestr[strlen(timestr)-1] = '\0';
 215                         ret = snprintf(buf + offset, rem, "%s ", timestr);
 216                         if (ret < 0)
 217                                 goto err;
 218                         OSMO_SNPRINTF_RET(ret, rem, offset, len);
 219                 }
 220                 ret = snprintf(buf + offset, rem, "<%4.4x> %s:%d ",
 221                                 subsys, file, line);
 222                 if (ret < 0)
 223                         goto err;
 224                 OSMO_SNPRINTF_RET(ret, rem, offset, len);
 225         }
 226         ret = vsnprintf(buf + offset, rem, format, ap);
 227         if (ret < 0)
 228                 goto err;
 229         OSMO_SNPRINTF_RET(ret, rem, offset, len);
 230
 231         ret = snprintf(buf + offset, rem, "%s",
 232                         target->use_color ? "\033[0;m" : "");
 233         if (ret < 0)
 234                 goto err;
 235         OSMO_SNPRINTF_RET(ret, rem, offset, len);
 236 err:
 237         buf[sizeof(buf)-1] = '\0';
 238         target->output(target, level, buf);
 239 }
 240
 241 static void _logp(int subsys, int level, char *file, int line,
 242                   int cont, const char *format, va_list ap)
 243 {
 244         struct log_target *tar;
 245
 246         if (subsys < 0)
 247                 subsys = subsys_lib2index(subsys);
 248
 249         if (subsys > osmo_log_info->num_cat)
 250                 subsys = DLGLOBAL;
 251
 252         llist_for_each_entry(tar, &osmo_log_target_list, entry) {
 253                 struct log_category *category;
 254                 int output = 0;
 255                 va_list bp;
 256
 257                 category = &tar->categories[subsys];
 258                 /* subsystem is not supposed to be logged */
 259                 if (!category->enabled)
 260                         continue;
 261
 262                 /* Check the global log level */
 263                 if (tar->loglevel != 0 && level < tar->loglevel)
 264                         continue;
 265
 266                 /* Check the category log level */
 267                 if (tar->loglevel == 0 && category->loglevel != 0 &&
 268                     level < category->loglevel)
 269                         continue;
 270
 271                 /* Apply filters here... if that becomes messy we will
 272                  * need to put filters in a list and each filter will
 273                  * say stop, continue, output */
 274                 if ((tar->filter_map & LOG_FILTER_ALL) != 0)
 275                         output = 1;
 276                 else if (osmo_log_info->filter_fn)
 277                         output = osmo_log_info->filter_fn(&log_context,
 278                                                        tar);
 279                 if (!output)
 280                         continue;
 281
 282                 /* According to the manpage, vsnprintf leaves the value of ap
 283                  * in undefined state. Since _output uses vsnprintf and it may
 284                  * be called several times, we have to pass a copy of ap. */
 285                 va_copy(bp, ap);
 286                 _output(tar, subsys, level, file, line, cont, format, bp);
 287                 va_end(bp);
 288         }
 289 }
 290
 291 void logp(int subsys, char *file, int line, int cont,
 292           const char *format, ...)
 293 {
 294         va_list ap;
 295
 296         va_start(ap, format);
 297         _logp(subsys, LOGL_DEBUG, file, line, cont, format, ap);
 298         va_end(ap);
 299 }
 300
 301 void logp2(int subsys, unsigned int level, char *file, int line, int cont, const char *format, ...)
 302 {
 303         va_list ap;
 304
 305         va_start(ap, format);
 306         _logp(subsys, level, file, line, cont, format, ap);
 307         va_end(ap);
 308 }
 309
 310 void log_add_target(struct log_target *target)
 311 {
 312         llist_add_tail(&target->entry, &osmo_log_target_list);
 313 }
 314
 315 void log_del_target(struct log_target *target)
 316 {
 317         llist_del(&target->entry);
 318 }
 319
 320 void log_reset_context(void)
 321 {
 322         memset(&log_context, 0, sizeof(log_context));
 323 }
 324
 325 int log_set_context(uint8_t ctx_nr, void *value)
 326 {
 327         if (ctx_nr > LOG_MAX_CTX)
 328                 return -EINVAL;
 329
 330         log_context.ctx[ctx_nr] = value;
 331
 332         return 0;
 333 }
 334
 335 void log_set_all_filter(struct log_target *target, int all)
 336 {
 337         if (all)
 338                 target->filter_map |= LOG_FILTER_ALL;
 339         else
 340                 target->filter_map &= ~LOG_FILTER_ALL;
 341 }
 342
 343 void log_set_use_color(struct log_target *target, int use_color)
 344 {
 345         target->use_color = use_color;
 346 }
 347
 348 void log_set_print_timestamp(struct log_target *target, int print_timestamp)
 349 {
 350         target->print_timestamp = print_timestamp;
 351 }
 352
 353 void log_set_log_level(struct log_target *target, int log_level)
 354 {
 355         target->loglevel = log_level;
 356 }
 357
 358 void log_set_category_filter(struct log_target *target, int category,
 359                                int enable, int level)
 360 {
 361         if (category >= osmo_log_info->num_cat)
 362                 return;
 363         target->categories[category].enabled = !!enable;
 364         target->categories[category].loglevel = level;
 365 }
 366
 367 static void _file_output(struct log_target *target, unsigned int level,
 368                          const char *log)
 369 {
 370         fprintf(target->tgt_file.out, "%s", log);
 371         fflush(target->tgt_file.out);
 372 }
 373
 374 struct log_target *log_target_create(void)
 375 {
 376         struct log_target *target;
 377         unsigned int i;
 378
 379         target = talloc_zero(tall_log_ctx, struct log_target);
 380         if (!target)
 381                 return NULL;
 382
 383         target->categories = talloc_zero_array(target,
 384                                                 struct log_category,
 385                                                 osmo_log_info->num_cat);
 386         if (!target->categories) {
 387                 talloc_free(target);
 388                 return NULL;
 389         }
 390
 391         INIT_LLIST_HEAD(&target->entry);
 392
 393         /* initialize the per-category enabled/loglevel from defaults */
 394         for (i = 0; i < osmo_log_info->num_cat; i++) {
 395                 struct log_category *cat = &target->categories[i];
 396                 cat->enabled = osmo_log_info->cat[i].enabled;
 397                 cat->loglevel = osmo_log_info->cat[i].loglevel;
 398         }
 399
 400         /* global settings */
 401         target->use_color = 1;
 402         target->print_timestamp = 0;
 403
 404         /* global log level */
 405         target->loglevel = 0;
 406         return target;
 407 }
 408
 409 struct log_target *log_target_create_stderr(void)
 410 {
 411 /* since C89/C99 says stderr is a macro, we can safely do this! */
 412 #ifdef stderr
 413         struct log_target *target;
 414
 415         target = log_target_create();
 416         if (!target)
 417                 return NULL;
 418
 419         target->type = LOG_TGT_TYPE_STDERR;
 420         target->tgt_file.out = stderr;
 421         target->output = _file_output;
 422         return target;
 423 #else
 424         return NULL;
 425 #endif /* stderr */
 426 }
 427
 428 struct log_target *log_target_create_file(const char *fname)
 429 {
 430         struct log_target *target;
 431
 432         target = log_target_create();
 433         if (!target)
 434                 return NULL;
 435
 436         target->type = LOG_TGT_TYPE_FILE;
 437         target->tgt_file.out = fopen(fname, "a");
 438         if (!target->tgt_file.out)
 439                 return NULL;
 440
 441         target->output = _file_output;
 442
 443         target->tgt_file.fname = talloc_strdup(target, fname);
 444
 445         return target;
 446 }
 447
 448 struct log_target *log_target_find(int type, const char *fname)
 449 {
 450         struct log_target *tgt;
 451
 452         llist_for_each_entry(tgt, &osmo_log_target_list, entry) {
 453                 if (tgt->type != type)
 454                         continue;
 455                 if (tgt->type == LOG_TGT_TYPE_FILE) {
 456                         if (!strcmp(fname, tgt->tgt_file.fname))
 457                                 return tgt;
 458                 } else
 459                         return tgt;
 460         }
 461         return NULL;
 462 }
 463
 464 void log_target_destroy(struct log_target *target)
 465 {
 466
 467         /* just in case, to make sure we don't have any references */
 468         log_del_target(target);
 469
 470         if (target->output == &_file_output) {
 471 /* since C89/C99 says stderr is a macro, we can safely do this! */
 472 #ifdef stderr
 473                 /* don't close stderr */
 474                 if (target->tgt_file.out != stderr)
 475 #endif
 476                 {
 477                         fclose(target->tgt_file.out);
 478                         target->tgt_file.out = NULL;
 479                 }
 480         }
 481
 482         talloc_free(target);
 483 }
 484
 485 /* close and re-open a log file (for log file rotation) */
 486 int log_target_file_reopen(struct log_target *target)
 487 {
 488         fclose(target->tgt_file.out);
 489
 490         target->tgt_file.out = fopen(target->tgt_file.fname, "a");
 491         if (!target->tgt_file.out)
 492                 return -errno;
 493
 494         /* we assume target->output already to be set */
 495
 496         return 0;
 497 }
 498
 499 /* This generates the logging command string for VTY. */
 500 const char *log_vty_command_string(const struct log_info *unused_info)
 501 {
 502         struct log_info *info = osmo_log_info;
 503         int len = 0, offset = 0, ret, i, rem;
 504         int size = strlen("logging level () ()") + 1;
 505         char *str;
 506
 507         for (i = 0; i < info->num_cat; i++) {
 508                 if (info->cat[i].name == NULL)
 509                         continue;
 510                 size += strlen(info->cat[i].name) + 1;
 511         }
 512
 513         for (i = 0; i < LOGLEVEL_DEFS; i++)
 514                 size += strlen(loglevel_strs[i].str) + 1;
 515
 516         rem = size;
 517         str = talloc_zero_size(tall_log_ctx, size);
 518         if (!str)
 519                 return NULL;
 520
 521         ret = snprintf(str + offset, rem, "logging level (all|");
 522         if (ret < 0)
 523                 goto err;
 524         OSMO_SNPRINTF_RET(ret, rem, offset, len);
 525
 526         for (i = 0; i < info->num_cat; i++) {
 527                 if (info->cat[i].name) {
 528                         int j, name_len = strlen(info->cat[i].name)+1;
 529                         char name[name_len];
 530
 531                         for (j = 0; j < name_len; j++)
 532                                 name[j] = tolower(info->cat[i].name[j]);
 533
 534                         name[name_len-1] = '\0';
 535                         ret = snprintf(str + offset, rem, "%s|", name+1);
 536                         if (ret < 0)
 537                                 goto err;
 538                         OSMO_SNPRINTF_RET(ret, rem, offset, len);
 539                 }
 540         }
 541         offset--;       /* to remove the trailing | */
 542         rem++;
 543
 544         ret = snprintf(str + offset, rem, ") (");
 545         if (ret < 0)
 546                 goto err;
 547         OSMO_SNPRINTF_RET(ret, rem, offset, len);
 548
 549         for (i = 0; i < LOGLEVEL_DEFS; i++) {
 550                 int j, loglevel_str_len = strlen(loglevel_strs[i].str)+1;
 551                 char loglevel_str[loglevel_str_len];
 552
 553                 for (j = 0; j < loglevel_str_len; j++)
 554                         loglevel_str[j] = tolower(loglevel_strs[i].str[j]);
 555
 556                 loglevel_str[loglevel_str_len-1] = '\0';
 557                 ret = snprintf(str + offset, rem, "%s|", loglevel_str);
 558                 if (ret < 0)
 559                         goto err;
 560                 OSMO_SNPRINTF_RET(ret, rem, offset, len);
 561         }
 562         offset--;       /* to remove the trailing | */
 563         rem++;
 564
 565         ret = snprintf(str + offset, rem, ")");
 566         if (ret < 0)
 567                 goto err;
 568         OSMO_SNPRINTF_RET(ret, rem, offset, len);
 569 err:
 570         str[size-1] = '\0';
 571         return str;
 572 }
 573
 574 /* This generates the logging command description for VTY. */
 575 const char *log_vty_command_description(const struct log_info *unused_info)
 576 {
 577         struct log_info *info = osmo_log_info;
 578         char *str;
 579         int i, ret, len = 0, offset = 0, rem;
 580         unsigned int size =
 581                 strlen(LOGGING_STR
 582                        "Set the log level for a specified category\n") + 1;
 583
 584         for (i = 0; i < info->num_cat; i++) {
 585                 if (info->cat[i].name == NULL)
 586                         continue;
 587                 size += strlen(info->cat[i].description) + 1;
 588         }
 589
 590         for (i = 0; i < LOGLEVEL_DEFS; i++)
 591                 size += strlen(loglevel_descriptions[i]) + 1;
 592
 593         size += strlen("Global setting for all subsystems") + 1;
 594         rem = size;
 595         str = talloc_zero_size(tall_log_ctx, size);
 596         if (!str)
 597                 return NULL;
 598
 599         ret = snprintf(str + offset, rem, LOGGING_STR
 600                         "Set the log level for a specified category\n");
 601         if (ret < 0)
 602                 goto err;
 603         OSMO_SNPRINTF_RET(ret, rem, offset, len);
 604
 605         ret = snprintf(str + offset, rem,
 606                         "Global setting for all subsystems\n");
 607         if (ret < 0)
 608                 goto err;
 609         OSMO_SNPRINTF_RET(ret, rem, offset, len);
 610
 611         for (i = 0; i < info->num_cat; i++) {
 612                 if (info->cat[i].name == NULL)
 613                         continue;
 614                 ret = snprintf(str + offset, rem, "%s\n",
 615                                 info->cat[i].description);
 616                 if (ret < 0)
 617                         goto err;
 618                 OSMO_SNPRINTF_RET(ret, rem, offset, len);
 619         }
 620         for (i = 0; i < LOGLEVEL_DEFS; i++) {
 621                 ret = snprintf(str + offset, rem, "%s\n",
 622                                 loglevel_descriptions[i]);
 623                 if (ret < 0)
 624                         goto err;
 625                 OSMO_SNPRINTF_RET(ret, rem, offset, len);
 626         }
 627 err:
 628         str[size-1] = '\0';
 629         return str;
 630 }
 631
 632 int log_init(const struct log_info *inf, void *ctx)
 633 {
 634         int i;
 635
 636         tall_log_ctx = talloc_named_const(ctx, 1, "logging");
 637         if (!tall_log_ctx)
 638                 return -ENOMEM;
 639
 640         osmo_log_info = talloc_zero(tall_log_ctx, struct log_info);
 641         if (!osmo_log_info)
 642                 return -ENOMEM;
 643
 644         osmo_log_info->num_cat_user = inf->num_cat;
 645         /* total number = number of user cat + library cat */
 646         osmo_log_info->num_cat = inf->num_cat + ARRAY_SIZE(internal_cat);
 647
 648         osmo_log_info->cat = talloc_zero_array(osmo_log_info,
 649                                         struct log_info_cat,
 650                                         osmo_log_info->num_cat);
 651         if (!osmo_log_info->cat) {
 652                 talloc_free(osmo_log_info);
 653                 osmo_log_info = NULL;
 654                 return -ENOMEM;
 655         }
 656
 657         /* copy over the user part */
 658         for (i = 0; i < inf->num_cat; i++) {
 659                 memcpy(&osmo_log_info->cat[i], &inf->cat[i],
 660                         sizeof(struct log_info_cat));
 661         }
 662
 663         /* copy over the library part */
 664         for (i = 0; i < ARRAY_SIZE(internal_cat); i++) {
 665                 unsigned int cn = osmo_log_info->num_cat_user + i;
 666                 memcpy(&osmo_log_info->cat[cn],
 667                         &internal_cat[i], sizeof(struct log_info_cat));
 668         }
 669
 670         return 0;
 671 }