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