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