trackrdrd: re-worked logging, added the options -d (debug) and -l (log file)

src/Makefile.am

@@ -4,7 +4,8 @@ bin_PROGRAMS = trackrdrd
 
 trackrdrd_SOURCES = \
 	trackrdrd.c \
-	parse.c
+	parse.c \
+	log.c
 #	$(VARNISHSRC)/lib/libvarnish/assert.c \
 #	$(VARNISHSRC)/lib/libvarnish/flopen.c \
 #	$(VARNISHSRC)/lib/libvarnish/version.c \

src/log.c

+/*-
+ * Copyright (c) 2012 UPLEX Nils Goroll Systemoptimierung
+ * Copyright (c) 2012 Otto Gmbh & Co KG
+ * All rights reserved
+ * Use only with permission
+ *
+ * Author: Geoffrey Simmons <geoffrey.simmons@uplex.de>
+ *
+ * Redistribution and use in source and binary forms, with or without
+ * modification, are permitted provided that the following conditions
+ * are met:
+ * 1. Redistributions of source code must retain the above copyright
+ *    notice, this list of conditions and the following disclaimer.
+ * 2. Redistributions in binary form must reproduce the above copyright
+ *    notice, this list of conditions and the following disclaimer in the
+ *    documentation and/or other materials provided with the distribution.
+ *
+ * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND
+ * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
+ * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
+ * ARE DISCLAIMED.  IN NO EVENT SHALL AUTHOR OR CONTRIBUTORS BE LIABLE
+ * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
+ * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
+ * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
+ * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
+ * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
+ * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
+ * SUCH DAMAGE.
+ *
+ */
+
+#include <syslog.h>
+#include <stdlib.h>
+#include <stdio.h>
+#include <stdarg.h>
+#include <strings.h>
+
+#include "trackrdrd.h"
+
+#include "libvarnish.h"
+
+static const char *level2name[LOG_DEBUG];
+
+static void
+syslog_setlevel(int level)
+{
+    setlogmask(LOG_UPTO(level));
+}
+
+/* XXX: is this safe? */
+static void
+stdio_initnames(void)
+{
+    level2name[LOG_EMERG]	= "EMERG";
+    level2name[LOG_ALERT]	= "ALERT";
+    level2name[LOG_CRIT]	= "CRIT";
+    level2name[LOG_ERR]		= "ERR";
+    level2name[LOG_WARNING]	= "WARNING";
+    level2name[LOG_NOTICE]	= "NOTICE";
+    level2name[LOG_INFO]	= "INFO";
+    level2name[LOG_DEBUG]	= "DEBUG";
+}
+
+static void
+stdio_log(int level, const char *msg, ...)
+{
+    va_list ap;
+    
+    if (level > logconf.level)
+        return;
+    fprintf(logconf.out, "%s: ", level2name[level]);
+    va_start(ap, msg);
+    (void) vfprintf(logconf.out, msg, ap);
+    va_end(ap);
+    fprintf(logconf.out, "\n");
+}
+
+static void
+stdio_setlevel(int level)
+{
+    logconf.level = level;
+}
+
+static void
+stdio_close(void)
+{
+    fclose(logconf.out);
+}
+
+int LOG_Open(const char *progname, const char *dest)
+{
+    if (dest == NULL) {
+        /* syslog */
+        logconf.log = syslog;
+        logconf.setlevel = syslog_setlevel;
+        logconf.close = closelog;
+        openlog(progname, LOG_PID | LOG_CONS | LOG_NDELAY | LOG_NOWAIT,
+            LOG_USER);
+        setlogmask(LOG_UPTO(LOG_INFO));
+        atexit(closelog);
+        return(0);
+    }
+
+    if (strcmp(dest, "-") == 0)
+        logconf.out = stdout;
+    else {
+        logconf.out = fopen(dest, "w");
+        if (logconf.out == NULL)
+            return(-1);
+    }
+    logconf.level = LOG_INFO;
+    logconf.log = stdio_log;
+    logconf.setlevel = stdio_setlevel;
+    logconf.close = stdio_close;
+    stdio_initnames();
+    
+    return(0);
+}

src/trackrdrd.c

@@ -38,7 +38,6 @@
 #include "config.h"
 
 #include <errno.h>
-#include <fcntl.h>
 #include <signal.h>
 #include <stdio.h>
 #include <stdlib.h>
@@ -46,8 +45,6 @@
 #include <unistd.h>
 #include <syslog.h>
 
-#include "trackrdrd.h"
-
 #include "compat/daemon.h"
 
 #include "vsb.h"
@@ -57,6 +54,8 @@
 #include "vsl.h"
 #include "varnishapi.h"
 
+#include "trackrdrd.h"
+
 #define TRACK_TAGS "ReqStart,VCL_log,ReqEnd"
 #define TRACKLOG_PREFIX "track "
 #define TRACKLOG_PREFIX_LEN (sizeof(TRACKLOG_PREFIX)-1)
@@ -97,8 +96,7 @@ OSL_Track(void *priv, enum VSL_tag_e tag, unsigned fd, unsigned len,
 
         err = Parse_ReqStart(ptr, len, &xid);
         AZ(err);
-
-        syslog(LOG_DEBUG, "%s: XID=%d", VSL_tags[tag], xid);
+        LOG_Log(LOG_DEBUG, "%s: XID=%d", VSL_tags[tag], xid);
 #if 0
         /* assert(!(hash(XID) exists)); */
         /* init hash(XID); */
@@ -123,10 +121,10 @@ OSL_Track(void *priv, enum VSL_tag_e tag, unsigned fd, unsigned len,
         err = Parse_VCL_Log(&ptr[TRACKLOG_PREFIX_LEN], len-TRACKLOG_PREFIX_LEN,
                             &xid, &data, &datalen);
         AZ(err);
-        syslog(LOG_DEBUG, "%s: XID=%d, data=[%.*s]", VSL_tags[tag],
-               xid, datalen, data);
-        
+        LOG_Log(LOG_DEBUG, "%s: XID=%d, data=[%.*s]", VSL_tags[tag],
+            xid, datalen, data);
 #if 0
+        
         /* assert((hash(XID) exists) && hash(XID).tid == fd
                   && !hash(XID).done); */
         entry = HSH_Find(hashtable, xid);
@@ -152,7 +150,8 @@ OSL_Track(void *priv, enum VSL_tag_e tag, unsigned fd, unsigned len,
                   && !hash(XID).done); */
         err = Parse_ReqEnd(ptr, len, &xid);
         AZ(err);
-        syslog(LOG_DEBUG, "%s: XID=%d", VSL_tags[tag], xid);
+        LOG_Log(LOG_DEBUG, "%s: XID=%d", VSL_tags[tag], xid);
+        
 #if 0        
         entry = HSH_Find(hashtable, xid);
         CHECK_OBJ_NOTNULL(entry, HASHENTRY_MAGIC);
@@ -190,19 +189,15 @@ int
 main(int argc, char * const *argv)
 {
 	int c;
-	int D_flag = 0;
-	const char *P_arg = NULL;
+	int D_flag = 0, d_flag = 0;
+	const char *P_arg = NULL, *l_arg = NULL;
 	struct vpf_fh *pfh = NULL;
 	struct VSM_data *vd;
 
 	vd = VSM_New();
 	VSL_Setup(vd);
 
-        openlog(PACKAGE_NAME, LOG_PID | LOG_CONS | LOG_NDELAY | LOG_NOWAIT,
-            LOG_USER);
-        atexit(closelog);
-
-	while ((c = getopt(argc, argv, "DP:Vn:")) != -1) {
+	while ((c = getopt(argc, argv, "DP:Vn:hl:d")) != -1) {
 		switch (c) {
 		case 'D':
                     D_flag = 1;
@@ -216,6 +211,13 @@ main(int argc, char * const *argv)
                 case 'n':
                     if (VSL_Arg(vd, c, optarg) <= 0)
                         exit(1);
+                case 'l':
+                    l_arg = optarg;
+                    break;
+                case 'd':
+                    d_flag = 1;
+                    break;
+                case 'h':
 		default:
                     usage();
 		}
@@ -224,13 +226,14 @@ main(int argc, char * const *argv)
 	if ((argc - optind) > 0)
 		usage();
 
-	if (VSL_Open(vd, 1))
-		exit(1);
-
-	if (P_arg && (pfh = VPF_Open(P_arg, 0644, NULL)) == NULL) {
-		perror(P_arg);
-		exit(1);
-	}
+        if (LOG_Open(PACKAGE_NAME, l_arg) != 0) {
+            perror(l_arg);
+            exit(1);
+        }
+        if (d_flag)
+            LOG_SetLevel(LOG_DEBUG);
+        LOG_Log0(LOG_INFO, "starting");
+        
         /*
 	if (D_flag && varnish_daemon(0, 0) == -1) {
 		perror("daemon()");
@@ -239,14 +242,23 @@ main(int argc, char * const *argv)
 		exit(1);
 	}
         */
+
+        /* XXX: Parent/child setup
+           Write the pid in the parent, open VSL in the child
+        */
+	if (P_arg && (pfh = VPF_Open(P_arg, 0644, NULL)) == NULL) {
+		perror(P_arg);
+		exit(1);
+	}
 	if (pfh != NULL)
 		VPF_Write(pfh);
 
+        /* XXX: child opens and reads VSL */
+	if (VSL_Open(vd, 1))
+		exit(1);
+
         /* Only read the VSL tags relevant to tracking */
-        if (VSL_Arg(vd, 'i', TRACK_TAGS) <= 0) {
-            fprintf(stderr, "VSL_Arg(i)\n");
-            exit(1);
-        }
+        assert(VSL_Arg(vd, 'i', TRACK_TAGS) > 0);
         
 	while (VSL_Dispatch(vd, OSL_Track, stdout) >= 0) {            
 		if (fflush(stdout) != 0) {
@@ -255,7 +267,10 @@ main(int argc, char * const *argv)
 		}
 	}
 
+        /* XXX: Parent removes PID */
 	if (pfh != NULL)
 		VPF_Remove(pfh);
+
+        LOG_Log0(LOG_INFO, "exiting");
 	exit(0);
 }

src/trackrdrd.h

@@ -29,8 +29,32 @@
  *
  */
 
+#include <stdio.h>
+
+/* log.c */
+typedef void log_log_t(int level, const char *msg, ...);
+typedef void log_setlevel_t(int level);
+typedef void log_close_t(void);
+
+struct logconf {
+    log_log_t		*log;
+    log_setlevel_t	*setlevel;
+    log_close_t		*close;
+    FILE		*out;
+    int			level;
+} logconf;
+
+int LOG_Open(const char *progname, const char *dest);
+/* XXX: __VA_ARGS__ can't be empty ... */
+#define LOG_Log0(level, msg) logconf.log(level, msg)
+#define LOG_Log(level, msg, ...) logconf.log(level, msg, __VA_ARGS__)
+#define LOG_SetLevel(level) logconf.setlevel(level)
+#define LOG_Close() logconf.close()
+
+/* parse.c */
 int Parse_XID(const char *str, int len, unsigned *xid);
 int Parse_ReqStart(const char *ptr, int len, unsigned *xid);
 int Parse_ReqEnd(const char *ptr, unsigned len, unsigned *xid);
 int Parse_VCL_Log(const char *ptr, int len, unsigned *xid,
     char **data, int *datalen);
+