log.c

   1 #include "secnet.h"
   2 #include <stdio.h>
   3 #include <string.h>
   4 #include <stdlib.h>
   5 #include <time.h>
   6 #include <errno.h>
   7 #include <syslog.h>
   8 #include <assert.h>
   9 #include <unistd.h>
  10 #include "process.h"
  11 #include "util.h"
  12
  13 bool_t secnet_is_daemon=False;
  14 uint32_t message_level=M_WARNING|M_ERR|M_SECURITY|M_FATAL;
  15 struct log_if *system_log=NULL;
  16
  17 static void vMessageFallback(uint32_t class, const char *message, va_list args)
  18     FORMAT(printf,2,0);
  19 static void vMessageFallback(uint32_t class, const char *message, va_list args)
  20 {
  21     FILE *dest=stdout;
  22     /* Messages go to stdout/stderr */
  23     if (class & message_level) {
  24         if (class&M_FATAL || class&M_ERR || class&M_WARNING) {
  25             dest=stderr;
  26         }
  27         vfprintf(dest,message,args);
  28     }
  29 }
  30
  31 static void vMessage(uint32_t class, const char *message, va_list args)
  32 {
  33 #define MESSAGE_BUFLEN 1023
  34     static char buff[MESSAGE_BUFLEN+1]={0,};
  35     size_t bp;
  36     char *nlp;
  37
  38     if (system_log) {
  39         /* Messages go to the system log interface */
  40         bp=strlen(buff);
  41         assert(bp < MESSAGE_BUFLEN);
  42         vsnprintf(buff+bp,MESSAGE_BUFLEN-bp,message,args);
  43         buff[sizeof(buff)-2] = '\n';
  44         buff[sizeof(buff)-1] = '\0';
  45         /* Each line is sent separately */
  46         while ((nlp=strchr(buff,'\n'))) {
  47             *nlp=0;
  48             slilog(system_log,class,"%s",buff);
  49             memmove(buff,nlp+1,strlen(nlp+1)+1);
  50         }
  51     } else {
  52         vMessageFallback(class,message,args);
  53     }
  54 }
  55
  56 void Message(uint32_t class, const char *message, ...)
  57 {
  58     va_list ap;
  59
  60     va_start(ap,message);
  61     vMessage(class,message,ap);
  62     va_end(ap);
  63 }
  64
  65 static void MessageFallback(uint32_t class, const char *message, ...)
  66     FORMAT(printf,2,3);
  67 static void MessageFallback(uint32_t class, const char *message, ...)
  68 {
  69     va_list ap;
  70
  71     va_start(ap,message);
  72     vMessageFallback(class,message,ap);
  73     va_end(ap);
  74 }
  75
  76 static NORETURN(vfatal(int status, bool_t perror, const char *message,
  77                        va_list args));
  78
  79 static void vfatal(int status, bool_t perror, const char *message,
  80                    va_list args)
  81 {
  82     int err;
  83
  84     err=errno;
  85
  86     enter_phase(PHASE_SHUTDOWN);
  87     Message(M_FATAL, "secnet fatal error: ");
  88     vMessage(M_FATAL, message, args);
  89     if (perror)
  90         Message(M_FATAL, ": %s\n",strerror(err));
  91     else
  92         Message(M_FATAL, "\n");
  93     exit(status);
  94 }
  95
  96 void fatal(const char *message, ...)
  97 {
  98     va_list args;
  99     va_start(args,message);
 100     vfatal(current_phase,False,message,args);
 101     va_end(args);
 102 }
 103
 104 void fatal_status(int status, const char *message, ...)
 105 {
 106     va_list args;
 107     va_start(args,message);
 108     vfatal(status,False,message,args);
 109     va_end(args);
 110 }
 111
 112 void fatal_perror(const char *message, ...)
 113 {
 114     va_list args;
 115     va_start(args,message);
 116     vfatal(current_phase,True,message,args);
 117     va_end(args);
 118 }
 119
 120 void fatal_perror_status(int status, const char *message, ...)
 121 {
 122     va_list args;
 123     va_start(args,message);
 124     vfatal(status,True,message,args);
 125     va_end(args);
 126 }
 127
 128 void vcfgfatal_maybefile(FILE *maybe_f /* or 0 */, struct cloc loc,
 129                          cstring_t facility, const char *message, va_list args)
 130 {
 131     enter_phase(PHASE_SHUTDOWN);
 132
 133     if (maybe_f && ferror(maybe_f)) {
 134         assert(loc.file);
 135         Message(M_FATAL, "error reading config file (%s, %s): %s",
 136                 facility, loc.file, strerror(errno));
 137     } else if (maybe_f && feof(maybe_f)) {
 138         assert(loc.file);
 139         Message(M_FATAL, "unexpected end of config file (%s, %s)",
 140                 facility, loc.file);
 141     } else if (loc.file && loc.line) {
 142         Message(M_FATAL, "config error (%s, %s:%d): ",facility,loc.file,
 143                 loc.line);
 144     } else if (!loc.file && loc.line) {
 145         Message(M_FATAL, "config error (%s, line %d): ",facility,loc.line);
 146     } else {
 147         Message(M_FATAL, "config error (%s): ",facility);
 148     }
 149
 150     vMessage(M_FATAL,message,args);
 151     exit(current_phase);
 152 }
 153
 154 void cfgfatal_maybefile(FILE *maybe_f, struct cloc loc, cstring_t facility,
 155                         const char *message, ...)
 156 {
 157     va_list args;
 158
 159     va_start(args,message);
 160     vcfgfatal_maybefile(maybe_f,loc,facility,message,args);
 161     va_end(args);
 162 }
 163
 164 void cfgfatal(struct cloc loc, cstring_t facility, const char *message, ...)
 165 {
 166     va_list args;
 167
 168     va_start(args,message);
 169     vcfgfatal_maybefile(0,loc,facility,message,args);
 170     va_end(args);
 171 }
 172
 173 void cfgfile_postreadcheck(struct cloc loc, FILE *f)
 174 {
 175     assert(loc.file);
 176     if (ferror(f)) {
 177         Message(M_FATAL, "error reading config file (%s): %s\n",
 178                 loc.file, strerror(errno));
 179         exit(current_phase);
 180     } else if (feof(f)) {
 181         Message(M_FATAL, "unexpected end of config file (%s)\n", loc.file);
 182         exit(current_phase);
 183     }
 184 }
 185
 186 /* Take a list of log closures and merge them */
 187 struct loglist {
 188     struct log_if *l;
 189     struct loglist *next;
 190 };
 191
 192 static void log_vmulti(void *sst, int class, const char *message, va_list args)
 193 {
 194     struct loglist *st=sst, *i;
 195
 196     if (secnet_is_daemon) {
 197         for (i=st; i; i=i->next) {
 198             vslilog(i->l,class,message,args);
 199         }
 200     } else {
 201         vMessage(class,message,args);
 202         Message(class,"\n");
 203     }
 204 }
 205
 206 static void log_multi(void *st, int priority, const char *message, ...)
 207     FORMAT(printf,3,4);
 208 static void log_multi(void *st, int priority, const char *message, ...)
 209 {
 210     va_list ap;
 211
 212     va_start(ap,message);
 213     log_vmulti(st,priority,message,ap);
 214     va_end(ap);
 215 }
 216
 217 struct log_if *init_log(list_t *ll)
 218 {
 219     int i=0;
 220     item_t *item;
 221     closure_t *cl;
 222     struct loglist *l=NULL, *n;
 223     struct log_if *r;
 224
 225     if (list_length(ll)==1) {
 226         item=list_elem(ll,0);
 227         cl=item->data.closure;
 228         if (cl->type!=CL_LOG) {
 229             cfgfatal(item->loc,"init_log","closure is not a logger");
 230         }
 231         return cl->interface;
 232     }
 233     while ((item=list_elem(ll,i++))) {
 234         if (item->type!=t_closure) {
 235             cfgfatal(item->loc,"init_log","item is not a closure");
 236         }
 237         cl=item->data.closure;
 238         if (cl->type!=CL_LOG) {
 239             cfgfatal(item->loc,"init_log","closure is not a logger");
 240         }
 241         n=safe_malloc(sizeof(*n),"init_log");
 242         n->l=cl->interface;
 243         n->next=l;
 244         l=n;
 245     }
 246     if (!l) {
 247         fatal("init_log: no log");
 248     }
 249     r=safe_malloc(sizeof(*r), "init_log");
 250     r->st=l;
 251     r->logfn=log_multi;
 252     r->vlogfn=log_vmulti;
 253     return r;
 254 }
 255
 256 struct logfile {
 257     closure_t cl;
 258     struct log_if ops;
 259     struct cloc loc;
 260     string_t logfile;
 261     uint32_t level;
 262     FILE *f;
 263 };
 264
 265 static cstring_t months[]={
 266     "Jan","Feb","Mar","Apr","May","Jun","Jul","Aug","Sep","Oct","Nov","Dec"};
 267
 268 static void logfile_vlog(void *sst, int class, const char *message,
 269                          va_list args)
 270 {
 271     struct logfile *st=sst;
 272     time_t t;
 273     struct tm *tm;
 274
 275     if (secnet_is_daemon && st->f) {
 276         if (class&st->level) {
 277             t=time(NULL);
 278             tm=localtime(&t);
 279             fprintf(st->f,"%s %2d %02d:%02d:%02d ",
 280                     months[tm->tm_mon],tm->tm_mday,tm->tm_hour,tm->tm_min,
 281                     tm->tm_sec);
 282             vfprintf(st->f,message,args);
 283             fprintf(st->f,"\n");
 284             fflush(st->f);
 285         }
 286     } else {
 287         vMessageFallback(class,message,args);
 288         MessageFallback(class,"\n");
 289     }
 290 }
 291
 292 static void logfile_log(void *state, int class, const char *message, ...)
 293     FORMAT(printf,3,4);
 294 static void logfile_log(void *state, int class, const char *message, ...)
 295 {
 296     va_list ap;
 297
 298     va_start(ap,message);
 299     logfile_vlog(state,class,message,ap);
 300     va_end(ap);
 301 }
 302
 303 static void logfile_hup_notify(void *sst, int signum)
 304 {
 305     struct logfile *st=sst;
 306     FILE *f;
 307     f=fopen(st->logfile,"a");
 308     if (!f) {
 309         logfile_log(st,M_FATAL,"received SIGHUP, but could not reopen "
 310                     "logfile: %s",strerror(errno));
 311     } else {
 312         fclose(st->f);
 313         st->f=f;
 314         logfile_log(st,M_INFO,"received SIGHUP");
 315     }
 316 }
 317
 318 static void logfile_phase_hook(void *sst, uint32_t new_phase)
 319 {
 320     struct logfile *st=sst;
 321     FILE *f;
 322
 323     if (background) {
 324         f=fopen(st->logfile,"a");
 325         if (!f) fatal_perror("logfile (%s:%d): cannot open \"%s\"",
 326                              st->loc.file,st->loc.line,st->logfile);
 327         st->f=f;
 328         request_signal_notification(SIGHUP, logfile_hup_notify,st);
 329     }
 330 }
 331
 332 static struct flagstr message_class_table[]={
 333     { "debug-config", M_DEBUG_CONFIG },
 334     { "debug-phase", M_DEBUG_PHASE },
 335     { "debug", M_DEBUG },
 336     { "all-debug", M_DEBUG|M_DEBUG_PHASE|M_DEBUG_CONFIG },
 337     { "info", M_INFO },
 338     { "notice", M_NOTICE },
 339     { "warning", M_WARNING },
 340     { "error", M_ERR },
 341     { "security", M_SECURITY },
 342     { "fatal", M_FATAL },
 343     { "default", M_WARNING|M_ERR|M_SECURITY|M_FATAL },
 344     { "verbose", M_INFO|M_NOTICE|M_WARNING|M_ERR|M_SECURITY|M_FATAL },
 345     { "quiet", M_FATAL },
 346     { NULL, 0 }
 347 };
 348
 349 static list_t *logfile_apply(closure_t *self, struct cloc loc, dict_t *context,
 350                              list_t *args)
 351 {
 352     struct logfile *st;
 353     item_t *item;
 354     dict_t *dict;
 355
 356     /* We should defer opening the logfile until the getresources
 357        phase.  We should defer writing into the logfile until after we
 358        become a daemon. */
 359
 360     st=safe_malloc(sizeof(*st),"logfile_apply");
 361     st->cl.description="logfile";
 362     st->cl.type=CL_LOG;
 363     st->cl.apply=NULL;
 364     st->cl.interface=&st->ops;
 365     st->ops.st=st;
 366     st->ops.logfn=logfile_log;
 367     st->ops.vlogfn=logfile_vlog;
 368     st->loc=loc;
 369     st->f=NULL;
 370
 371     item=list_elem(args,0);
 372     if (!item || item->type!=t_dict) {
 373         cfgfatal(loc,"logfile","argument must be a dictionary\n");
 374     }
 375     dict=item->data.dict;
 376
 377     st->logfile=dict_read_string(dict,"filename",True,"logfile",loc);
 378     st->level=string_list_to_word(dict_lookup(dict,"class"),
 379                                        message_class_table,"logfile");
 380
 381     add_hook(PHASE_GETRESOURCES,logfile_phase_hook,st);
 382
 383     return new_closure(&st->cl);
 384 }
 385
 386 struct syslog {
 387     closure_t cl;
 388     struct log_if ops;
 389     string_t ident;
 390     int facility;
 391     bool_t open;
 392 };
 393
 394 static int msgclass_to_syslogpriority(uint32_t m)
 395 {
 396     switch (m) {
 397     case M_DEBUG_CONFIG: return LOG_DEBUG;
 398     case M_DEBUG_PHASE: return LOG_DEBUG;
 399     case M_DEBUG: return LOG_DEBUG;
 400     case M_INFO: return LOG_INFO;
 401     case M_NOTICE: return LOG_NOTICE;
 402     case M_WARNING: return LOG_WARNING;
 403     case M_ERR: return LOG_ERR;
 404     case M_SECURITY: return LOG_CRIT;
 405     case M_FATAL: return LOG_EMERG;
 406     default: return LOG_NOTICE;
 407     }
 408 }
 409
 410 static void syslog_vlog(void *sst, int class, const char *message,
 411                          va_list args)
 412     FORMAT(printf,3,0);
 413 static void syslog_vlog(void *sst, int class, const char *message,
 414                          va_list args)
 415 {
 416     struct syslog *st=sst;
 417
 418     if (st->open)
 419         vsyslog(msgclass_to_syslogpriority(class),message,args);
 420     else {
 421         vMessageFallback(class,message,args);
 422         MessageFallback(class,"\n");
 423     }
 424 }
 425
 426 static void syslog_log(void *sst, int priority, const char *message, ...)
 427     FORMAT(printf,3,4);
 428 static void syslog_log(void *sst, int priority, const char *message, ...)
 429 {
 430     va_list ap;
 431
 432     va_start(ap,message);
 433     syslog_vlog(sst,priority,message,ap);
 434     va_end(ap);
 435 }
 436
 437 static struct flagstr syslog_facility_table[]={
 438 #ifdef LOG_AUTH
 439     { "auth", LOG_AUTH },
 440 #endif
 441 #ifdef LOG_AUTHPRIV
 442     { "authpriv", LOG_AUTHPRIV },
 443 #endif
 444     { "cron", LOG_CRON },
 445     { "daemon", LOG_DAEMON },
 446     { "kern", LOG_KERN },
 447     { "local0", LOG_LOCAL0 },
 448     { "local1", LOG_LOCAL1 },
 449     { "local2", LOG_LOCAL2 },
 450     { "local3", LOG_LOCAL3 },
 451     { "local4", LOG_LOCAL4 },
 452     { "local5", LOG_LOCAL5 },
 453     { "local6", LOG_LOCAL6 },
 454     { "local7", LOG_LOCAL7 },
 455     { "lpr", LOG_LPR },
 456     { "mail", LOG_MAIL },
 457     { "news", LOG_NEWS },
 458     { "syslog", LOG_SYSLOG },
 459     { "user", LOG_USER },
 460     { "uucp", LOG_UUCP },
 461     { NULL, 0 }
 462 };
 463
 464 static void syslog_phase_hook(void *sst, uint32_t newphase)
 465 {
 466     struct syslog *st=sst;
 467
 468     if (background) {
 469         openlog(st->ident,0,st->facility);
 470         st->open=True;
 471     }
 472 }
 473
 474 static list_t *syslog_apply(closure_t *self, struct cloc loc, dict_t *context,
 475                             list_t *args)
 476 {
 477     struct syslog *st;
 478     dict_t *d;
 479     item_t *item;
 480     string_t facstr;
 481
 482     st=safe_malloc(sizeof(*st),"syslog_apply");
 483     st->cl.description="syslog";
 484     st->cl.type=CL_LOG;
 485     st->cl.apply=NULL;
 486     st->cl.interface=&st->ops;
 487     st->ops.st=st;
 488     st->ops.logfn=syslog_log;
 489     st->ops.vlogfn=syslog_vlog;
 490
 491     item=list_elem(args,0);
 492     if (!item || item->type!=t_dict)
 493         cfgfatal(loc,"syslog","parameter must be a dictionary\n");
 494     d=item->data.dict;
 495
 496     st->ident=dict_read_string(d, "ident", False, "syslog", loc);
 497     facstr=dict_read_string(d, "facility", True, "syslog", loc);
 498     st->facility=string_to_word(facstr,loc,
 499                                 syslog_facility_table,"syslog");
 500     st->open=False;
 501     add_hook(PHASE_GETRESOURCES,syslog_phase_hook,st);
 502
 503     return new_closure(&st->cl);
 504 }
 505
 506 /* Read from a fd and output to a log.  This is a quick hack to
 507    support logging stderr, and needs code adding to tidy up before it
 508    can be used for anything else. */
 509 #define FDLOG_BUFSIZE 1024
 510 struct fdlog {
 511     struct log_if *log;
 512     int fd;
 513     cstring_t prefix;
 514     string_t buffer;
 515     int i;
 516     bool_t finished;
 517 };
 518
 519 static int log_from_fd_beforepoll(void *sst, struct pollfd *fds, int *nfds_io,
 520                                   int *timeout_io)
 521 {
 522     struct fdlog *st=sst;
 523     if (!st->finished) {
 524         *nfds_io=1;
 525         fds[0].fd=st->fd;
 526         fds[0].events=POLLIN;
 527     }
 528     return 0;
 529 }
 530
 531 static void log_from_fd_afterpoll(void *sst, struct pollfd *fds, int nfds)
 532 {
 533     struct fdlog *st=sst;
 534     int r,remain,i;
 535
 536     if (nfds==0) return;
 537     if (fds[0].revents&POLLERR) {
 538         st->finished=True;
 539     }
 540     if (fds[0].revents&POLLIN) {
 541         remain=FDLOG_BUFSIZE-st->i-1;
 542         if (remain<=0) {
 543             st->buffer[FDLOG_BUFSIZE-1]=0;
 544             slilog(st->log,M_WARNING,"%s: overlong line: %s",
 545                          st->prefix,st->buffer);
 546             st->i=0;
 547             remain=FDLOG_BUFSIZE-1;
 548         }
 549         r=read(st->fd,st->buffer+st->i,remain);
 550         if (r>0) {
 551             st->i+=r;
 552             for (i=0; i<st->i; i++) {
 553                 if (st->buffer[i]=='\n') {
 554                     st->buffer[i]=0;
 555                     slilog(st->log,M_INFO,"%s: %s",
 556                                  st->prefix,st->buffer);
 557                     i++;
 558                     memmove(st->buffer,st->buffer+i,st->i-i);
 559                     st->i-=i;
 560                     i=-1;
 561                 }
 562             }
 563         } else {
 564             Message(M_WARNING,"log_from_fd: %s\n",strerror(errno));
 565             st->finished=True;
 566         }
 567     }
 568 }
 569
 570 void log_from_fd(int fd, cstring_t prefix, struct log_if *log)
 571 {
 572     struct fdlog *st;
 573
 574     st=safe_malloc(sizeof(*st),"log_from_fd");
 575     st->log=log;
 576     st->fd=fd;
 577     st->prefix=prefix;
 578     st->buffer=safe_malloc(FDLOG_BUFSIZE,"log_from_fd");
 579     st->i=0;
 580     st->finished=False;
 581
 582     register_for_poll(st,log_from_fd_beforepoll,log_from_fd_afterpoll,1,
 583                       prefix);
 584 }
 585
 586 void log_module(dict_t *dict)
 587 {
 588     add_closure(dict,"logfile",logfile_apply);
 589     add_closure(dict,"syslog",syslog_apply);
 590 }