libdaemon: Draft logging infrastructure.

- logging is not controlled by "levels" but by "types"; types are
  independent of each other... implementation of the usual "log level"
  user-level semantics can be simply done on top; the immediate
  application is enabling/disabling wire traffic logging independently
  of other debug data, since the former is rather bulky and can easily
  obscure almost everything else
- all logs go to "outlets", of which we currently have 2: syslog and
  stderr; which "types" go to which "outlets" is entirely configurable

5 files changed, 211 insertions, 9 deletions

diff --git a/libdaemon/server/Makefile.in b/libdaemon/server/Makefile.in
index 245a19d2..1c4a38e7 100644
--- a/libdaemon/server/Makefile.in
+++ b/libdaemon/server/Makefile.in
@@ -15,7 +15,7 @@ top_srcdir = @top_srcdir@
 top_builddir = @top_builddir@
 
 LIB_STATIC = libdaemonserver.a
-SOURCES = daemon-server.c
+SOURCES = daemon-server.c daemon-log.c
 
 include $(top_builddir)/make.tmpl
 
diff --git a/libdaemon/server/daemon-log.c b/libdaemon/server/daemon-log.c
new file mode 100644
index 00000000..caa40cbc
--- /dev/null
+++ b/libdaemon/server/daemon-log.c
@@ -0,0 +1,143 @@
+#include "daemon-server.h"
+#include "daemon-log.h"
+#include <syslog.h>
+#include "assert.h"
+
+struct backend {
+	int id;
+	void (*log)(log_state *s, void **state, int type, const char *message);
+};
+
+static void log_syslog(log_state *s, void **state, int type, const char *message)
+{
+	if (!*state) { /* initialize */
+		*state = (void *)1;
+		openlog(s->name, LOG_PID, LOG_DAEMON);
+	}
+	int prio = LOG_DEBUG;
+	switch (type) {
+	case DAEMON_LOG_INFO: prio = LOG_INFO; break;
+	case DAEMON_LOG_WARN: prio = LOG_WARNING; break;
+	case DAEMON_LOG_FATAL: prio = LOG_CRIT; break;
+	}
+
+	syslog(prio, "%s", message);
+}
+
+static void log_stderr(log_state *s, void **state, int type, const char *message)
+{
+	const char *prefix = "";
+	switch (type) {
+	case DAEMON_LOG_INFO: prefix = "I: "; break;
+	case DAEMON_LOG_WARN: prefix = "W: " ; break;
+	case DAEMON_LOG_ERROR:
+	case DAEMON_LOG_FATAL: prefix = "E: " ; break;
+	}
+
+	fprintf(stderr, "%s%s\n", prefix, message);
+}
+
+struct backend backend[] = {
+	{ DAEMON_LOG_OUTLET_SYSLOG, log_syslog },
+	{ DAEMON_LOG_OUTLET_STDERR, log_stderr },
+	{ 0, 0 }
+};
+
+void daemon_log(log_state *s, int type, const char *message) {
+	int i = 0;
+	while ( backend[i].id ) {
+		if ( (s->log_config[type] & backend[i].id) == backend[i].id )
+			backend[i].log( s, &s->backend_state[i], type, message );
+		++ i;
+	}
+}
+
+void daemon_logf(log_state *s, int type, const char *fmt, ...) {
+	va_list ap;
+	va_start(ap, fmt);
+	char *buf;
+	if (dm_vasprintf(&buf, fmt, ap) < 0)
+		return; /* _0 */
+	daemon_log(s, type, buf);
+}
+
+struct log_line_baton {
+	log_state *s;
+	int type;
+	const char *prefix;
+};
+
+static int _log_line(const char *line, void *baton) {
+	struct log_line_baton *b = baton;
+	daemon_logf(b->s, b->type, "%s%s", b->prefix, line);
+	return 0;
+}
+
+void daemon_log_cft(log_state *s, int type, const char *prefix, const struct dm_config_node *n)
+{
+	struct log_line_baton b = { .s = s, .type = type, .prefix = prefix };
+	dm_config_write_node(n, &_log_line, &b);
+}
+
+void daemon_log_multi(log_state *s, int type, const char *prefix, const char *msg)
+{
+	struct log_line_baton b = { .s = s, .type = type, .prefix = prefix };
+	char *buf = dm_strdup(msg);
+	char *pos = buf;
+
+	if (!buf)
+		return; /* _0 */
+
+	while (pos) {
+		char *next = strchr(pos, '\n');
+		if (next)
+			*next = 0;
+		_log_line(pos, &b);
+		pos = next ? next + 1 : 0;
+	}
+}
+
+void daemon_log_enable(log_state *s, int outlet, int type, int enable)
+{
+	assert(type < 32);
+	if (enable)
+		s->log_config[type] |= outlet;
+	else
+		s->log_config[type] &= ~outlet;
+}
+
+static int _parse_one(log_state *s, int outlet, const char *type, int enable)
+{
+	int i;
+	if (!strcmp(type, "all"))
+		for (i = 0; i < 32; ++i)
+			daemon_log_enable(s, outlet, i, enable);
+	else if (!strcmp(type, "wire"))
+		daemon_log_enable(s, outlet, DAEMON_LOG_WIRE, enable);
+	else if (!strcmp(type, "debug"))
+		daemon_log_enable(s, outlet, DAEMON_LOG_DEBUG, enable);
+	else
+		return 0;
+
+	return 1;
+}
+
+int daemon_log_parse(log_state *s, int outlet, const char *types, int enable)
+{
+	char *buf = dm_strdup(types);
+	char *pos = buf;
+
+	if (!buf)
+		return 0;
+
+	while (pos) {
+		char *next = strchr(pos, ',');
+		if (next)
+			*next = 0;
+		if (!_parse_one(s, outlet, pos, enable))
+			return 0;
+		pos = next ? next + 1 : 0;
+	}
+
+	return 1;
+}
diff --git a/libdaemon/server/daemon-log.h b/libdaemon/server/daemon-log.h
new file mode 100644
index 00000000..17d80076
--- /dev/null
+++ b/libdaemon/server/daemon-log.h
@@ -0,0 +1,14 @@
+enum { DAEMON_LOG_FATAL = 0 /* usually preceding daemon death */
+     , DAEMON_LOG_ERROR = 1 /* something serious has happened */
+     , DAEMON_LOG_WARN = 2 /* something unusual has happened */
+     , DAEMON_LOG_INFO = 3 /* thought you might be interested */
+     , DAEMON_LOG_WIRE = 4 /* dump traffic on client sockets */
+     , DAEMON_LOG_DEBUG = 5 /* unsorted debug stuff */
+     };
+
+#define DEBUG(s, x...) daemon_logf((s)->log, DAEMON_LOG_DEBUG, x)
+#define DEBUG_cft(s, i, n) daemon_log_cft((s)->log, DAEMON_LOG_DEBUG, i, n)
+#define WARN(s, x...) daemon_logf((s)->log, DAEMON_LOG_WARN, x)
+#define INFO(s, x...) daemon_logf((s)->log, DAEMON_LOG_INFO, x)
+#define ERROR(s, x...) daemon_logf((s)->log, DAEMON_LOG_ERROR, x)
+#define FATAL(s, x...) daemon_logf((s)->log, DAEMON_LOG_FATAL, x)
diff --git a/libdaemon/server/daemon-server.c b/libdaemon/server/daemon-server.c
index 5ca92316..c69da360 100644
--- a/libdaemon/server/daemon-server.c
+++ b/libdaemon/server/daemon-server.c
@@ -12,6 +12,7 @@
 
 #include "daemon-shared.h"
 #include "daemon-server.h"
+#include "daemon-log.h"
 
 #include <dlfcn.h>
 #include <errno.h>
@@ -26,7 +27,7 @@
 #include <unistd.h>
 #include <signal.h>
 
-#include <syslog.h>
+#include <syslog.h> /* FIXME. For the global closelog(). */
 
 #if 0
 /* Create a device monitoring thread. */
@@ -391,6 +392,7 @@ static void *client_thread(void *baton)
 		if (!req.cft)
 			fprintf(stderr, "error parsing request:\n %s\n", req.buffer);
 
+		daemon_log_cft(b->s.log, DAEMON_LOG_WIRE, "<- ", req.cft->root);
 		res = builtin_handler(b->s, b->client, req);
 
 		if (res.error == EPROTO) /* Not a builtin, delegate to the custom handler. */
@@ -407,6 +409,7 @@ static void *client_thread(void *baton)
 			dm_config_destroy(req.cft);
 		dm_free(req.buffer);
 
+		daemon_log_multi(b->s.log, DAEMON_LOG_WIRE, "-> ", res.buffer);
 		write_buffer(b->client.socket_fd, res.buffer, strlen(res.buffer));
 
 		free(res.buffer);
@@ -462,8 +465,13 @@ void daemon_start(daemon_state s)
 	if (!s.foreground)
 		_daemonise();
 
-	/* TODO logging interface should be somewhat more elaborate */
-	openlog(s.name, LOG_PID, LOG_DAEMON);
+	log_state _log = { { 0 } };
+	s.log = &_log;
+	s.log->name = s.name;
+
+	/* Log important things to syslog by default. */
+	daemon_log_enable(s.log, DAEMON_LOG_OUTLET_SYSLOG, DAEMON_LOG_FATAL, 1);
+	daemon_log_enable(s.log, DAEMON_LOG_OUTLET_SYSLOG, DAEMON_LOG_ERROR, 1);
 
 	(void) dm_prepare_selinux_context(s.pidfile, S_IFREG);
 
@@ -487,7 +495,7 @@ void daemon_start(daemon_state s)
 #ifdef linux
 	/* Systemd has adjusted oom killer for us already */
 	if (s.avoid_oom && !_systemd_activation && !_protect_against_oom_killer())
-		syslog(LOG_ERR, "Failed to protect against OOM killer");
+		ERROR(&s, "Failed to protect against OOM killer");
 #endif
 
 	if (!_systemd_activation && s.socket_path) {
@@ -511,7 +519,7 @@ void daemon_start(daemon_state s)
 			perror("select error");
 		if (FD_ISSET(s.socket_fd, &in))
 			if (!_shutdown_requested && !handle_connect(s))
-				syslog(LOG_ERR, "Failed to handle a client connection.");
+				ERROR(&s, "Failed to handle a client connection.");
 	}
 
 	/* If activated by systemd, do not unlink the socket - systemd takes care of that! */
@@ -522,8 +530,9 @@ void daemon_start(daemon_state s)
 	if (s.daemon_fini)
 		s.daemon_fini(&s);
 
-	syslog(LOG_NOTICE, "%s shutting down", s.name);
-	closelog();
+	INFO(&s, "%s shutting down", s.name);
+
+	closelog(); /* FIXME */
 	remove_lockfile(s.pidfile);
 	if (failed)
 		exit(1);
diff --git a/libdaemon/server/daemon-server.h b/libdaemon/server/daemon-server.h
index 104dac17..df7ed8e0 100644
--- a/libdaemon/server/daemon-server.h
+++ b/libdaemon/server/daemon-server.h
@@ -64,6 +64,12 @@ static inline const char *daemon_request_str(request r, const char *path, const
  */
 typedef response (*handle_request)(struct daemon_state s, client_handle h, request r);
 
+typedef struct {
+	uint32_t log_config[32];
+	void *backend_state[32];
+	const char *name;
+} log_state;
+
 typedef struct daemon_state {
 	/*
 	 * The maximal stack size for individual daemon threads. This is
@@ -81,7 +87,6 @@ typedef struct daemon_state {
 	const char *protocol;
 	int protocol_version;
 
-	int log_level;
 	handle_request handler;
 	int (*daemon_init)(struct daemon_state *st);
 	int (*daemon_fini)(struct daemon_state *st);
@@ -89,6 +94,7 @@ typedef struct daemon_state {
 	/* Global runtime info maintained by the framework. */
 	int socket_fd;
 
+	log_state *log;
 	void *private; /* the global daemon state */
 } daemon_state;
 
@@ -119,4 +125,34 @@ daemon_reply daemon_takeover(daemon_info i, daemon_request r);
 /* Call this to request a clean shutdown of the daemon. Async safe. */
 void daemon_stop(void);
 
+enum { DAEMON_LOG_OUTLET_SYSLOG = 1,
+       DAEMON_LOG_OUTLET_STDERR = 2,
+       DAEMON_LOG_OUTLET_SOCKET = 4 };
+
+/* Log a message of a given type. */
+void daemon_log(log_state *s, int type, const char *message);
+
+/* Log a config (sub)tree, using a given message type, each line prefixed with "prefix". */
+void daemon_log_cft(log_state *s, int type, const char *prefix,
+                    const struct dm_config_node *n);
+
+/* Log a multi-line block, prefixing each line with "prefix". */
+void daemon_log_multi(log_state *s, int type, const char *prefix, const char *message);
+
+/* Log a formatted message as "type". See also daemon-log.h. */
+void daemon_logf(log_state *s, int type, const char *format, ...);
+
+/*
+ * Configure log_state to send messages of type "type" to the log outlet
+ * "outlet", iff "enable" is true.
+ */
+void daemon_log_enable(log_state *s, int outlet, int type, int enable);
+
+/*
+ * Set up logging on a given outlet using a list of message types (comma
+ * separated) to log using that outlet. The list is expected to look like this,
+ * "info,wire,debug". Returns 0 upon encountering an unknown message type.
+ */
+int daemon_log_parse(log_state *s, int outlet, const char *types, int enable);
+
 #endif