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