logger.c

   1 /*
   2  * Asterisk Logger
   3  *
   4  * Mark Spencer <markster@marko.net>
   5  *
   6  * Copyright(C)1999, Linux Support Services, Inc.
   7  *
   8  * Distributed under the terms of the GNU General Public License (GPL) Version 2
   9  *
  10  * Logging routines
  11  *
  12  */
  13
  14 #include <signal.h>
  15 #include <stdarg.h>
  16 #include <stdio.h>
  17 #include <unistd.h>
  18 #include <time.h>
  19 #include <asterisk/lock.h>
  20 #include <asterisk/options.h>
  21 #include <asterisk/channel.h>
  22 #include <asterisk/config.h>
  23 #include <asterisk/term.h>
  24 #include <asterisk/cli.h>
  25 #include <string.h>
  26 #include <stdlib.h>
  27 #include <errno.h>
  28 #include <pthread.h>
  29 #include <sys/stat.h>
  30 #include "asterisk.h"
  31 #include "astconf.h"
  32
  33 #define SYSLOG_NAMES /* so we can map syslog facilities names to their numeric values,
  34                         from <syslog.h> which is included by logger.h */
  35 #include <syslog.h>
  36 static int syslog_level_map[] = {
  37         LOG_DEBUG,
  38         LOG_INFO,    /* arbitrary equivalent of LOG_EVENT */
  39         LOG_NOTICE,
  40         LOG_WARNING,
  41         LOG_ERR,
  42         LOG_DEBUG
  43 };
  44 #define SYSLOG_NLEVELS 6
  45
  46 #include <asterisk/logger.h>
  47
  48 #define MAX_MSG_QUEUE 200
  49
  50 static ast_mutex_t msglist_lock = AST_MUTEX_INITIALIZER;
  51 static ast_mutex_t loglock = AST_MUTEX_INITIALIZER;
  52 static int pending_logger_reload = 0;
  53
  54 static struct msglist {
  55         char *msg;
  56         struct msglist *next;
  57 } *list = NULL, *last = NULL;
  58
  59 struct logchannel {
  60         int logmask;
  61         int facility; /* syslog */
  62         int syslog; /* syslog flag */
  63         int console;  /* console logging */
  64         FILE *fileptr; /* logfile logging */
  65         char filename[256];
  66         struct logchannel *next;
  67 };
  68
  69 static struct logchannel *logchannels = NULL;
  70
  71 static int msgcnt = 0;
  72
  73 static FILE *eventlog = NULL;
  74
  75 static char *levels[] = {
  76        "DEBUG",
  77        "EVENT",
  78        "NOTICE",
  79        "WARNING",
  80        "ERROR",
  81        "VERBOSE"
  82 };
  83
  84 static int colors[] = {
  85        COLOR_BRGREEN,
  86        COLOR_BRBLUE,
  87        COLOR_YELLOW,
  88        COLOR_BRRED,
  89        COLOR_RED,
  90        COLOR_GREEN
  91 };
  92
  93 static int make_components(char *s, int lineno)
  94 {
  95         char *w;
  96         int res = 0;
  97         char *stringp=NULL;
  98         stringp=s;
  99         w = strsep(&stringp, ",");
 100         while(w) {
 101             while(*w && (*w < 33))
 102                 w++;
 103             if (!strcasecmp(w, "error"))
 104                 res |= (1 << __LOG_ERROR);
 105             else if (!strcasecmp(w, "warning"))
 106                 res |= (1 << __LOG_WARNING);
 107             else if (!strcasecmp(w, "notice"))
 108                 res |= (1 << __LOG_NOTICE);
 109             else if (!strcasecmp(w, "event"))
 110                 res |= (1 << __LOG_EVENT);
 111             else if (!strcasecmp(w, "debug"))
 112                 res |= (1 << __LOG_DEBUG);
 113             else if (!strcasecmp(w, "verbose"))
 114                 res |= (1 << __LOG_VERBOSE);
 115             else {
 116                 fprintf(stderr, "Logfile Warning: Unknown keyword '%s' at line %d of logger.conf\n", w, lineno);
 117             }
 118             w = strsep(&stringp, ",");
 119         }
 120         return res;
 121 }
 122
 123 static struct logchannel *make_logchannel(char *channel, char *components, int lineno)
 124 {
 125         struct logchannel *chan;
 126         char *facility;
 127         CODE *cptr;
 128
 129         if (!strlen(channel))
 130                 return NULL;
 131         chan = malloc(sizeof(struct logchannel));
 132
 133         if (chan) {
 134                 memset(chan, 0, sizeof(struct logchannel));
 135                 if (!strcasecmp(channel, "console")) {
 136                     chan->console = 1;
 137                 } else if (!strncasecmp(channel, "syslog", 6)) {
 138                     /*
 139                      * syntax is:
 140                      *  syslog.facility => level,level,level
 141                      */
 142                     facility = strchr(channel, '.');
 143                     if(!facility++ || !facility) {
 144                         facility = "local0";
 145                     }
 146                     /*
 147                      * Walk through the list of facilitynames (defined in sys/syslog.h)
 148                      * to see if we can find the one we have been given
 149                      */
 150                     chan->facility = -1;
 151                     cptr = facilitynames;
 152                     while (cptr->c_name) {
 153                         if (!strncasecmp(facility, cptr->c_name, sizeof(cptr->c_name))) {
 154                             chan->facility = cptr->c_val;
 155                             break;
 156                         }
 157                         cptr++;
 158                     }
 159                     if (0 > chan->facility) {
 160                         fprintf(stderr, "Logger Warning: bad syslog facility in logger.conf\n");
 161                         free(chan);
 162                         return NULL;
 163                     }
 164
 165                     chan->syslog = 1;
 166                     openlog("asterisk", LOG_PID, chan->facility);
 167                 } else {
 168                         if (channel[0] == '/')
 169                                 strncpy(chan->filename, channel, sizeof(chan->filename) - 1);
 170                         else
 171                                 snprintf(chan->filename, sizeof(chan->filename), "%s/%s", (char *)ast_config_AST_LOG_DIR, channel);
 172                         chan->fileptr = fopen(chan->filename, "a");
 173                         if (!chan->fileptr) {
 174                                 /* Can't log here, since we're called with a lock */
 175                                 fprintf(stderr, "Logger Warning: Unable to open log file '%s': %s\n", chan->filename, strerror(errno));
 176                         }
 177                 }
 178                 chan->logmask = make_components(components, lineno);
 179         }
 180         return chan;
 181 }
 182
 183 static void init_logger_chain(void)
 184 {
 185         struct logchannel *chan, *cur;
 186         struct ast_config *cfg;
 187         struct ast_variable *var;
 188
 189         /* delete our list of log channels */
 190         ast_mutex_lock(&loglock);
 191         chan = logchannels;
 192         while (chan) {
 193             cur = chan->next;
 194             free(chan);
 195             chan = cur;
 196         }
 197         logchannels = NULL;
 198         ast_mutex_unlock(&loglock);
 199
 200         /* close syslog */
 201         closelog();
 202
 203         cfg = ast_load("logger.conf");
 204
 205         /* If no config file, we're fine */
 206         if (!cfg)
 207             return;
 208
 209         ast_mutex_lock(&loglock);
 210         var = ast_variable_browse(cfg, "logfiles");
 211         while(var) {
 212                 chan = make_logchannel(var->name, var->value, var->lineno);
 213                 if (chan) {
 214                         chan->next = logchannels;
 215                         logchannels = chan;
 216                 }
 217                 var = var->next;
 218         }
 219
 220         ast_destroy(cfg);
 221         ast_mutex_unlock(&loglock);
 222 }
 223
 224 static FILE *qlog = NULL;
 225 static ast_mutex_t qloglock = AST_MUTEX_INITIALIZER;
 226
 227 void ast_queue_log(const char *queuename, const char *callid, const char *agent, const char *event, const char *fmt, ...)
 228 {
 229         va_list ap;
 230         ast_mutex_lock(&qloglock);
 231         if (qlog) {
 232                 va_start(ap, fmt);
 233                 fprintf(qlog, "%ld|%s|%s|%s|%s|", (long)time(NULL), callid, queuename, agent, event);
 234                 vfprintf(qlog, fmt, ap);
 235                 fprintf(qlog, "\n");
 236                 va_end(ap);
 237                 fflush(qlog);
 238         }
 239         ast_mutex_unlock(&qloglock);
 240 }
 241
 242 static void queue_log_init(void)
 243 {
 244         char filename[256];
 245         int reloaded = 0;
 246         ast_mutex_lock(&qloglock);
 247         if (qlog) {
 248                 reloaded = 1;
 249                 fclose(qlog);
 250                 qlog = NULL;
 251         }
 252         snprintf(filename, sizeof(filename), "%s/%s", (char *)ast_config_AST_LOG_DIR, "queue_log");
 253         qlog = fopen(filename, "a");
 254         ast_mutex_unlock(&qloglock);
 255         if (reloaded)
 256                 ast_queue_log("NONE", "NONE", "NONE", "CONFIGRELOAD", "%s", "");
 257         else
 258                 ast_queue_log("NONE", "NONE", "NONE", "QUEUESTART", "%s", "");
 259 }
 260
 261 int reload_logger(int rotate)
 262 {
 263         char old[AST_CONFIG_MAX_PATH];
 264         char new[AST_CONFIG_MAX_PATH];
 265         struct logchannel *f;
 266         FILE *myf;
 267
 268         int x;
 269         ast_mutex_lock(&loglock);
 270         if (eventlog)
 271                 fclose(eventlog);
 272         else
 273                 rotate = 0;
 274         eventlog = NULL;
 275
 276
 277
 278         mkdir((char *)ast_config_AST_LOG_DIR, 0755);
 279         snprintf(old, sizeof(old), "%s/%s", (char *)ast_config_AST_LOG_DIR, EVENTLOG);
 280
 281         if(rotate) {
 282                 for(x=0;;x++) {
 283                         snprintf(new, sizeof(new), "%s/%s.%d", (char *)ast_config_AST_LOG_DIR, EVENTLOG,x);
 284                         myf = fopen((char *)new, "r");
 285                         if(myf)
 286                                 fclose(myf);
 287                         else
 288                                 break;
 289                 }
 290
 291                 /* do it */
 292                 if (rename(old,new))
 293                         fprintf(stderr, "Unable to rename file '%s' to '%s'\n", old, new);
 294         }
 295
 296         eventlog = fopen(old, "a");
 297
 298         f = logchannels;
 299         while(f) {
 300                 if (f->fileptr && (f->fileptr != stdout) && (f->fileptr != stderr)) {
 301                         fclose(f->fileptr);
 302                         f->fileptr = NULL;
 303                         if(rotate) {
 304                                 strncpy(old, f->filename, sizeof(old));
 305
 306                                 for(x=0;;x++) {
 307                                         snprintf(new, sizeof(new), "%s.%d", f->filename, x);
 308                                         myf = fopen((char *)new, "r");
 309                                         if (myf) {
 310                                                 fclose(myf);
 311                                         } else {
 312                                                 break;
 313                                         }
 314                                 }
 315
 316                                 /* do it */
 317                                 if (rename(old,new))
 318                                         fprintf(stderr, "Unable to rename file '%s' to '%s'\n", old, new);
 319                         }
 320                 }
 321                 f = f->next;
 322         }
 323
 324         ast_mutex_unlock(&loglock);
 325
 326         queue_log_init();
 327
 328         if (eventlog) {
 329                 init_logger_chain();
 330                 ast_log(LOG_EVENT, "Restarted Asterisk Event Logger\n");
 331                 if (option_verbose)
 332                         ast_verbose("Asterisk Event Logger restarted\n");
 333                 return 0;
 334         } else
 335                 ast_log(LOG_ERROR, "Unable to create event log: %s\n", strerror(errno));
 336         init_logger_chain();
 337         pending_logger_reload = 0;
 338         return -1;
 339 }
 340
 341 static int handle_logger_reload(int fd, int argc, char *argv[])
 342 {
 343         if(reload_logger(0))
 344         {
 345                 ast_cli(fd, "Failed to reloadthe logger\n");
 346                 return RESULT_FAILURE;
 347         }
 348         else
 349                 return RESULT_SUCCESS;
 350 }
 351
 352 static int handle_logger_rotate(int fd, int argc, char *argv[])
 353 {
 354         if(reload_logger(1))
 355         {
 356                 ast_cli(fd, "Failed to reloadthe logger\n");
 357                 return RESULT_FAILURE;
 358         }
 359         else
 360                 return RESULT_SUCCESS;
 361 }
 362
 363 static struct verb {
 364         void (*verboser)(const char *string, int opos, int replacelast, int complete);
 365         struct verb *next;
 366 } *verboser = NULL;
 367
 368
 369 static char logger_reload_help[] =
 370 "Usage: logger reload\n"
 371 "       Reloads the logger subsystem state.  Use after restarting syslogd(8)\n";
 372
 373 static char logger_rotate_help[] =
 374 "Usage: logger rotate\n"
 375 "       Rotates and Reopens the log files.\n";
 376
 377 static struct ast_cli_entry reload_logger_cli =
 378         { { "logger", "reload", NULL },
 379         handle_logger_reload, "Reopens the log files",
 380         logger_reload_help };
 381
 382 static struct ast_cli_entry rotate_logger_cli =
 383         { { "logger", "rotate", NULL },
 384         handle_logger_rotate, "Rotates and reopens the log files",
 385         logger_rotate_help };
 386
 387 static int handle_SIGXFSZ(int sig) {
 388         /* Indicate need to reload */
 389         pending_logger_reload = 1;
 390     return 0;
 391 }
 392
 393 int init_logger(void)
 394 {
 395         char tmp[256];
 396
 397         /* auto rotate if sig SIGXFSZ comes a-knockin */
 398         (void) signal(SIGXFSZ,(void *) handle_SIGXFSZ);
 399
 400         /* register the relaod logger cli command */
 401         ast_cli_register(&reload_logger_cli);
 402         ast_cli_register(&rotate_logger_cli);
 403
 404         /* initialize queue logger */
 405         queue_log_init();
 406
 407         /* create the eventlog */
 408         mkdir((char *)ast_config_AST_LOG_DIR, 0755);
 409         snprintf(tmp, sizeof(tmp), "%s/%s", (char *)ast_config_AST_LOG_DIR, EVENTLOG);
 410         eventlog = fopen((char *)tmp, "a");
 411         if (eventlog) {
 412                 init_logger_chain();
 413                 ast_log(LOG_EVENT, "Started Asterisk Event Logger\n");
 414                 if (option_verbose)
 415                         ast_verbose("Asterisk Event Logger Started %s\n",(char *)tmp);
 416                 return 0;
 417         } else
 418                 ast_log(LOG_ERROR, "Unable to create event log: %s\n", strerror(errno));
 419
 420         init_logger_chain();
 421
 422         /* create log channels */
 423         init_logger_chain();
 424         return -1;
 425 }
 426
 427 static void ast_log_vsyslog(int level, const char *file, int line, const char *function, const char *fmt, va_list args) {
 428     char buf[BUFSIZ];
 429
 430     if(level >= SYSLOG_NLEVELS) {
 431             /* we are locked here, so cannot ast_log() */
 432             fprintf(stderr, "ast_log_vsyslog called with bogus level: %d\n", level);
 433             return;
 434     }
 435     if(level == __LOG_VERBOSE) {
 436         snprintf(buf, sizeof(buf), "VERBOSE[%ld]: ", (long)pthread_self());
 437         level = __LOG_DEBUG;
 438     } else {
 439         snprintf(buf, sizeof(buf), "%s[%ld]: %s:%d in %s: ",
 440                  levels[level], (long)pthread_self(), file, line, function);
 441     }
 442     vsnprintf(buf+strlen(buf), sizeof(buf)-strlen(buf), fmt, args);
 443     syslog(syslog_level_map[level], "%s", buf);
 444 }
 445
 446 /*
 447  * send log messages to syslog and/or the console
 448  */
 449 void ast_log(int level, const char *file, int line, const char *function, const char *fmt, ...)
 450 {
 451     struct logchannel *chan;
 452     char buf[BUFSIZ];
 453     time_t t;
 454     struct tm tm;
 455     char date[256];
 456
 457     va_list ap;
 458
 459     if (!option_verbose && !option_debug && (level == __LOG_DEBUG)) {
 460         return;
 461     }
 462
 463     /* begin critical section */
 464     ast_mutex_lock(&loglock);
 465
 466     time(&t);
 467     localtime_r(&t, &tm);
 468     strftime(date, sizeof(date), "%b %e %T", &tm);
 469
 470
 471     if (level == __LOG_EVENT) {
 472             va_start(ap, fmt);
 473
 474             fprintf(eventlog, "%s asterisk[%d]: ", date, getpid());
 475             vfprintf(eventlog, fmt, ap);
 476             fflush(eventlog);
 477
 478             va_end(ap);
 479             ast_mutex_unlock(&loglock);
 480             return;
 481     }
 482
 483     if (logchannels) {
 484         chan = logchannels;
 485         while(chan) {
 486             if (chan->syslog && (chan->logmask & (1 << level))) {
 487                 va_start(ap, fmt);
 488                 ast_log_vsyslog(level, file, line, function, fmt, ap);
 489                 va_end(ap);
 490             } else if ((chan->logmask & (1 << level)) && (chan->console)) {
 491                 char linestr[128];
 492                 char tmp1[80], tmp2[80], tmp3[80], tmp4[80];
 493
 494                 if(level != __LOG_VERBOSE) {
 495                     sprintf(linestr, "%d", line);
 496                     snprintf(buf, sizeof(buf), "%s %s[%ld]: %s:%s %s: ",
 497                              date,
 498                              term_color(tmp1, levels[level], colors[level], 0, sizeof(tmp1)),
 499                              (long)pthread_self(),
 500                              term_color(tmp2, file, COLOR_BRWHITE, 0, sizeof(tmp2)),
 501                              term_color(tmp3, linestr, COLOR_BRWHITE, 0, sizeof(tmp3)),
 502                              term_color(tmp4, function, COLOR_BRWHITE, 0, sizeof(tmp4)));
 503
 504                     ast_console_puts(buf);
 505                     va_start(ap, fmt);
 506                     vsnprintf(buf, sizeof(buf), fmt, ap);
 507                     va_end(ap);
 508                     ast_console_puts(buf);
 509                 }
 510             } else if ((chan->logmask & (1 << level)) && (chan->fileptr)) {
 511                     snprintf(buf, sizeof(buf), "%s %s[%ld]: ", date,
 512                              levels[level], (long)pthread_self());
 513                     fprintf(chan->fileptr, buf);
 514                     va_start(ap, fmt);
 515                     vsnprintf(buf, sizeof(buf), fmt, ap);
 516                     va_end(ap);
 517                     fputs(buf, chan->fileptr);
 518                     fflush(chan->fileptr);
 519             }
 520             chan = chan->next;
 521         }
 522     } else {
 523             /*
 524              * we don't have the logger chain configured yet,
 525              * so just log to stdout
 526              */
 527                 if (level != __LOG_VERBOSE) {
 528                     va_start(ap, fmt);
 529                     vsnprintf(buf, sizeof(buf), fmt, ap);
 530                     va_end(ap);
 531                     fputs(buf, stdout);
 532                 }
 533     }
 534
 535     ast_mutex_unlock(&loglock);
 536     /* end critical section */
 537         if (pending_logger_reload) {
 538             reload_logger(1);
 539             ast_log(LOG_EVENT,"Rotated Logs Per SIGXFSZ\n");
 540             if (option_verbose)
 541                     ast_verbose("Rotated Logs Per SIGXFSZ\n");
 542         }
 543 }
 544
 545 extern void ast_verbose(const char *fmt, ...)
 546 {
 547         static char stuff[4096];
 548         static int pos = 0, opos;
 549         static int replacelast = 0, complete;
 550         struct msglist *m;
 551         struct verb *v;
 552         va_list ap;
 553         va_start(ap, fmt);
 554         ast_mutex_lock(&msglist_lock);
 555         vsnprintf(stuff + pos, sizeof(stuff) - pos, fmt, ap);
 556         opos = pos;
 557         pos = strlen(stuff);
 558         if (fmt[strlen(fmt)-1] == '\n')
 559                 complete = 1;
 560         else
 561                 complete=0;
 562         if (complete) {
 563                 if (msgcnt < MAX_MSG_QUEUE) {
 564                         /* Allocate new structure */
 565                         m = malloc(sizeof(struct msglist));
 566                         msgcnt++;
 567                 } else {
 568                         /* Recycle the oldest entry */
 569                         m = list;
 570                         list = list->next;
 571                         free(m->msg);
 572                 }
 573                 if (m) {
 574                         m->msg = strdup(stuff);
 575                         if (m->msg) {
 576                                 if (last)
 577                                         last->next = m;
 578                                 else
 579                                         list = m;
 580                                 m->next = NULL;
 581                                 last = m;
 582                         } else {
 583                                 msgcnt--;
 584                                 ast_log(LOG_ERROR, "Out of memory\n");
 585                                 free(m);
 586                         }
 587                 }
 588         }
 589         if (verboser) {
 590                 v = verboser;
 591                 while(v) {
 592                         v->verboser(stuff, opos, replacelast, complete);
 593                         v = v->next;
 594                 }
 595         } /* else
 596                 fprintf(stdout, stuff + opos); */
 597
 598         ast_log(LOG_VERBOSE, stuff);
 599
 600         if (fmt[strlen(fmt)-1] != '\n')
 601                 replacelast = 1;
 602         else
 603                 replacelast = pos = 0;
 604         va_end(ap);
 605
 606         ast_mutex_unlock(&msglist_lock);
 607 }
 608
 609 int ast_verbose_dmesg(void (*v)(const char *string, int opos, int replacelast, int complete))
 610 {
 611         struct msglist *m;
 612         m = list;
 613         ast_mutex_lock(&msglist_lock);
 614         while(m) {
 615                 /* Send all the existing entries that we have queued (i.e. they're likely to have missed) */
 616                 v(m->msg, 0, 0, 1);
 617                 m = m->next;
 618         }
 619         ast_mutex_unlock(&msglist_lock);
 620         return 0;
 621 }
 622
 623 int ast_register_verbose(void (*v)(const char *string, int opos, int replacelast, int complete))
 624 {
 625         struct msglist *m;
 626         struct verb *tmp;
 627         /* XXX Should be more flexible here, taking > 1 verboser XXX */
 628         if ((tmp = malloc(sizeof (struct verb)))) {
 629                 tmp->verboser = v;
 630                 ast_mutex_lock(&msglist_lock);
 631                 tmp->next = verboser;
 632                 verboser = tmp;
 633                 m = list;
 634                 while(m) {
 635                         /* Send all the existing entries that we have queued (i.e. they're likely to have missed) */
 636                         v(m->msg, 0, 0, 1);
 637                         m = m->next;
 638                 }
 639                 ast_mutex_unlock(&msglist_lock);
 640                 return 0;
 641         }
 642         return -1;
 643 }
 644
 645 int ast_unregister_verbose(void (*v)(const char *string, int opos, int replacelast, int complete))
 646 {
 647         int res = -1;
 648         struct verb *tmp, *tmpl=NULL;
 649         ast_mutex_lock(&msglist_lock);
 650         tmp = verboser;
 651         while(tmp) {
 652                 if (tmp->verboser == v) {
 653                         if (tmpl)
 654                                 tmpl->next = tmp->next;
 655                         else
 656                                 verboser = tmp->next;
 657                         free(tmp);
 658                         break;
 659                 }
 660                 tmpl = tmp;
 661                 tmp = tmp->next;
 662         }
 663         if (tmp)
 664                 res = 0;
 665         ast_mutex_unlock(&msglist_lock);
 666         return res;
 667 }