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