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