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