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