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