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