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