log.c

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