log.c

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