X-Git-Url: http://www.chiark.greenend.org.uk/ucgi/~ian/git?p=secnet.git;a=blobdiff_plain;f=log.c;h=a2e24aed61e1fd37669648f46519cc6f3ce896b7;hp=32f0901e96830b3df1fdc5dac346c09a3d9b6149;hb=656df7e2c9b688150ebe991d79a64ac096bb5f8e;hpb=469fd1d95b2528212a46b155cb115c078de4228f

diff --git a/log.c b/log.c
index 32f0901..a2e24ae 100644
--- a/log.c
+++ b/log.c
@@ -5,42 +5,41 @@
 #include <time.h>
 #include <errno.h>
 #include <syslog.h>
+#include <assert.h>
+#include <unistd.h>
 #include "process.h"
+#include "util.h"
 
 bool_t secnet_is_daemon=False;
 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)
+static void vMessageFallback(uint32_t class, const 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) {
+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_ERR || 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 +48,38 @@ void Message(uint32_t class, char *message, ...)
     va_end(ap);
 }
 
-static void vfatal(int status, bool_t perror, char *message, va_list args)
+static void MessageFallback(uint32_t class, const char *message, ...)
+    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));
+
+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 +87,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 +95,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 +103,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 +111,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 +134,54 @@ 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)
+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 +189,57 @@ static void log_vmulti(void *sst, int class, char *message, va_list args)
     }
 }
 
-static void log_multi(void *st, int priority, char *message, ...)
+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 +266,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 +274,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 +288,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)
+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, ...)
+static void logfile_log(void *state, int class, const 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 +368,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 },
@@ -291,16 +402,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 +425,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);
 }
@@ -341,7 +454,10 @@ static int msgclass_to_syslogpriority(uint32_t m)
     }
 }
     
-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,20 +465,11 @@ 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 },
@@ -395,7 +502,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;
     }
 }
@@ -408,14 +517,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)
@@ -428,11 +537,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; i<st->i; 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);