Try to preserve the integrity of the log file in case of errors/unexpected

shutdowns etc. Also check logfile integrity on startup and suspend
logging if an inconsistency is detected.
ok dhartmei@

1 files changed, 297 insertions, 61 deletions

diff --git a/sbin/pflogd/pflogd.c b/sbin/pflogd/pflogd.c
index 85d6baf2514..76536c34d4b 100644
--- a/sbin/pflogd/pflogd.c
+++ b/sbin/pflogd/pflogd.c
@@ -1,4 +1,4 @@
-/*	$OpenBSD: pflogd.c,v 1.24 2003/10/22 19:53:15 deraadt Exp $	*/
+/*	$OpenBSD: pflogd.c,v 1.25 2004/01/15 20:15:14 canacar Exp $	*/
 
 /*
  * Copyright (c) 2001 Theo de Raadt
@@ -49,10 +49,11 @@
 #include "pflogd.h"
 
 pcap_t *hpcap;
-pcap_dumper_t *dpcap;
+static FILE *dpcap;
 
 int Debug = 0;
-int snaplen = DEF_SNAPLEN;
+static int snaplen = DEF_SNAPLEN;
+static int cur_snaplen = DEF_SNAPLEN;
 
 volatile sig_atomic_t gotsig_close, gotsig_alrm, gotsig_hup;
 
@@ -65,15 +66,43 @@ char errbuf[PCAP_ERRBUF_SIZE];
 int log_debug = 0;
 unsigned int delay = FLUSH_DELAY;
 
-char *copy_argv(char * const *argv);
+char *copy_argv(char * const *);
+void  dump_packet(u_char *, const struct pcap_pkthdr *, const u_char *);
+void  dump_packet_nobuf(u_char *, const struct pcap_pkthdr *, const u_char *);
+int   flush_buffer(FILE *);
 int   init_pcap(void);
-void  logmsg(int priority, const char *message, ...);
+void  logmsg(int, const char *, ...);
+void  purge_buffer(void);
 int   reset_dump(void);
+int   scan_dump(FILE *, off_t);
+int   set_snaplen(int);
+void  set_suspended(int);
 void  sig_alrm(int);
 void  sig_close(int);
 void  sig_hup(int);
 void  usage(void);
 
+/* buffer must always be greater than snaplen */
+static int    bufpkt = 0;	/* number of packets in buffer */
+static int    buflen = 0;	/* allocated size of buffer */
+static char  *buffer = NULL;	/* packet buffer */
+static char  *bufpos = NULL;	/* position in buffer */
+static int    bufleft = 0;	/* bytes left in buffer */
+
+/* if error, stop logging but count dropped packets */
+static int suspended = -1;
+static long packets_dropped = 0;
+
+void
+set_suspended(int s)
+{
+	if (suspended == s)
+		return;
+
+	suspended = s;
+	setproctitle("[%s] -s %d -f %s",
+            suspended ? "suspended" : "running", cur_snaplen, filename);
+}
 
 char *
 copy_argv(char * const *argv)
@@ -161,7 +190,6 @@ init_pcap(void)
 	hpcap = pcap_open_live(interface, snaplen, 1, PCAP_TO_MS, errbuf);
 	if (hpcap == NULL) {
 		logmsg(LOG_ERR, "Failed to initialize: %s", errbuf);
-		hpcap = NULL;
 		return (-1);
 	}
 
@@ -174,7 +202,7 @@ init_pcap(void)
 
 	set_pcap_filter();
 
-	snaplen = pcap_snapshot(hpcap);
+	cur_snaplen = snaplen = pcap_snapshot(hpcap);
 
 	/* lock */
 	if (ioctl(pcap_fileno(hpcap), BIOCLOCK) < 0) {
@@ -186,6 +214,20 @@ init_pcap(void)
 }
 
 int
+set_snaplen(int snap)
+{
+	if (priv_set_snaplen(snap))
+		return (1);
+
+	if (cur_snaplen > snap)
+		purge_buffer();
+
+	cur_snaplen = snap;
+
+	return (0);
+}
+
+int
 reset_dump(void)
 {
 	struct pcap_file_header hdr;
@@ -194,10 +236,12 @@ reset_dump(void)
 	FILE *fp;
 
 	if (hpcap == NULL)
-		return (1);
+		return (-1);
+
 	if (dpcap) {
-		pcap_dump_close(dpcap);
-		dpcap = 0;
+		flush_buffer(dpcap);
+		fclose(dpcap);
+		dpcap = NULL;
 	}
 
 	/*
@@ -219,14 +263,18 @@ reset_dump(void)
 		return (1);
 	}
 
-	dpcap = (pcap_dumper_t *)fp;
+	/* set FILE unbuffered, we do our own buffering */
+	if (setvbuf(fp, NULL, _IONBF, 0)) {
+		logmsg(LOG_ERR, "Failed to set output buffers");
+		return (1);
+	}
 
 #define TCPDUMP_MAGIC 0xa1b2c3d4
 
 	if (st.st_size == 0) {
-		if (snaplen != pcap_snapshot(hpcap)) {
+		if (snaplen != cur_snaplen) {
 			logmsg(LOG_NOTICE, "Using snaplen %d", snaplen);
-			if (priv_set_snaplen(snaplen)) {
+			if (set_snaplen(snaplen)) {
 				logmsg(LOG_WARNING,
 				    "Failed, using old settings");
 			}
@@ -240,52 +288,222 @@ reset_dump(void)
 		hdr.linktype = hpcap->linktype;
 
 		if (fwrite((char *)&hdr, sizeof(hdr), 1, fp) != 1) {
-			dpcap = NULL;
 			fclose(fp);
-			return (-1);
+			return (1);
 		}
-		return (0);
+	} else if (scan_dump(fp, st.st_size)) {
+		/* XXX move file and continue? */
+		fclose(fp);
+		return (1);
 	}
 
+	dpcap = fp;
+
+	set_suspended(0);
+	flush_buffer(fp);
+
+	return (0);
+}
+
+int
+scan_dump(FILE *fp, off_t size)
+{
+	struct pcap_file_header hdr;
+	struct pcap_pkthdr ph;
+	off_t pos;
+
 	/*
-	 * XXX Must read the file, compare the header against our new
+	 * Must read the file, compare the header against our new
 	 * options (in particular, snaplen) and adjust our options so
-	 * that we generate a correct file.
+	 * that we generate a correct file. Furthermore, check the file
+	 * for consistency so that we can append safely.
+	 *
+	 * XXX this may take a long time for large logs.
 	 */
 	(void) fseek(fp, 0L, SEEK_SET);
-	if (fread((char *)&hdr, sizeof(hdr), 1, fp) == 1) {
-		if (hdr.magic != TCPDUMP_MAGIC ||
-		    hdr.version_major != PCAP_VERSION_MAJOR ||
-		    hdr.version_minor != PCAP_VERSION_MINOR ||
-		    hdr.linktype != hpcap->linktype) {
-			logmsg(LOG_ERR,
-			    "Invalid/incompatible log file, move it away");
-			fclose(fp);
-			return (1);
-		}
-		if (hdr.snaplen != snaplen) {
+
+	if (fread((char *)&hdr, sizeof(hdr), 1, fp) != 1) {
+		logmsg(LOG_ERR, "Short file header");
+		return (1);
+	}
+
+	if (hdr.magic != TCPDUMP_MAGIC ||
+	    hdr.version_major != PCAP_VERSION_MAJOR ||
+	    hdr.version_minor != PCAP_VERSION_MINOR ||
+	    hdr.linktype != hpcap->linktype ||
+	    hdr.snaplen > PFLOGD_MAXSNAPLEN) {
+		logmsg(LOG_ERR, "Invalid/incompatible log file, move it away");
+		return (1);
+	}
+
+	pos = sizeof(hdr);
+
+	while (!feof(fp)) {
+		off_t len = fread((char *)&ph, 1, sizeof(ph), fp);
+		if (len == 0)
+			break;
+
+		if (len != sizeof(ph))
+			goto error;
+		if (ph.caplen > hdr.snaplen || ph.caplen > PFLOGD_MAXSNAPLEN)
+			goto error;
+		pos += sizeof(ph) + ph.caplen;
+		if (pos > size)
+			goto error;
+		fseek(fp, ph.caplen, SEEK_CUR);
+	}
+
+	if (pos != size)
+		goto error;
+
+	if (hdr.snaplen != cur_snaplen) {
+		logmsg(LOG_WARNING,
+		       "Existing file has different snaplen %u, using it",
+		       hdr.snaplen);
+		if (set_snaplen(hdr.snaplen)) {
 			logmsg(LOG_WARNING,
-			    "Existing file has different snaplen %u, using it",
-			    hdr.snaplen);
-			if (priv_set_snaplen(hdr.snaplen)) {
-				logmsg(LOG_WARNING,
-				    "Failed, using old settings, offset %llu",
-				    (unsigned long long) st.st_size);
-			}
+			       "Failed, using old settings, offset %llu",
+			       (unsigned long long) size);
+		}
+	}
+
+	return (0);
+
+ error:
+	logmsg(LOG_ERR, "Corrupted log file.");
+	return (1);
+}
+
+/* dump a packet directly to the stream, which is unbuffered */
+void
+dump_packet_nobuf(u_char *user, const struct pcap_pkthdr *h, const u_char *sp)
+{
+	FILE *f = (FILE *)user;
+
+	if (suspended) {
+		packets_dropped++;
+		return;
+	}
+
+	if (fwrite((char *)h, sizeof(*h), 1, f) != 1) {
+		/* try to undo header to prevent corruption */
+		off_t pos = ftello(f);
+		if (pos < sizeof(*h) ||
+		    ftruncate(fileno(f), pos - sizeof(*h))) {
+			logmsg(LOG_ERR, "Write failed, corrupted logfile!");
+			set_suspended(1);
+			gotsig_close = 1;
+			return;
 		}
+		goto error;
+	}
+
+	if (fwrite((char *)sp, h->caplen, 1, f) != 1)
+		goto error;
+
+	return;
+
+error:
+	set_suspended(1);
+	packets_dropped ++;
+	logmsg(LOG_ERR, "Logging suspended: fwrite: %s", strerror(errno));
+}
+
+int
+flush_buffer(FILE *f)
+{
+	off_t offset;
+	int len = bufpos - buffer;
+
+	if (len <= 0)
+		return (0);
+
+	offset = ftello(f);
+	if (offset == (off_t)-1) {
+		set_suspended(1);
+		logmsg(LOG_ERR, "Logging suspended: ftello: %s",
+		    strerror(errno));
+		return (1);
+	}
+
+	if (fwrite(buffer, len, 1, f) != 1) {
+		set_suspended(1);
+		logmsg(LOG_ERR, "Logging suspended: fwrite: %s",
+		    strerror(errno));
+		ftruncate(fileno(f), offset);
+		return (1);
 	}
 
-	(void) fseek(fp, 0L, SEEK_END);
+	set_suspended(0);
+	bufpos = buffer;
+	bufleft = buflen;
+	bufpkt = 0;
+
 	return (0);
 }
 
+void
+purge_buffer(void)
+{
+	packets_dropped += bufpkt;
+
+	set_suspended(0);
+	bufpos = buffer;
+	bufleft = buflen;
+	bufpkt = 0;
+}
+
+/* append packet to the buffer, flushing if necessary */
+void
+dump_packet(u_char *user, const struct pcap_pkthdr *h, const u_char *sp)
+{
+	FILE *f = (FILE *)user;
+	size_t len = sizeof(*h) + h->caplen;
+
+	if (len < sizeof(*h) || h->caplen > (size_t)cur_snaplen) {
+		logmsg(LOG_NOTICE, "invalid size %u (%u/%u), packet dropped",
+		       len, cur_snaplen, snaplen);
+		packets_dropped++;
+		return;
+	}
+
+	if (len <= bufleft)
+		goto append;
+
+	if (suspended) {
+		packets_dropped++;
+		return;
+	}
+
+	if (flush_buffer(f)) {
+		packets_dropped++;
+		return;
+	}
+
+	if (len > bufleft) {
+		dump_packet_nobuf(user, h, sp);
+		return;
+	}
+
+ append:	
+	memcpy(bufpos, h, sizeof(*h));
+	memcpy(bufpos + sizeof(*h), sp, h->caplen);
+
+	bufpos += len;
+	bufleft -= len;
+	bufpkt++;
+
+	return;
+}
+
 int
 main(int argc, char **argv)
 {
 	struct pcap_stat pstat;
-	int ch, np;
+	int ch, np, Xflag = 0;
+	pcap_handler phandler = dump_packet;
 
-	while ((ch = getopt(argc, argv, "Dd:s:f:")) != -1) {
+	while ((ch = getopt(argc, argv, "Dxd:s:f:")) != -1) {
 		switch (ch) {
 		case 'D':
 			Debug = 1;
@@ -302,6 +520,11 @@ main(int argc, char **argv)
 			snaplen = atoi(optarg);
 			if (snaplen <= 0)
 				snaplen = DEF_SNAPLEN;
+			if (snaplen > PFLOGD_MAXSNAPLEN)
+				snaplen = PFLOGD_MAXSNAPLEN;
+			break;
+		case 'x':
+			Xflag++;
 			break;
 		default:
 			usage();
@@ -343,6 +566,7 @@ main(int argc, char **argv)
 		exit(1);
 	}
 
+	setproctitle("[initializing]");
 	/* Process is now unprivileged and inside a chroot */
 	signal(SIGTERM, sig_close);
 	signal(SIGINT, sig_close);
@@ -351,14 +575,29 @@ main(int argc, char **argv)
 	signal(SIGHUP, sig_hup);
 	alarm(delay);
 
-	if (reset_dump()) {
-		logmsg(LOG_ERR, "Failed to open log file %s", filename);
-		pcap_close(hpcap);
-		exit(1);
+	buffer = malloc(PFLOGD_BUFSIZE);
+
+	if (buffer == NULL) {
+		logmsg(LOG_WARNING, "Failed to allocate output buffer");
+		phandler = dump_packet_nobuf;
+	} else {
+		bufleft = buflen = PFLOGD_BUFSIZE;
+		bufpos = buffer;
+		bufpkt = 0;
 	}
 
+	if (reset_dump()) {
+		if (Xflag)
+			return (1);
+
+		logmsg(LOG_ERR, "Logging suspended: open error");
+		set_suspended(1);
+	} else if (Xflag)
+		return (0);
+
 	while (1) {
-		np = pcap_dispatch(hpcap, PCAP_NUM_PKTS, pcap_dump, (u_char *)dpcap);
+		np = pcap_dispatch(hpcap, PCAP_NUM_PKTS,
+		    dump_packet, (u_char *)dpcap);
 		if (np < 0)
 			logmsg(LOG_NOTICE, "%s", pcap_geterr(hpcap));
 
@@ -366,37 +605,34 @@ main(int argc, char **argv)
 			break;
 		if (gotsig_hup) {
 			if (reset_dump()) {
-				logmsg(LOG_ERR, "Failed to open log file!");
-				break;
+				logmsg(LOG_ERR,
+				    "Logging suspended: open error");
+				set_suspended(1);
 			}
 			gotsig_hup = 0;
 		}
 
 		if (gotsig_alrm) {
-			/* XXX pcap_dumper is an incomplete type which libpcap
-			 * casts to a FILE* currently.  For now it is safe to
-			 * make the same assumption, however this may change
-			 * in the future.
-			 */
-			if (dpcap) {
-				if (fflush((FILE *)dpcap) == EOF) {
-					break;
-				}
-			}
+			if (dpcap)
+				flush_buffer(dpcap);
 			gotsig_alrm = 0;
 			alarm(delay);
 		}
 	}
 
-	logmsg(LOG_NOTICE, "Exiting due to signal");
-	if (dpcap)
-		pcap_dump_close(dpcap);
+	logmsg(LOG_NOTICE, "Exiting");
+	if (dpcap) {
+		flush_buffer(dpcap);
+		fclose(dpcap);
+	}
+	purge_buffer();
 
 	if (pcap_stats(hpcap, &pstat) < 0)
 		logmsg(LOG_WARNING, "Reading stats: %s", pcap_geterr(hpcap));
 	else
-		logmsg(LOG_NOTICE, "%u packets received, %u dropped",
-		    pstat.ps_recv, pstat.ps_drop);
+		logmsg(LOG_NOTICE,
+		    "%u packets received, %u/%u dropped (kernel/pflogd)",
+		    pstat.ps_recv, pstat.ps_drop, packets_dropped);
 
 	pcap_close(hpcap);
 	if (!Debug)