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