X-Git-Url: https://git.distorted.org.uk/~mdw/secnet/blobdiff_plain/7138d0c54cd2212439434d27cb2d6ea775c3039b..refs/heads/master:/log.c diff --git a/log.c b/log.c index 0981506..d5669ca 100644 --- a/log.c +++ b/log.c @@ -1,3 +1,21 @@ +/* + * This file is part of secnet. + * See README for full list of copyright holders. + * + * secnet is free software; you can redistribute it and/or modify it + * under the terms of the GNU General Public License as published by + * the Free Software Foundation; either version 3 of the License, or + * (at your option) any later version. + * + * secnet is distributed in the hope that it will be useful, but + * WITHOUT ANY WARRANTY; without even the implied warranty of + * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU + * General Public License for more details. + * + * You should have received a copy of the GNU General Public License + * version 3 along with secnet; if not, see + * https://www.gnu.org/licenses/gpl.html. + */ #include "secnet.h" #include #include @@ -5,42 +23,41 @@ #include #include #include +#include +#include #include "process.h" +#include "util.h" bool_t secnet_is_daemon=False; -uint32_t message_level=M_WARNING|M_ERROR|M_SECURITY|M_FATAL; +uint32_t message_level=M_WARNING|M_ERR|M_SECURITY|M_FATAL; struct log_if *system_log=NULL; -static void vMessage(uint32_t class, char *message, va_list args) +FORMAT(printf,2,0) +static void vMessageFallback(uint32_t class, const char *message, va_list args) { FILE *dest=stdout; -#define MESSAGE_BUFLEN 1023 - static char buff[MESSAGE_BUFLEN+1]={0,}; - uint32_t bp; - char *nlp; + /* Messages go to stdout/stderr */ + if (class & message_level) { + if (class&M_FATAL || class&M_ERR || class&M_WARNING) { + dest=stderr; + } + vfprintf(dest,message,args); + } +} - if (secnet_is_daemon) { +FORMAT(printf,2,0) +static void vMessage(uint32_t class, const char *message, va_list args) +{ + + if (system_log) { /* Messages go to the system log interface */ - bp=strlen(buff); - vsnprintf(buff+bp,MESSAGE_BUFLEN-bp,message,args); - /* Each line is sent separately */ - while ((nlp=strchr(buff,'\n'))) { - *nlp=0; - log(system_log,class,buff); - memmove(buff,nlp+1,strlen(nlp+1)+1); - } + vslilog_part(system_log, class, message, args); } else { - /* Messages go to stdout/stderr */ - if (class & message_level) { - if (class&M_FATAL || class&M_ERROR || class&M_WARNING) { - dest=stderr; - } - vfprintf(dest,message,args); - } + vMessageFallback(class,message,args); } } -void Message(uint32_t class, char *message, ...) +void Message(uint32_t class, const char *message, ...) { va_list ap; @@ -49,26 +66,38 @@ void Message(uint32_t class, char *message, ...) va_end(ap); } -static void vfatal(int status, bool_t perror, char *message, va_list args) +FORMAT(printf,2,3) +static void MessageFallback(uint32_t class, const char *message, ...) +{ + va_list ap; + + va_start(ap,message); + vMessageFallback(class,message,ap); + va_end(ap); +} + +static NORETURN(vfatal(int status, bool_t perror, const char *message, + va_list args)); + +FORMAT(printf,3,0) +static void vfatal(int status, bool_t perror, const char *message, + va_list args) { int err; err=errno; enter_phase(PHASE_SHUTDOWN); - if (perror) { - Message(M_FATAL, "secnet fatal error: "); - vMessage(M_FATAL, message, args); + Message(M_FATAL, "secnet fatal error: "); + vMessage(M_FATAL, message, args); + if (perror) Message(M_FATAL, ": %s\n",strerror(err)); - } - else { - Message(M_FATAL, "secnet fatal error: "); - vMessage(M_FATAL,message,args); - } + else + Message(M_FATAL, "\n"); exit(status); } -void fatal(char *message, ...) +void fatal(const char *message, ...) { va_list args; va_start(args,message); @@ -76,7 +105,7 @@ void fatal(char *message, ...) va_end(args); } -void fatal_status(int status, char *message, ...) +void fatal_status(int status, const char *message, ...) { va_list args; va_start(args,message); @@ -84,7 +113,7 @@ void fatal_status(int status, char *message, ...) va_end(args); } -void fatal_perror(char *message, ...) +void fatal_perror(const char *message, ...) { va_list args; va_start(args,message); @@ -92,7 +121,7 @@ void fatal_perror(char *message, ...) va_end(args); } -void fatal_perror_status(int status, char *message, ...) +void fatal_perror_status(int status, const char *message, ...) { va_list args; va_start(args,message); @@ -100,15 +129,20 @@ void fatal_perror_status(int status, char *message, ...) va_end(args); } -void cfgfatal(struct cloc loc, string_t facility, char *message, ...) +void vcfgfatal_maybefile(FILE *maybe_f /* or 0 */, struct cloc loc, + cstring_t facility, const char *message, va_list args) { - va_list args; - - va_start(args,message); - enter_phase(PHASE_SHUTDOWN); - if (loc.file && loc.line) { + if (maybe_f && ferror(maybe_f)) { + assert(loc.file); + Message(M_FATAL, "error reading config file (%s, %s): %s", + facility, loc.file, strerror(errno)); + } else if (maybe_f && feof(maybe_f)) { + assert(loc.file); + Message(M_FATAL, "unexpected end of config file (%s, %s)", + facility, loc.file); + } else if (loc.file && loc.line) { Message(M_FATAL, "config error (%s, %s:%d): ",facility,loc.file, loc.line); } else if (!loc.file && loc.line) { @@ -118,23 +152,55 @@ void cfgfatal(struct cloc loc, string_t facility, char *message, ...) } vMessage(M_FATAL,message,args); - va_end(args); exit(current_phase); } +void cfgfatal_maybefile(FILE *maybe_f, struct cloc loc, cstring_t facility, + const char *message, ...) +{ + va_list args; + + va_start(args,message); + vcfgfatal_maybefile(maybe_f,loc,facility,message,args); + va_end(args); +} + +void cfgfatal(struct cloc loc, cstring_t facility, const char *message, ...) +{ + va_list args; + + va_start(args,message); + vcfgfatal_maybefile(0,loc,facility,message,args); + va_end(args); +} + +void cfgfile_postreadcheck(struct cloc loc, FILE *f) +{ + assert(loc.file); + if (ferror(f)) { + Message(M_FATAL, "error reading config file (%s): %s\n", + loc.file, strerror(errno)); + exit(current_phase); + } else if (feof(f)) { + Message(M_FATAL, "unexpected end of config file (%s)\n", loc.file); + exit(current_phase); + } +} + /* Take a list of log closures and merge them */ struct loglist { struct log_if *l; struct loglist *next; }; -static void log_vmulti(void *sst, int class, char *message, va_list args) +FORMAT(printf, 3, 0) +static void log_vmulti(void *sst, int class, const char *message, va_list args) { struct loglist *st=sst, *i; if (secnet_is_daemon) { for (i=st; i; i=i->next) { - i->l->vlog(i->l->st,class,message,args); + vslilog(i->l,class,message,args); } } else { vMessage(class,message,args); @@ -142,13 +208,58 @@ static void log_vmulti(void *sst, int class, char *message, va_list args) } } -static void log_multi(void *st, int priority, char *message, ...) +FORMAT(printf, 6, 0) +void lg_vperror(struct log_if *lg, const char *desc, struct cloc *loc, + int class, int errnoval, const char *fmt, va_list al) { - va_list ap; + int status=current_phase; + int esave=errno; - va_start(ap,message); - log_vmulti(st,priority,message,ap); - va_end(ap); + if (!lg) + lg=system_log; + + if (class & M_FATAL) + enter_phase(PHASE_SHUTDOWN); + + slilog_part(lg,class,"%s",desc); + if (loc) + slilog_part(lg,class," (%s:%d)",loc->file,loc->line); + slilog_part(lg,class,": "); + vslilog_part(lg,class,fmt,al); + if (errnoval) + slilog_part(lg,class,": %s",strerror(errnoval)); + slilog_part(lg,class,"\n"); + + if (class & M_FATAL) + exit(status); + + errno=esave; +} + +void lg_perror(struct log_if *lg, const char *desc, struct cloc *loc, + int class, int errnoval, const char *fmt, ...) +{ + va_list al; + va_start(al,fmt); + lg_vperror(lg,desc,loc,class,errnoval,fmt,al); + va_end(al); +} + +void lg_exitstatus(struct log_if *lg, const char *desc, struct cloc *loc, + int class, int status, const char *progname) +{ + if (!status) + lg_perror(lg,desc,loc,class,0,"%s exited",progname); + else if (WIFEXITED(status)) + lg_perror(lg,desc,loc,class,0,"%s exited with error exit status %d", + progname,WEXITSTATUS(status)); + else if (WIFSIGNALED(status)) + lg_perror(lg,desc,loc,class,0,"%s died due to fatal signal %s (%d)%s", + progname,strsignal(WTERMSIG(status)),WTERMSIG(status), + WCOREDUMP(status)?" (core dumped)":""); + else + lg_perror(lg,desc,loc,class,0,"%s died with unknown wait status %d", + progname,status); } struct log_if *init_log(list_t *ll) @@ -175,7 +286,7 @@ struct log_if *init_log(list_t *ll) if (cl->type!=CL_LOG) { cfgfatal(item->loc,"init_log","closure is not a logger"); } - n=safe_malloc(sizeof(*n),"init_log"); + NEW(n); n->l=cl->interface; n->next=l; l=n; @@ -183,10 +294,10 @@ struct log_if *init_log(list_t *ll) if (!l) { fatal("init_log: no log"); } - r=safe_malloc(sizeof(*r), "init_log"); + NEW(r); r->st=l; - r->log=log_multi; - r->vlog=log_vmulti; + r->vlogfn=log_vmulti; + r->buff[0]=0; return r; } @@ -197,40 +308,54 @@ struct logfile { string_t logfile; uint32_t level; FILE *f; + bool_t forked; }; -static string_t months[]={ +static cstring_t months[]={ "Jan","Feb","Mar","Apr","May","Jun","Jul","Aug","Sep","Oct","Nov","Dec"}; -static void logfile_vlog(void *sst, int class, char *message, va_list args) +FORMAT(printf, 3, 0) +static void logfile_vlog(void *sst, int class, const char *message, + va_list args) { struct logfile *st=sst; time_t t; struct tm *tm; + char pidbuf[20]; - if (secnet_is_daemon) { + if (st->forked) { + pid_t us=getpid(); + snprintf(pidbuf,sizeof(pidbuf),"[%ld] ",(long)us); + } else { + pidbuf[0]=0; + } + + if (secnet_is_daemon && st->f) { if (class&st->level) { t=time(NULL); tm=localtime(&t); - fprintf(st->f,"%s %2d %02d:%02d:%02d ", + fprintf(st->f,"%s %2d %02d:%02d:%02d %s", months[tm->tm_mon],tm->tm_mday,tm->tm_hour,tm->tm_min, - tm->tm_sec); + tm->tm_sec, + pidbuf); vfprintf(st->f,message,args); fprintf(st->f,"\n"); fflush(st->f); } } else { - vMessage(class,message,args); - Message(class,"\n"); + if (pidbuf[0]) MessageFallback(class,"%s",pidbuf); + vMessageFallback(class,message,args); + MessageFallback(class,"\n"); } } -static void logfile_log(void *state, int priority, char *message, ...) +FORMAT(printf,3,4) +static void logfile_log(void *state, int class, const char *message, ...) { va_list ap; va_start(ap,message); - logfile_vlog(state,priority,message,ap); + logfile_vlog(state,class,message,ap); va_end(ap); } @@ -263,6 +388,12 @@ static void logfile_phase_hook(void *sst, uint32_t new_phase) } } +static void logfile_childpersist_hook(void *sst, uint32_t new_phase) +{ + struct logfile *st=sst; + st->forked=1; +} + static struct flagstr message_class_table[]={ { "debug-config", M_DEBUG_CONFIG }, { "debug-phase", M_DEBUG_PHASE }, @@ -271,11 +402,11 @@ static struct flagstr message_class_table[]={ { "info", M_INFO }, { "notice", M_NOTICE }, { "warning", M_WARNING }, - { "error", M_ERROR }, + { "error", M_ERR }, { "security", M_SECURITY }, { "fatal", M_FATAL }, - { "default", M_WARNING|M_ERROR|M_SECURITY|M_FATAL }, - { "verbose", M_INFO|M_NOTICE|M_WARNING|M_ERROR|M_SECURITY|M_FATAL }, + { "default", M_WARNING|M_ERR|M_SECURITY|M_FATAL }, + { "verbose", M_INFO|M_NOTICE|M_WARNING|M_ERR|M_SECURITY|M_FATAL }, { "quiet", M_FATAL }, { NULL, 0 } }; @@ -291,16 +422,17 @@ static list_t *logfile_apply(closure_t *self, struct cloc loc, dict_t *context, phase. We should defer writing into the logfile until after we become a daemon. */ - st=safe_malloc(sizeof(*st),"logfile_apply"); + NEW(st); st->cl.description="logfile"; st->cl.type=CL_LOG; st->cl.apply=NULL; st->cl.interface=&st->ops; st->ops.st=st; - st->ops.log=logfile_log; - st->ops.vlog=logfile_vlog; + st->ops.vlogfn=logfile_vlog; + st->ops.buff[0]=0; st->loc=loc; - st->f=stderr; + st->f=NULL; + st->forked=0; item=list_elem(args,0); if (!item || item->type!=t_dict) { @@ -313,6 +445,7 @@ static list_t *logfile_apply(closure_t *self, struct cloc loc, dict_t *context, message_class_table,"logfile"); add_hook(PHASE_GETRESOURCES,logfile_phase_hook,st); + add_hook(PHASE_CHILDPERSIST,logfile_childpersist_hook,st); return new_closure(&st->cl); } @@ -334,14 +467,17 @@ static int msgclass_to_syslogpriority(uint32_t m) case M_INFO: return LOG_INFO; case M_NOTICE: return LOG_NOTICE; case M_WARNING: return LOG_WARNING; - case M_ERROR: return LOG_ERR; + case M_ERR: return LOG_ERR; case M_SECURITY: return LOG_CRIT; case M_FATAL: return LOG_EMERG; default: return LOG_NOTICE; } } -static void syslog_vlog(void *sst, int class, char *message, +static void syslog_vlog(void *sst, int class, const char *message, + va_list args) + FORMAT(printf,3,0); +static void syslog_vlog(void *sst, int class, const char *message, va_list args) { struct syslog *st=sst; @@ -349,22 +485,18 @@ static void syslog_vlog(void *sst, int class, char *message, if (st->open) vsyslog(msgclass_to_syslogpriority(class),message,args); else { - vMessage(class,message,args); - Message(class,"\n"); + vMessageFallback(class,message,args); + MessageFallback(class,"\n"); } } -static void syslog_log(void *sst, int priority, char *message, ...) -{ - va_list ap; - - va_start(ap,message); - syslog_vlog(sst,priority,message,ap); - va_end(ap); -} - static struct flagstr syslog_facility_table[]={ +#ifdef LOG_AUTH + { "auth", LOG_AUTH }, +#endif +#ifdef LOG_AUTHPRIV { "authpriv", LOG_AUTHPRIV }, +#endif { "cron", LOG_CRON }, { "daemon", LOG_DAEMON }, { "kern", LOG_KERN }, @@ -390,7 +522,9 @@ static void syslog_phase_hook(void *sst, uint32_t newphase) struct syslog *st=sst; if (background) { - openlog(st->ident,0,st->facility); + openlog(st->ident, + newphase==PHASE_CHILDPERSIST ? LOG_PID : 0, + st->facility); st->open=True; } } @@ -403,14 +537,14 @@ static list_t *syslog_apply(closure_t *self, struct cloc loc, dict_t *context, item_t *item; string_t facstr; - st=safe_malloc(sizeof(*st),"syslog_apply"); + NEW(st); st->cl.description="syslog"; st->cl.type=CL_LOG; st->cl.apply=NULL; st->cl.interface=&st->ops; st->ops.st=st; - st->ops.log=syslog_log; - st->ops.vlog=syslog_vlog; + st->ops.vlogfn=syslog_vlog; + st->ops.buff[0]=0; item=list_elem(args,0); if (!item || item->type!=t_dict) @@ -423,11 +557,96 @@ static list_t *syslog_apply(closure_t *self, struct cloc loc, dict_t *context, syslog_facility_table,"syslog"); st->open=False; add_hook(PHASE_GETRESOURCES,syslog_phase_hook,st); + add_hook(PHASE_CHILDPERSIST,syslog_phase_hook,st); return new_closure(&st->cl); } -init_module log_module; +/* Read from a fd and output to a log. This is a quick hack to + support logging stderr, and needs code adding to tidy up before it + can be used for anything else. */ +#define FDLOG_BUFSIZE 1024 +struct fdlog { + struct log_if *log; + int fd; + cstring_t prefix; + string_t buffer; + int i; + bool_t finished; +}; + +static int log_from_fd_beforepoll(void *sst, struct pollfd *fds, int *nfds_io, + int *timeout_io) +{ + struct fdlog *st=sst; + if (!st->finished) { + BEFOREPOLL_WANT_FDS(1); + fds[0].fd=st->fd; + fds[0].events=POLLIN; + } else { + BEFOREPOLL_WANT_FDS(0); + } + return 0; +} + +static void log_from_fd_afterpoll(void *sst, struct pollfd *fds, int nfds) +{ + struct fdlog *st=sst; + int r,remain,i; + + if (nfds==0) return; + if (fds[0].revents&POLLERR) { + st->finished=True; + } + if (fds[0].revents&POLLIN) { + remain=FDLOG_BUFSIZE-st->i-1; + if (remain<=0) { + st->buffer[FDLOG_BUFSIZE-1]=0; + slilog(st->log,M_WARNING,"%s: overlong line: %s", + st->prefix,st->buffer); + st->i=0; + remain=FDLOG_BUFSIZE-1; + } + r=read(st->fd,st->buffer+st->i,remain); + if (r>0) { + st->i+=r; + for (i=0; ii; i++) { + if (st->buffer[i]=='\n') { + st->buffer[i]=0; + slilog(st->log,M_INFO,"%s: %s", + st->prefix,st->buffer); + i++; + memmove(st->buffer,st->buffer+i,st->i-i); + st->i-=i; + i=-1; + } + } + } else if (errno==EINTR || iswouldblock(errno)) { + } else { + Message(M_WARNING,"log_from_fd: %s\n",strerror(errno)); + st->finished=True; + } + } +} + +void log_from_fd(int fd, cstring_t prefix, struct log_if *log) +{ + struct fdlog *st; + + NEW(st); + st->log=log; + st->fd=fd; + st->prefix=prefix; + st->buffer=safe_malloc(FDLOG_BUFSIZE,"log_from_fd"); + st->i=0; + st->finished=False; + + setnonblock(st->fd); + + register_for_poll(st,log_from_fd_beforepoll,log_from_fd_afterpoll, + prefix); +} + void log_module(dict_t *dict) { add_closure(dict,"logfile",logfile_apply);