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