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