[PATCH 0/6] logging refactoring

[PATCH 0/6] logging refactoring

[Colin McCabe]

This patch series creates a common.h and populates it with some function
prototypes and logging stuff.

The changes here are fairly minor and mostly consist of switching over to use
the new logging macros. Probably the most helpful one is CLD_DEBUG, which only
evaluates its arguments if log->verbose is set. CLD_INFO, CLD_WARN, CLD_ERR
and CLD_CRIT simply call the log function with the appropriate log level, in a
shorter amount of code.

I also eliminated some cases where we had to pass both a logging function and
a verbosity level. We only need to pass a pointer to a cld_log struct now.
This should facilitate some code sharing and hopefully improve stuff.

regards,
C.

[PATCH 1/6] cld: Declare common.c functions in common.h

[Colin McCabe]

From: Colin McCabe <cmccabe@cobalt.club.cc.cmu.edu>

Signed-off-by: Colin McCabe <cmccabe@alumni.cmu.edu>
---
 include/cld_msg.h |   10 ----------
 include/cldc.h    |    1 +
 include/common.h  |   11 +++++++++++
 3 files changed, 12 insertions(+), 10 deletions(-)
 create mode 100644 include/common.h

diff --git a/include/cld_msg.h b/include/cld_msg.h
index 641b857..01837b7 100644
--- a/include/cld_msg.h
+++ b/include/cld_msg.h
@@ -250,14 +250,4 @@ struct cld_msg_event {
 	uint8_t			res[4];
 };
 
-/*
- * function prototypes for lib/common.c;
- * ideally these should not be in cld_msg.h
- */
-
-extern unsigned long long cld_sid2llu(const uint8_t *sid);
-extern void __cld_rand64(void *p);
-extern const char *cld_errstr(enum cle_err_codes ecode);
-extern int cld_readport(const char *fname);
-
 #endif /* __CLD_MSG_H__ */
diff --git a/include/cldc.h b/include/cldc.h
index 9ae6dfe..3f0deb5 100644
--- a/include/cldc.h
+++ b/include/cldc.h
@@ -5,6 +5,7 @@
 #include <stdbool.h>
 #include <glib.h>
 #include <cld_msg.h>
+#include <common.h>
 
 struct cldc_session;
 
diff --git a/include/common.h b/include/common.h
new file mode 100644
index 0000000..52e5603
--- /dev/null
+++ b/include/common.h
@@ -0,0 +1,11 @@
+#ifndef __CLD_COMMON_H__
+#define __CLD_COMMON_H__
+
+#include <stdint.h>
+
+unsigned long long cld_sid2llu(const uint8_t *sid);
+void __cld_rand64(void *p);
+const char *cld_errstr(enum cle_err_codes ecode);
+int cld_readport(const char *fname);
+
+#endif /* __CLD_COMMON_H__ */
-- 
1.6.2.5

[PATCH 2/6] cld: create logging macros

[Colin McCabe]

From: Colin McCabe <cmccabe@cobalt.club.cc.cmu.edu>

Signed-off-by: Colin McCabe <cmccabe@alumni.cmu.edu>
---
 include/common.h |   27 +++++++++++++++++++++++++++
 1 files changed, 27 insertions(+), 0 deletions(-)

diff --git a/include/common.h b/include/common.h
index 52e5603..30610d8 100644
--- a/include/common.h
+++ b/include/common.h
@@ -8,4 +8,31 @@ void __cld_rand64(void *p);
 const char *cld_errstr(enum cle_err_codes ecode);
 int cld_readport(const char *fname);
 
+/** Print out a debug message if 'verbose' is enabled */
+#define CLD_DEBUG(cld_log, ...) \
+	if ((cld_log)->verbose) { \
+		(cld_log)->func(LOG_DEBUG, __VA_ARGS__); \
+	}
+
+/** Print out an informational log message */
+#define CLD_INFO(cld_log, ...) \
+	(cld_log)->func(LOG_INFO, __VA_ARGS__);
+
+/** Print out a warning message */
+#define CLD_WARN(cld_log, ...) \
+	(cld_log)->func(LOG_WARNING, __VA_ARGS__);
+
+/** Print out an error message */
+#define CLD_ERR(cld_log, ...) \
+	(cld_log)->func(LOG_ERR, __VA_ARGS__);
+
+/** Print out a critical warning message */
+#define CLD_CRIT(cld_log, ...) \
+	(cld_log)->func(LOG_CRIT, __VA_ARGS__);
+
+struct cld_log {
+	void (*func)(int prio, const char *fmt, ...);
+	bool verbose;
+};
+
 #endif /* __CLD_COMMON_H__ */
-- 
1.6.2.5

[PATCH 3/6] cld: modify client code to use logging macros

[Colin McCabe]

From: Colin McCabe <cmccabe@cobalt.club.cc.cmu.edu>

Signed-off-by: Colin McCabe <cmccabe@alumni.cmu.edu>
---
 include/cldc.h |    4 +--
 lib/cldc.c     |   98 +++++++++++++++++++++++---------------------------------
 tools/cldcli.c |    2 +-
 3 files changed, 42 insertions(+), 62 deletions(-)

diff --git a/include/cldc.h b/include/cldc.h
index 3f0deb5..70062cf 100644
--- a/include/cldc.h
+++ b/include/cldc.h
@@ -85,10 +85,8 @@ struct cldc_ops {
 struct cldc_session {
 	uint8_t		sid[CLD_SID_SZ];	/* client id */
 
-	bool		verbose;
-
 	const struct cldc_ops *ops;
-	void		(*act_log)(int prio, const char *fmt, ...);
+	struct		cld_log log;
 	void		*private;
 
 	uint8_t		addr[64];		/* server address */
diff --git a/lib/cldc.c b/lib/cldc.c
index 0ab4f19..38bed8f 100644
--- a/lib/cldc.c
+++ b/lib/cldc.c
@@ -111,7 +111,7 @@ static int ack_seqid(struct cldc_session *sess, uint64_t seqid_le)
 	memcpy(resp, &def_msg_ack, sizeof(*resp));
 
 	if (!authsign(sess, pkt, pkt_len)) {
-		sess->act_log(LOG_INFO, "authsign failed 2");
+		CLD_INFO(&sess->log, "authsign failed 2");
 		return -1;
 	}
 
@@ -135,12 +135,10 @@ static int cldc_rx_generic(struct cldc_session *sess,
 	while (tmp) {
 		req = tmp->data;
 
-		if (sess->verbose)
-			sess->act_log(LOG_DEBUG,
-				      "rx_gen: comparing req->xid (%llu) "
-				      "with resp->xid_in (%llu)",
-				(unsigned long long) le64_to_cpu(req->xid),
-			        (unsigned long long) le64_to_cpu(resp->xid_in));
+		CLD_DEBUG(&sess->log, "rx_gen: comparing req->xid (%llu) "
+			"with resp->xid_in (%llu)",
+			(unsigned long long) le64_to_cpu(req->xid),
+			(unsigned long long) le64_to_cpu(resp->xid_in));
 
 		if (req->xid == resp->xid_in)
 			break;
@@ -150,12 +148,9 @@ static int cldc_rx_generic(struct cldc_session *sess,
 		return -1005;
 
 	if (req->done) {
-		if (sess->verbose)
-			sess->act_log(LOG_DEBUG, "rx_gen: re-acking");
+		CLD_DEBUG(&sess->log, "rx_gen: re-acking");
 	} else {
-		if (sess->verbose)
-			sess->act_log(LOG_DEBUG,
-				      "rx_gen: issuing completion, acking");
+		CLD_DEBUG(&sess->log, "rx_gen: issuing completion, acking");
 
 		req->done = true;
 
@@ -181,9 +176,8 @@ static int cldc_rx_ack_frag(struct cldc_session *sess,
 	if (buflen < sizeof(*ack_msg))
 		return -1008;
 
-	if (sess->verbose)
-		sess->act_log(LOG_DEBUG, "ack-frag: seqid %llu, want to ack",
-			      ack_msg->seqid);
+	CLD_DEBUG(&sess->log, "ack-frag: seqid %llu, want to ack",
+			ack_msg->seqid);
 
 	tmp = sess->out_msg;
 	while (tmp) {
@@ -201,10 +195,8 @@ static int cldc_rx_ack_frag(struct cldc_session *sess,
 			if (pi->pkt.seqid != ack_msg->seqid)
 				continue;
 
-			if (sess->verbose)
-				sess->act_log(LOG_DEBUG,
-					      "ack-frag: seqid %llu, expiring",
-					      ack_msg->seqid);
+			CLD_DEBUG(&sess->log, "ack-frag: seqid %llu, expiring",
+				ack_msg->seqid);
 
 			req->pkt_info[i] = NULL;
 			free(pi);
@@ -248,7 +240,7 @@ static int cldc_rx_not_master(struct cldc_session *sess,
 			      const void *msgbuf,
 			      size_t buflen)
 {
-	sess->act_log(LOG_INFO, "FIXME: not-master message received");
+	CLD_DEBUG(&sess->log, "FIXME: not-master message received");
 	return -1055;	/* FIXME */
 }
 
@@ -315,8 +307,8 @@ static bool authcheck(struct cldc_session *sess, const struct cld_packet *pkt,
 	     md, &md_len);
 
 	if (md_len != SHA_DIGEST_LENGTH)
-		sess->act_log(LOG_INFO,
-			      "authsign BUG: md_len != SHA_DIGEST_LENGTH");
+		CLD_INFO(&sess->log,
+			"authsign BUG: md_len != SHA_DIGEST_LENGTH");
 
 	if (memcmp(buf + buflen - SHA_DIGEST_LENGTH, md, SHA_DIGEST_LENGTH))
 		return false;
@@ -340,8 +332,8 @@ static bool authsign(struct cldc_session *sess, struct cld_packet *pkt,
 	     md, &md_len);
 
 	if (md_len != SHA_DIGEST_LENGTH)
-		sess->act_log(LOG_INFO,
-			      "authsign BUG: md_len != SHA_DIGEST_LENGTH");
+		CLD_INFO(&sess->log,
+			"authsign BUG: md_len != SHA_DIGEST_LENGTH");
 
 	memcpy(buf + (buflen - SHA_DIGEST_LENGTH), md, SHA_DIGEST_LENGTH);
 
@@ -380,8 +372,7 @@ static int cldc_receive_msg(struct cldc_session *sess,
 	size_t msglen = sess->msg_buf_len;
 
 	if (memcmp(msg->magic, CLD_MSG_MAGIC, sizeof(msg->magic))) {
-		if (sess->verbose)
-			sess->act_log(LOG_DEBUG, "receive_pkt: bad msg magic");
+		CLD_DEBUG(&sess->log, "receive_pkt: bad msg magic");
 		return -EPROTO;
 	}
 
@@ -433,8 +424,7 @@ int cldc_receive_pkt(struct cldc_session *sess,
 	current_time = tv.tv_sec;
 
 	if (pkt_len < (sizeof(*pkt) + SHA_DIGEST_LENGTH)) {
-		if (sess->verbose)
-			sess->act_log(LOG_DEBUG, "receive_pkt: msg too short");
+		CLD_DEBUG(&sess->log, "receive_pkt: msg too short");
 		return -EPROTO;
 	}
 
@@ -448,11 +438,11 @@ int cldc_receive_pkt(struct cldc_session *sess,
 	no_seqid = first_frag && ((msg->op == cmo_not_master) ||
 				  (msg->op == cmo_ack_frag));
 
-	if (sess->verbose) {
+	if (sess->log.verbose) {
 		if (have_get) {
 			struct cld_msg_get_resp *dp;
 			dp = (struct cld_msg_get_resp *) msg;
-			sess->act_log(LOG_DEBUG, "receive_pkt(len %u, op %s"
+			CLD_DEBUG(&sess->log, "receive_pkt(len %u, op %s"
 				      ", seqid %llu, user %s, size %u)",
 				(unsigned int) pkt_len,
 				opstr(msg->op),
@@ -462,7 +452,7 @@ int cldc_receive_pkt(struct cldc_session *sess,
 		} else if (have_new_sess) {
 			struct cld_msg_resp *dp;
 			dp = (struct cld_msg_resp *) msg;
-			sess->act_log(LOG_DEBUG, "receive_pkt(len %u, op %s"
+			CLD_DEBUG(&sess->log, "receive_pkt(len %u, op %s"
 				      ", seqid %llu, user %s, xid_in %llu)",
 				(unsigned int) pkt_len,
 				opstr(msg->op),
@@ -470,8 +460,8 @@ int cldc_receive_pkt(struct cldc_session *sess,
 				pkt->user,
 				(unsigned long long) le64_to_cpu(dp->xid_in));
 		} else {
-			sess->act_log(LOG_DEBUG, "receive_pkt(len %u, "
-				      "flags %s%s, op %s, seqid %llu, user %s)",
+			CLD_DEBUG(&sess->log, "receive_pkt(len %u, "
+				"flags %s%s, op %s, seqid %llu, user %s)",
 				(unsigned int) pkt_len,
 				first_frag ? "F" : "",
 				last_frag ? "L" : "",
@@ -482,24 +472,20 @@ int cldc_receive_pkt(struct cldc_session *sess,
 	}
 
 	if (memcmp(pkt->magic, CLD_PKT_MAGIC, sizeof(pkt->magic))) {
-		if (sess->verbose)
-			sess->act_log(LOG_DEBUG, "receive_pkt: bad pkt magic");
+		CLD_DEBUG(&sess->log, "receive_pkt: bad pkt magic");
 		return -EPROTO;
 	}
 
 	/* check HMAC signature */
 	if (!authcheck(sess, pkt, pkt_len)) {
-		if (sess->verbose)
-			sess->act_log(LOG_DEBUG, "receive_pkt: invalid auth");
+		CLD_DEBUG(&sess->log, "receive_pkt: invalid auth");
 		return -EACCES;
 	}
 
 	/* verify stored server addr matches pkt addr */
 	if (((sess->addr_len != net_addrlen) ||
 	    memcmp(sess->addr, net_addr, net_addrlen))) {
-		if (sess->verbose)
-			sess->act_log(LOG_DEBUG,
-				      "receive_pkt: server address mismatch");
+		CLD_DEBUG(&sess->log, "receive_pkt: server address mismatch");
 		return -EBADE;
 	}
 
@@ -511,8 +497,7 @@ int cldc_receive_pkt(struct cldc_session *sess,
 		sess->msg_buf_len = 0;
 
 	if ((sess->msg_buf_len + msglen) > CLD_MAX_MSG_SZ) {
-		if (sess->verbose)
-			sess->act_log(LOG_DEBUG, "receive_pkt: bad pkt length");
+		CLD_DEBUG(&sess->log, "receive_pkt: bad pkt length");
 		return -EPROTO;
 	}
 
@@ -526,8 +511,7 @@ int cldc_receive_pkt(struct cldc_session *sess,
 		sess->next_seqid_in_tr =
 			sess->next_seqid_in - CLDC_MSG_REMEMBER;
 
-		if (sess->verbose)
-			sess->act_log(LOG_DEBUG, "receive_pkt: "
+		CLD_DEBUG(&sess->log, "receive_pkt: "
 				      "setting next_seqid_in to %llu",
 				      (unsigned long long) seqid);
 	} else if (!no_seqid) {
@@ -537,9 +521,7 @@ int cldc_receive_pkt(struct cldc_session *sess,
 					   sess->next_seqid_in))
 				return ack_seqid(sess, pkt->seqid);
 
-			if (sess->verbose)
-				sess->act_log(LOG_DEBUG,
-					      "receive_pkt: bad seqid %llu",
+			CLD_DEBUG(&sess->log, "receive_pkt: bad seqid %llu",
 					      (unsigned long long) seqid);
 			return -EBADSLT;
 		}
@@ -664,7 +646,7 @@ static void sess_expire(struct cldc_session *sess)
 static int sess_send_pkt(struct cldc_session *sess,
 			 const struct cld_packet *pkt, size_t pkt_len)
 {
-	if (sess->verbose) {
+	if (sess->log.verbose) {
 		uint32_t flags = le32_to_cpu(pkt->flags);
 		bool first = (flags & CPF_FIRST);
 		bool last = (flags & CPF_LAST);
@@ -677,14 +659,14 @@ static int sess_send_pkt(struct cldc_session *sess,
 			op = hdr->op;
 		}
 
-		sess->act_log(LOG_DEBUG,
-			      "send_pkt(len %zu, flags %s%s, "
-			      "op %s, seqid %llu)",
-			      pkt_len,
-			      first ? "F" : "",
-			      last ? "L" : "",
-			      first ? opstr(op) : "n/a",
-			      le64_to_cpu(pkt->seqid));
+		CLD_DEBUG(&sess->log,
+			"send_pkt(len %zu, flags %s%s, "
+			"op %s, seqid %llu)",
+			pkt_len,
+			first ? "F" : "",
+			last ? "L" : "",
+			first ? opstr(op) : "n/a",
+			le64_to_cpu(pkt->seqid));
 	}
 
 	return sess->ops->pkt_send(sess->private,
@@ -876,12 +858,12 @@ int cldc_new_sess(const struct cldc_ops *ops,
 		return -ENOMEM;
 
 #if 0
-	sess->verbose = true;
+	sess->log.verbose = true;
 #endif
 
 	sess->private = private;
 	sess->ops = ops;
-	sess->act_log = ops->errlog ? ops->errlog : cldc_errlog;
+	sess->log.func = ops->errlog ? ops->errlog : cldc_errlog;
 	sess->fh = g_array_sized_new(FALSE, TRUE, sizeof(struct cldc_fh), 16);
 	strcpy(sess->user, user);
 	strcpy(sess->secret_key, secret_key);
diff --git a/tools/cldcli.c b/tools/cldcli.c
index 60ab301..23cba99 100644
--- a/tools/cldcli.c
+++ b/tools/cldcli.c
@@ -823,7 +823,7 @@ static gpointer cld_thread(gpointer dummy)
 		return NULL;
 	}
 
-	thr_udp->sess->verbose = cldcli_verbose;
+	thr_udp->sess->log.verbose = cldcli_verbose;
 
 	pfd[0].fd = thr_udp->fd;
 	pfd[0].events = POLLIN;
-- 
1.6.2.5

[PATCH 4/6] cld: modify server code to use logging macros

[Colin McCabe]

From: Colin McCabe <cmccabe@cobalt.club.cc.cmu.edu>

Signed-off-by: Colin McCabe <cmccabe@alumni.cmu.edu>
---
 server/cld.h     |    4 +-
 server/cldb.c    |    6 ++--
 server/msg.c     |   49 +++++++++++++-----------------
 server/server.c  |   86 ++++++++++++++++++++++++------------------------------
 server/session.c |   57 ++++++++++++++----------------------
 server/util.c    |   27 +++++++++--------
 6 files changed, 100 insertions(+), 129 deletions(-)

diff --git a/server/cld.h b/server/cld.h
index 05c93ad..b013901 100644
--- a/server/cld.h
+++ b/server/cld.h
@@ -26,6 +26,7 @@
 #include <glib.h>
 #include "cldb.h"
 #include <cld_msg.h>
+#include "common.h"
 #include <libtimer.h>
 
 struct client;
@@ -152,7 +153,7 @@ extern int sess_load(GHashTable *ss);
 /* server.c */
 extern const char *opstr(enum cld_msg_ops op);
 extern struct server cld_srv;
-extern int debugging;
+extern struct cld_log srv_log;
 extern struct timeval current_time;
 extern int udp_tx(int sock_fd, struct sockaddr *, socklen_t,
 	    const void *, size_t);
@@ -161,7 +162,6 @@ extern void resp_err(struct session *sess,
 	      const struct cld_msg_hdr *src, enum cle_err_codes errcode);
 extern void resp_ok(struct session *sess, const struct cld_msg_hdr *src);
 extern bool authsign(struct cld_packet *pkt, size_t pkt_len);
-extern void applog(int prio, const char *fmt, ...);
 
 /* util.c */
 extern int write_pid_file(const char *pid_fn);
diff --git a/server/cldb.c b/server/cldb.c
index 2f012e5..1954587 100644
--- a/server/cldb.c
+++ b/server/cldb.c
@@ -241,7 +241,7 @@ int cldb_init(struct cldb *cldb, const char *db_home, const char *db_password,
 
 	rc = db_env_create(&cldb->env, 0);
 	if (rc) {
-		applog(LOG_WARNING, "cldb->env_create failed: %d", rc);
+		CLD_WARN(&srv_log, "cldb->env_create failed: %d", rc);
 		return rc;
 	}
 
@@ -375,7 +375,7 @@ static int cldb_up(struct cldb *cldb, unsigned int flags)
 
 	cldb->up = true;
 
-	applog(LOG_INFO, "databases up");
+	CLD_INFO(&srv_log, "databases up");
 	return 0;
 
 err_out_handle_idx:
@@ -417,7 +417,7 @@ void cldb_down(struct cldb *cldb)
 	cldb->inodes = NULL;
 	cldb->sessions = NULL;
 
-	applog(LOG_INFO, "databases down");
+	CLD_INFO(&srv_log, "databases down");
 }
 
 void cldb_fini(struct cldb *cldb)
diff --git a/server/msg.c b/server/msg.c
index dc5d5fa..218a5f0 100644
--- a/server/msg.c
+++ b/server/msg.c
@@ -169,7 +169,7 @@ static bool dirdata_append(void **data, size_t *data_len,
 
 	mem = realloc(*data, new_len);
 	if (!mem) {
-		applog(LOG_CRIT, "out of memory for data [%lu]", (long)new_len);
+		CLD_CRIT(&srv_log, "out of memory for data [%lz]", new_len);
 		return false;
 	}
 
@@ -238,15 +238,14 @@ static int inode_notify(DB_TXN *txn, cldino_t inum, bool deleted)
 
 		sess = g_hash_table_lookup(cld_srv.sessions, h.sid);
 		if (!sess) {
-			applog(LOG_WARNING, "inode_notify BUG");
+			CLD_WARN(&srv_log, "inode_notify BUG");
 			continue;
 		}
 
 		if (!sess->sock_fd) {		/* Freshly recovered session */
-			if (debugging)
-				applog(LOG_DEBUG,
-				       "Lost notify sid " SIDFMT " ino %lld",
-				       SIDARG(sess->sid), (long long) inum);
+			CLD_DEBUG(&srv_log, "Lost notify sid " SIDFMT
+				" ino %lld", SIDARG(sess->sid),
+				(long long) inum);
 			continue;
 		}
 
@@ -363,7 +362,7 @@ int inode_lock_rescan(DB_TXN *txn, cldino_t inum)
 
 		sess = g_hash_table_lookup(cld_srv.sessions, lock.sid);
 		if (!sess) {
-			applog(LOG_WARNING, "inode_lock_rescan BUG");
+			CLD_WARN(&srv_log, "inode_lock_rescan BUG");
 			break;
 		}
 
@@ -372,10 +371,9 @@ int inode_lock_rescan(DB_TXN *txn, cldino_t inum)
 		 */
 
 		if (!sess->sock_fd) {		/* Freshly recovered session */
-			if (debugging)
-				applog(LOG_DEBUG,
-				       "Lost success sid " SIDFMT " ino %lld",
-				       SIDARG(sess->sid), (long long) inum);
+			CLD_DEBUG(&srv_log, "Lost success sid " SIDFMT
+				" ino %lld", SIDARG(sess->sid),
+				(long long) inum);
 			continue;
 		}
 
@@ -455,13 +453,10 @@ void msg_get(struct msg_params *mp, bool metadata_only)
 		goto err_out;
 	}
 
-	if (debugging)
-		applog(LOG_DEBUG, "GET-DEBUG: sizeof(resp) %u, name_len %u, "
-		       "inode->size %u, resp_len %u",
-		       sizeof(*resp),
-		       name_len,
-		       inode_size,
-		       resp_len);
+	CLD_DEBUG(&srv_log, "GET-DEBUG: sizeof(resp) %u, name_len %u, "
+		"inode->size %u, resp_len %u",
+		sizeof(*resp), name_len,
+		inode_size, resp_len);
 
 	/* return response containing inode metadata */
 	memset(resp, 0, resp_len);
@@ -610,7 +605,7 @@ void msg_open(struct msg_params *mp)
 		/* create new in-memory inode */
 		inode = cldb_inode_new(txn, name, name_len, 0);
 		if (!inode) {
-			applog(LOG_CRIT, "cannot allocate new inode");
+			CLD_CRIT(&srv_log, "cannot allocate new inode");
 			resp_rc = CLE_OOM;
 			goto err_out;
 		}
@@ -667,7 +662,7 @@ void msg_open(struct msg_params *mp)
 	/* alloc & init new handle; updates session's next_fh */
 	h = cldb_handle_new(mp->sess, inum, msg_mode, msg_events);
 	if (!h) {
-		applog(LOG_CRIT, "cannot allocate handle");
+		CLD_CRIT(&srv_log, "cannot allocate handle");
 		resp_rc = CLE_OOM;
 		goto err_out;
 	}
@@ -695,7 +690,7 @@ void msg_open(struct msg_params *mp)
 	raw_sess = session_new_raw(mp->sess);
 
 	if (!raw_sess) {
-		applog(LOG_CRIT, "cannot allocate session");
+		CLD_CRIT(&srv_log, "cannot allocate session");
 		resp_rc = CLE_OOM;
 		goto err_out;
 	}
@@ -762,12 +757,10 @@ void msg_put(struct msg_params *mp)
 	/* make sure additional input data as large as expected */
 	data_size = le32_to_cpu(msg->data_size);
 	if (mp->msg_len != (data_size + sizeof(*msg))) {
-		applog(LOG_INFO, "PUT len mismatch: msg len %zu, "
-		       "wanted %zu + %u (== %u)",
-		       mp->msg_len,
-		       sizeof(*msg),
-		       data_size,
-		       data_size + sizeof(*msg));
+		CLD_INFO(&srv_log, "PUT len mismatch: msg len %zu, "
+			"wanted %zu + %u (== %u)",
+			mp->msg_len,
+			sizeof(*msg), data_size, data_size + sizeof(*msg));
 		resp_rc = CLE_BAD_PKT;
 		goto err_out_noabort;
 	}
@@ -1067,7 +1060,7 @@ void msg_del(struct msg_params *mp)
 	/* remove record from inode's directory data */
 	if (!dirdata_delete(parent_data, &parent_len,
 			    pinfo.base, pinfo.base_len)) {
-		applog(LOG_WARNING, "dirent del failed");
+		CLD_WARN(&srv_log, "dirent del failed");
 		resp_rc = CLE_DB_ERR;
 		goto err_out;
 	}
diff --git a/server/server.c b/server/server.c
index 39d1a54..b6e744f 100644
--- a/server/server.c
+++ b/server/server.c
@@ -37,6 +37,7 @@
 #include <openssl/hmac.h>
 #include <cld-private.h>
 #include "cld.h"
+#include "common.h"
 
 #define PROGRAM_NAME "cld"
 
@@ -84,7 +85,6 @@ static bool server_running = true;
 static bool dump_stats;
 static bool use_syslog = true;
 static bool strict_free = false;
-int debugging = 0;
 struct timeval current_time;
 
 struct server cld_srv = {
@@ -95,7 +95,7 @@ struct server cld_srv = {
 
 static void ensure_root(void);
 
-void applog(int prio, const char *fmt, ...)
+static void applog(int prio, const char *fmt, ...)
 {
 	va_list ap;
 
@@ -116,13 +116,17 @@ void applog(int prio, const char *fmt, ...)
 	va_end(ap);
 }
 
+struct cld_log srv_log = {
+	.func = applog,
+	.verbose = 0,
+};
+
 int udp_tx(int sock_fd, struct sockaddr *addr, socklen_t addr_len,
 	   const void *data, size_t data_len)
 {
 	ssize_t src;
 
-	if (debugging > 1)
-		applog(LOG_DEBUG, "udp_tx, fd %d", sock_fd);
+	CLD_DEBUG(&srv_log, "udp_tx, fd %d", sock_fd);
 
 	src = sendto(sock_fd, data, data_len, 0, addr, addr_len);
 	if (src < 0 && errno != EAGAIN)
@@ -267,7 +271,7 @@ static void show_msg(const struct cld_msg_hdr *msg)
 	case cmo_not_master:
 	case cmo_event:
 	case cmo_ack_frag:
-		applog(LOG_DEBUG, "msg: op %s, xid %llu",
+		CLD_DEBUG(&srv_log, "msg: op %s, xid %llu",
 		       opstr(msg->op),
 		       (unsigned long long) le64_to_cpu(msg->xid));
 		break;
@@ -279,7 +283,7 @@ static void udp_rx_msg(const struct client *cli, const struct cld_packet *pkt,
 {
 	struct session *sess = mp->sess;
 
-	if (debugging)
+	if (srv_log.verbose)
 		show_msg(msg);
 
 	switch(msg->op) {
@@ -328,12 +332,10 @@ static void pkt_ack_frag(int sock_fd,
 
 	authsign(outpkt, alloc_len);
 
-	if (debugging)
-		applog(LOG_DEBUG, "ack-partial-msg: "
-		       "sid " SIDFMT ", op %s, seqid %llu",
-		       SIDARG(outpkt->sid),
-		       opstr(ack_msg->hdr.op),
-		       (unsigned long long) le64_to_cpu(outpkt->seqid));
+	CLD_DEBUG(&srv_log, "ack-partial-msg: "
+		"sid " SIDFMT ", op %s, seqid %llu",
+		SIDARG(outpkt->sid), opstr(ack_msg->hdr.op),
+		(unsigned long long) le64_to_cpu(outpkt->seqid));
 
 	/* transmit ack-partial-msg response (once, without retries) */
 	udp_tx(sock_fd, (struct sockaddr *) &cli->addr, cli->addr_len,
@@ -386,15 +388,12 @@ static void udp_rx(int sock_fd,
 	mp.msg = msg;
 	mp.msg_len = pkt_len - sizeof(*pkt) - SHA_DIGEST_LENGTH;
 
-	if (debugging > 1)
-		applog(LOG_DEBUG, "pkt: len %zu, seqid %llu, sid " SIDFMT ", "
-		       "flags %s%s, user %s",
-		       pkt_len,
-		       (unsigned long long) le64_to_cpu(pkt->seqid),
-		       SIDARG(pkt->sid),
-		       first_frag ? "F" : "",
-		       last_frag ? "L" : "",
-		       pkt->user);
+	CLD_DEBUG(&srv_log, "pkt: len %zu, seqid %llu, sid " SIDFMT ", "
+		"flags %s%s, user %s",
+		pkt_len, (unsigned long long) le64_to_cpu(pkt->seqid),
+		SIDARG(pkt->sid),
+		first_frag ? "F" : "", last_frag ? "L" : "",
+		pkt->user);
 
 	/* advance sequence id's and update last-contact timestamp */
 	if (!have_new_sess) {
@@ -409,8 +408,7 @@ static void udp_rx(int sock_fd,
 		if (!have_ack) {
 			/* eliminate duplicates; do not return any response */
 			if (le64_to_cpu(pkt->seqid) != sess->next_seqid_in) {
-				if (debugging)
-					applog(LOG_DEBUG, "dropping dup");
+				CLD_DEBUG(&srv_log, "dropping dup");
 				return;
 			}
 
@@ -421,8 +419,7 @@ static void udp_rx(int sock_fd,
 		if (sess) {
 			/* eliminate duplicates; do not return any response */
 			if (le64_to_cpu(pkt->seqid) != sess->next_seqid_in) {
-				if (debugging)
-					applog(LOG_DEBUG, "dropping dup");
+				CLD_DEBUG(&srv_log, "dropping dup");
 				return;
 			}
 
@@ -452,8 +449,8 @@ static void udp_rx(int sock_fd,
 		mp.msg = msg = (struct cld_msg_hdr *) sess->msg_buf;
 		mp.msg_len = sess->msg_buf_len;
 
-		if ((debugging > 1) && !first_frag)
-			applog(LOG_DEBUG, "    final message size %u",
+		if ((srv_log.verbose > 1) && !first_frag)
+			CLD_DEBUG(&srv_log, "    final message size %u",
 			       sess->msg_buf_len);
 	}
 
@@ -475,13 +472,11 @@ err_out:
 
 	authsign(outpkt, alloc_len);
 
-	if (debugging)
-		applog(LOG_DEBUG, "udp_rx err: "
-		       "sid " SIDFMT ", op %s, seqid %llu, code %d",
-		       SIDARG(outpkt->sid),
-		       opstr(resp->hdr.op),
-		       (unsigned long long) le64_to_cpu(outpkt->seqid),
-		       resp_rc);
+	CLD_DEBUG(&srv_log, "udp_rx err: "
+		"sid " SIDFMT ", op %s, seqid %llu, code %d",
+		SIDARG(outpkt->sid), opstr(resp->hdr.op),
+		(unsigned long long) le64_to_cpu(outpkt->seqid),
+		resp_rc);
 
 	udp_tx(sock_fd, (struct sockaddr *) &cli->addr, cli->addr_len,
 	       outpkt, alloc_len);
@@ -523,9 +518,7 @@ static bool udp_srv_event(int fd, short events, void *userdata)
 
 	strcpy(cli.addr_host, host);
 
-	if (debugging)
-		applog(LOG_DEBUG, "client %s message (%d bytes)",
-		       host, (int) rrc);
+	CLD_DEBUG(&srv_log, "client %s message (%d bytes)", host, (int) rrc);
 
 	/* if it is complete garbage, drop immediately */
 	if ((rrc < (sizeof(*pkt) + SHA_DIGEST_LENGTH)) ||
@@ -575,8 +568,7 @@ static void cldb_checkpoint(struct timer *timer)
 
 	gettimeofday(&current_time, NULL);
 
-	if (debugging)
-		applog(LOG_INFO, "db4 checkpoint");
+	CLD_DEBUG(&srv_log, "db4 checkpoint");
 
 	/* flush logs to db, if log files >= 1MB */
 	rc = dbenv->txn_checkpoint(dbenv, 1024, 0, 0);
@@ -841,7 +833,7 @@ static error_t parse_opt (int key, char *arg, struct argp_state *state)
 		break;
 	case 'D':
 		if (atoi(arg) >= 0 && atoi(arg) <= 2)
-			debugging = atoi(arg);
+			srv_log.verbose = atoi(arg);
 		else {
 			fprintf(stderr, "invalid debug level: '%s'\n", arg);
 			argp_usage(state);
@@ -1044,8 +1036,8 @@ int main (int argc, char *argv[])
 	if (rc)
 		goto err_out_pid;
 
-	applog(LOG_INFO, "initialized: dbg %u%s",
-	       debugging,
+	CLD_INFO(&srv_log, "initialized: verbose %u%s",
+	       srv_log.verbose,
 	       strict_free ? ", strict-free" : "");
 
 	/*
@@ -1098,9 +1090,8 @@ static void ensure_root()
 
 	rc = cldb_inode_get_byname(txn, "/", sizeof("/")-1, &inode, false, 0);
 	if (rc == 0) {
-		if (debugging)
-			applog(LOG_DEBUG, "Root inode found, ino %llu",
-			       (unsigned long long) cldino_from_le(inode->inum));
+		CLD_DEBUG(&srv_log, "Root inode found, ino %llu",
+			(unsigned long long) cldino_from_le(inode->inum));
 	} else if (rc == DB_NOTFOUND) {
 		inode = cldb_inode_mem("/", sizeof("/")-1, CIFL_DIR, CLD_INO_ROOT);
 		if (!inode) {
@@ -1119,9 +1110,8 @@ static void ensure_root()
 			goto err_;
 		}
 
-		if (debugging)
-			applog(LOG_DEBUG, "Root inode created, ino %llu",
-			       (unsigned long long) cldino_from_le(inode->inum));
+		CLD_DEBUG(&srv_log, "Root inode created, ino %llu",
+			(unsigned long long) cldino_from_le(inode->inum));
 		free(inode);
 	} else {
 		dbenv->err(dbenv, rc, "Root inode lookup");
diff --git a/server/session.c b/server/session.c
index 09d26fe..06d32dd 100644
--- a/server/session.c
+++ b/server/session.c
@@ -158,8 +158,7 @@ void sessions_free(void)
 
 static void session_trash(struct session *sess)
 {
-	if (debugging)
-		applog(LOG_DEBUG, "session " SIDFMT " sent to garbage",
+	CLD_DEBUG(&srv_log, "session " SIDFMT " sent to garbage",
 		       SIDARG(sess->sid));
 	sess->dead = true;
 }
@@ -391,7 +390,7 @@ int session_dispose(DB_TXN *txn, struct session *sess)
 	session_free(sess, true);
 
 	if (rc)
-		applog(LOG_WARNING, "failed to remove session");
+		CLD_WARN(&srv_log, "failed to remove session");
 
 	return rc;
 }
@@ -435,9 +434,9 @@ static void session_timeout(struct timer *timer)
 		return;	/* timer added; do not time out session */
 	}
 
-	applog(LOG_INFO, "session %s, addr %s sid " SIDFMT,
-	       sess->dead ? "gc'd" : "timeout",
-	       sess->ipaddr, SIDARG(sess->sid));
+	CLD_INFO(&srv_log, "session %s, addr %s sid " SIDFMT,
+		sess->dead ? "gc'd" : "timeout",
+		sess->ipaddr, SIDARG(sess->sid));
 
 	/* open transaction */
 	rc = dbenv->txn_begin(dbenv, NULL, &txn, 0);
@@ -576,13 +575,9 @@ static int sess_retry_output(struct session *sess, time_t *next_retry_out)
 		if (current_time.tv_sec < op->next_retry)
 			continue;
 
-		if (debugging)
-			applog(LOG_DEBUG,
-			       "retry: sid " SIDFMT ", op %s, seqid %llu",
-			       SIDARG(outpkt->sid),
-			       opstr(outmsg->op),
-			       (unsigned long long)
-					le64_to_cpu(outpkt->seqid));
+		CLD_DEBUG(&srv_log, "retry: sid " SIDFMT ", op %s, seqid %llu",
+			SIDARG(outpkt->sid), opstr(outmsg->op),
+			(unsigned long long) le64_to_cpu(outpkt->seqid));
 
 		rc = udp_tx(sess->sock_fd, (struct sockaddr *) &sess->addr,
 			    sess->addr_len, op->pkt, op->pkt_len);
@@ -632,7 +627,7 @@ bool sess_sendmsg(struct session *sess, const void *msg_, size_t msglen,
 	n_pkts = (msglen / CLD_MAX_PKT_MSG_SZ);
 	n_pkts += (msglen % CLD_MAX_PKT_MSG_SZ) ? 1 : 0;
 
-	if (debugging) {
+	if (srv_log.verbose) {
 		const struct cld_msg_hdr *hdr = msg_;
 		const struct cld_msg_resp *rsp;
 
@@ -651,7 +646,7 @@ bool sess_sendmsg(struct session *sess, const void *msg_, size_t msglen,
 		case cmo_get_meta:
 		case cmo_get:
 			rsp = (struct cld_msg_resp *) msg_;
-			applog(LOG_DEBUG, "sendmsg: "
+			CLD_DEBUG(&srv_log, "sendmsg: "
 			       "sid " SIDFMT ", op %s, msglen %u, code %u, "
 			       "xid %llu, xid_in %llu",
 			       SIDARG(sess->sid),
@@ -662,7 +657,7 @@ bool sess_sendmsg(struct session *sess, const void *msg_, size_t msglen,
 			       (unsigned long long) le64_to_cpu(rsp->xid_in));
 			break;
 		default:
-			applog(LOG_DEBUG, "sendmsg: "
+			CLD_DEBUG(&srv_log, "sendmsg: "
 			       "sid " SIDFMT ", op %s, msglen %u",
 			       SIDARG(sess->sid),
 			       opstr(hdr->op),
@@ -771,9 +766,8 @@ void msg_ack(struct msg_params *mp)
 		if (mp->pkt->seqid != outpkt->seqid)
 			continue;
 
-		if (debugging)
-			applog(LOG_DEBUG, "    expiring seqid %llu",
-		           (unsigned long long) le64_to_cpu(outpkt->seqid));
+		CLD_DEBUG(&srv_log, "    expiring seqid %llu",
+			(unsigned long long) le64_to_cpu(outpkt->seqid));
 
 		/* remove and delete the ack'd msg; call ack'd callback */
 		sess->out_q = g_list_delete_link(sess->out_q, tmp1);
@@ -865,18 +859,14 @@ err_out:
 
 	authsign(outpkt, alloc_len);
 
-	if (debugging)
-		applog(LOG_DEBUG,
-		       "new_sess err: sid " SIDFMT ", op %s, seqid %llu",
-		       SIDARG(outpkt->sid),
-		       opstr(resp->hdr.op),
-		       (unsigned long long) le64_to_cpu(outpkt->seqid));
+	CLD_DEBUG(&srv_log, "new_sess err: sid " SIDFMT ", op %s, seqid %llu",
+		SIDARG(outpkt->sid), opstr(resp->hdr.op),
+		(unsigned long long) le64_to_cpu(outpkt->seqid));
 
 	udp_tx(mp->sock_fd, (struct sockaddr *) &mp->cli->addr,
 	       mp->cli->addr_len, outpkt, alloc_len);
 
-	if (debugging)
-		applog(LOG_DEBUG, "NEW-SESS failed: %d", resp_rc);
+	CLD_DEBUG(&srv_log, "NEW-SESS failed: %d", resp_rc);
 }
 
 static void end_sess_done(struct session_outpkt *outpkt)
@@ -971,14 +961,11 @@ static int sess_load_db(GHashTable *ss, DB_TXN *txn)
 
 		session_decode(sess, &raw_sess);
 
-		if (debugging)
-			applog(LOG_DEBUG,
-			       " loaded sid " SIDFMT " next seqid %llu/%llu",
-			       SIDARG(sess->sid),
-			       (unsigned long long)
-					le64_to_cpu(sess->next_seqid_out),
-			       (unsigned long long)
-					le64_to_cpu(sess->next_seqid_in));
+		CLD_DEBUG(&srv_log, " loaded sid " SIDFMT
+			" next seqid %llu/%llu",
+			SIDARG(sess->sid),
+			(unsigned long long) le64_to_cpu(sess->next_seqid_out),
+			(unsigned long long) le64_to_cpu(sess->next_seqid_in));
 
 		g_hash_table_insert(ss, sess->sid, sess);
 
diff --git a/server/util.c b/server/util.c
index 36fa219..ffe069f 100644
--- a/server/util.c
+++ b/server/util.c
@@ -47,8 +47,9 @@ int write_pid_file(const char *pid_fn)
 	fd = open(pid_fn, O_WRONLY | O_CREAT, S_IRUSR | S_IWUSR);
 	if (fd < 0) {
 		err = errno;
-		applog(LOG_ERR, "Cannot open PID file %s: %s",
-		       pid_fn, strerror(err));
+
+		CLD_ERR(&srv_log, "Cannot open PID file %s: %s",
+			pid_fn, strerror(err));
 		return -err;
 	}
 
@@ -59,11 +60,11 @@ int write_pid_file(const char *pid_fn)
 	if (fcntl(fd, F_SETLK, &lock) != 0) {
 		err = errno;
 		if (err == EAGAIN) {
-			applog(LOG_ERR, "PID file %s is already locked",
-			       pid_fn);
+			CLD_ERR(&srv_log, "PID file %s is already locked",
+				pid_fn);
 		} else {
-			applog(LOG_ERR, "Cannot lock PID file %s: %s",
-			       pid_fn, strerror(err));
+			CLD_ERR(&srv_log, "Cannot lock PID file %s: %s",
+				pid_fn, strerror(err));
 		}
 		close(fd);
 		return -err;
@@ -76,8 +77,8 @@ int write_pid_file(const char *pid_fn)
 		ssize_t rc = write(fd, s, bytes);
 		if (rc < 0) {
 			err = errno;
-			applog(LOG_ERR, "PID number write failed: %s",
-			       strerror(err));
+			CLD_ERR(&srv_log, "PID number write failed: %s",
+				strerror(err));
 			goto err_out;
 		}
 
@@ -88,7 +89,7 @@ int write_pid_file(const char *pid_fn)
 	/* make sure file data is written to disk */
 	if (fsync(fd) < 0) {
 		err = errno;
-		applog(LOG_ERR, "PID file fsync failed: %s", strerror(err));
+		CLD_ERR(&srv_log, "PID file fsync failed: %s", strerror(err));
 		goto err_out;
 	}
 
@@ -102,7 +103,7 @@ err_out:
 
 void syslogerr(const char *prefix)
 {
-	applog(LOG_ERR, "%s: %s", prefix, strerror(errno));
+	CLD_ERR(&srv_log, "%s: %s", prefix, strerror(errno));
 }
 
 int fsetflags(const char *prefix, int fd, int or_flags)
@@ -112,7 +113,7 @@ int fsetflags(const char *prefix, int fd, int or_flags)
 	/* get current flags */
 	old_flags = fcntl(fd, F_GETFL);
 	if (old_flags < 0) {
-		applog(LOG_ERR, "%s F_GETFL: %s", prefix, strerror(errno));
+		CLD_ERR(&srv_log, "%s F_GETFL: %s", prefix, strerror(errno));
 		return -errno;
 	}
 
@@ -123,8 +124,8 @@ int fsetflags(const char *prefix, int fd, int or_flags)
 	/* set new flags */
 	if (flags != old_flags)
 		if (fcntl(fd, F_SETFL, flags) < 0) {
-			applog(LOG_ERR, "%s F_SETFL: %s", prefix,
-			       strerror(errno));
+			CLD_ERR(&srv_log, "%s F_SETFL: %s", prefix,
+				strerror(errno));
 			rc = -errno;
 		}
 
-- 
1.6.2.5

[PATCH 5/6] cld: modify cld-dns to use logging macros

[Colin McCabe]

Signed-off-by: Colin McCabe <cmccabe@alumni.cmu.edu>
---
 include/cldc.h |    7 ++---
 lib/cldc-dns.c |   80 +++++++++++++++++++++-----------------------------------
 tools/cldcli.c |   12 +++++---
 3 files changed, 41 insertions(+), 58 deletions(-)

diff --git a/include/cldc.h b/include/cldc.h
index 70062cf..f0a1b37 100644
--- a/include/cldc.h
+++ b/include/cldc.h
@@ -200,14 +200,13 @@ extern int cldc_udp_pkt_send(void *private,
 			  const void *buf, size_t buflen);
 
 /* cldc-dns */
-extern int cldc_getaddr(GList **host_list, const char *thishost, bool verbose,
-		 void (*act_log)(int prio, const char *fmt, ...));
+extern int cldc_getaddr(GList **host_list, const char *thishost,
+			struct cld_log *log);
 extern int cldc_saveaddr(struct cldc_host *hp,
 			 unsigned int priority,
 			 unsigned int weight, unsigned int port,
 			 unsigned int nlen, const char *name,
-			 bool verbose,
-			 void (*act_log)(int prio, const char *fmt, ...));
+			 struct cld_log *log);
 
 static inline bool seqid_after_eq(uint64_t a_, uint64_t b_)
 {
diff --git a/lib/cldc-dns.c b/lib/cldc-dns.c
index 89800ba..f28cc92 100644
--- a/lib/cldc-dns.c
+++ b/lib/cldc-dns.c
@@ -21,8 +21,7 @@ int cldc_saveaddr(struct cldc_host *hp,
 			 unsigned int priority,
 			 unsigned int weight, unsigned int port,
 			 unsigned int nlen, const char *name,
-			 bool verbose,
-			 void (*act_log)(int prio, const char *fmt, ...))
+			 struct cld_log *log)
 {
 	char portstr[11];
 	char *hostname;
@@ -47,7 +46,7 @@ int cldc_saveaddr(struct cldc_host *hp,
 
 	rc = getaddrinfo(hostname, portstr, &hints, &res0);
 	if (rc) {
-		act_log(LOG_INFO, "getaddrinfo(%s,%s) failed: %s",
+		CLD_INFO(log, "getaddrinfo(%s,%s) failed: %s",
 		       hostname, portstr, gai_strerror(rc));
 		rc = -EINVAL;
 		goto err_addr;
@@ -66,7 +65,7 @@ int cldc_saveaddr(struct cldc_host *hp,
 	}
 
 	if (!something_suitable) {
-		act_log(LOG_INFO, "Host %s port %u has no addresses",
+		CLD_INFO(log, "Host %s port %u has no addresses",
 		       hostname, port);
 		rc = -EINVAL;
 		goto err_suitable;
@@ -77,11 +76,8 @@ int cldc_saveaddr(struct cldc_host *hp,
 	hp->prio = priority;
 	hp->weight = weight;
 
-	if (verbose) {
-		act_log(LOG_DEBUG,
-		       "Found CLD host %s prio %d weight %d",
-		       hostname, priority, weight);
-	}
+	CLD_DEBUG(log, "Found CLD host %s prio %d weight %d",
+			hostname, priority, weight);
 
 	freeaddrinfo(res0);
 	return 0;
@@ -100,8 +96,7 @@ err_name:
  * on YP-driven networks with nonqualified hostnames (at least for now).
  */
 static int cldc_make_fqdn(char *buf, int size, const char *srvname,
-			  const char *thishost,
-		 	  void (*act_log)(int prio, const char *fmt, ...))
+			  const char *thishost, struct cld_log *log)
 {
 	char *s;
 	int nlen;
@@ -109,29 +104,26 @@ static int cldc_make_fqdn(char *buf, int size, const char *srvname,
 
 	nlen = strlen(srvname);
 	if (nlen >= size-20) {
-		act_log(LOG_INFO,
-		       "cldc_getaddr: internal error (nlen %d size %d)",
+		CLD_INFO(log, "cldc_getaddr: internal error "
+			"(nlen %d size %d)",
 		       nlen, size);
 		return -1;
 	}
 
 	if (thishost == NULL) {
-		act_log(LOG_INFO,
-			"cldc_getaddr: internal error (null hostname)");
+		CLD_INFO(log, "cldc_getaddr: internal error (null hostname)");
 		return -1;
 	}
 	if ((s = strchr(thishost, '.')) == NULL) {
-		act_log(LOG_INFO,
-		       "cldc_getaddr: hostname is not FQDN: \"%s\"",
-		       thishost);
+		CLD_INFO(log, "cldc_getaddr: hostname is not FQDN: \"%s\"",
+			thishost);
 		return -1;
 	}
 	s++;
 
 	dlen = strlen(s);
 	if (nlen + 1 + dlen + 1 > size) {
-		act_log(LOG_INFO,
-		       "cldc_getaddr: domain is too long: \"%s\"", s);
+		CLD_INFO(log, "cldc_getaddr: domain is too long: \"%s\"", s);
 		return -1;
 	}
 
@@ -161,8 +153,8 @@ static void push_host(GList **host_list, struct cldc_host *hp_in)
  * This is not reentrant.  Better be called before any other threads
  * are started.
  */
-int cldc_getaddr(GList **host_list, const char *thishost, bool verbose,
-		 void (*act_log)(int prio, const char *fmt, ...))
+int cldc_getaddr(GList **host_list, const char *thishost,
+		struct cld_log *log)
 {
 	enum { hostsz = 64 };
 	char cldb[hostsz];
@@ -183,7 +175,7 @@ int cldc_getaddr(GList **host_list, const char *thishost, bool verbose,
 	 * is a lookup in the DNS root (probably the standard-compliant
 	 * dot between "_cld" and "_udp" hurts us here).
 	 */
-	if (cldc_make_fqdn(cldb, hostsz, "_cld._udp", thishost, act_log) != 0)
+	if (cldc_make_fqdn(cldb, hostsz, "_cld._udp", thishost, log) != 0)
 		return -1;
 
 do_try_again:
@@ -191,12 +183,11 @@ do_try_again:
 	if (rc < 0) {
 		switch (h_errno) {
 		case HOST_NOT_FOUND:
-			act_log(LOG_INFO,
-				"cldc_getaddr: No _cld._udp SRV record");
+		  CLD_INFO(log, "cldc_getaddr: No _cld._udp SRV record");
 			return -1;
 		case NO_DATA:
-			act_log(LOG_INFO,
-				"cldc_getaddr: Cannot find _cld._udp SRV record");
+			CLD_INFO(log, "cldc_getaddr: Cannot find _cld._udp "
+				"SRV record");
 			return -1;
 		case TRY_AGAIN:
 			if (search_retries-- > 0)
@@ -204,8 +195,7 @@ do_try_again:
 			/* fall through */
 		case NO_RECOVERY:
 		default:
-			act_log(LOG_INFO,
-				"cldc_getaddr: res_search error (%d): %s",
+			CLD_INFO(log, "cldc_getaddr: res_search error (%d): %s",
 				h_errno, hstrerror(h_errno));
 			return -1;
 		}
@@ -213,13 +203,13 @@ do_try_again:
 	rlen = rc;
 
 	if (rlen == 0) {
-		act_log(LOG_INFO,
-			"cldc_getaddr: res_search returned empty reply");
+		CLD_INFO(log, "cldc_getaddr: res_search returned "
+			"empty reply");
 		return -1;
 	}
 
 	if (ns_initparse(resp, rlen, &nsb) < 0) {
-		act_log(LOG_INFO, "cldc_getaddr: ns_initparse error");
+		CLD_INFO(log, "cldc_getaddr: ns_initparse error");
 		return -1;
 	}
 
@@ -237,42 +227,32 @@ do_try_again:
 		case ns_t_srv:
 			rrlen = ns_rr_rdlen(rrb);
 			if (rrlen < 8) {	/* 2+2+2 and 2 for host */
-				if (verbose) {
-					act_log(LOG_DEBUG,
-						"cldc_getaddr: SRV len %d",
-						rrlen);
-				}
+				CLD_DEBUG(log, "cldc_getaddr: SRV len %d",
+					rrlen);
 				break;
 			}
 			p = ns_rr_rdata(rrb);
 			rc = dn_expand(resp, resp+rlen, p+6, hostb, hostsz);
 			if (rc < 0) {
-				if (verbose) {
-					act_log(LOG_DEBUG, "cldc_getaddr: "
-					       "dn_expand error %d", rc);
-				}
+				CLD_DEBUG(log, "cldc_getaddr: "
+					"dn_expand error %d", rc);
 				break;
 			}
 			if (rc < 2) {
-				if (verbose) {
-					act_log(LOG_DEBUG, "cldc_getaddr: "
-					       "dn_expand short %d", rc);
-				}
+				CLD_DEBUG(log, "cldc_getaddr: "
+					"dn_expand short %d", rc);
 				break;
 			}
 
 			if (cldc_saveaddr(&hp, ns_get16(p+0),
 					  ns_get16(p+2), ns_get16(p+4),
-					  rc, hostb, verbose, act_log))
+					  rc, hostb, log))
 				break;
 
 			push_host(host_list, &hp);
 			break;
 		case ns_t_cname:	/* impossible, but */
-			if (verbose) {
-				act_log(LOG_DEBUG,
-					"CNAME in SRV request, ignored");
-			}
+			CLD_DEBUG(log, "CNAME in SRV request, ignored");
 			break;
 		default:
 			;
diff --git a/tools/cldcli.c b/tools/cldcli.c
index 23cba99..52ef49a 100644
--- a/tools/cldcli.c
+++ b/tools/cldcli.c
@@ -97,7 +97,6 @@ struct timer {
 };
 
 static unsigned long thread_running = 1;
-static int debugging;
 static GList *host_list;
 static char clicwd[CLD_PATH_MAX + 1] = "/";
 static int to_thread[2], from_thread[2];
@@ -136,6 +135,11 @@ static void applog(int prio, const char *fmt, ...)
 	va_end(ap);
 }
 
+static struct cld_log cli_log = {
+	.func = applog,
+	.verbose = 0,
+};
+
 static gint timer_cmp(gconstpointer a_, gconstpointer b_)
 {
 	const struct timer *a = a_;
@@ -531,7 +535,7 @@ static void handle_user_command(void)
 
 	read_to_thread(&creq, sizeof(creq));
 
-	if (debugging)
+	if (cli_log.verbose)
 		switch (creq.cmd) {
 		case CREQ_CD:
 		case CREQ_CAT:
@@ -1236,7 +1240,7 @@ static error_t parse_opt (int key, char *arg, struct argp_state *state)
 	switch(key) {
 	case 'D':
 		if (atoi(arg) >= 0 && atoi(arg) <= 2)
-			debugging = atoi(arg);
+			cli_log.verbose = atoi(arg);
 		else {
 			fprintf(stderr, "invalid debug level: '%s'\n", arg);
 			argp_usage(state);
@@ -1304,7 +1308,7 @@ int main (int argc, char *argv[])
 			return 1;
 		}
 		hostb[hostsz-1] = 0;
-		if (cldc_getaddr(&host_list, hostb, debugging, applog)) {
+		if (cldc_getaddr(&host_list, hostb, &cli_log)) {
 			fprintf(stderr, "Unable to find a CLD host\n");
 			return 1;
 		}
-- 
1.6.2.5

[PATCH 6/6] cld: Tweak some log levels in cldc dns

[Colin McCabe]

Signed-off-by: Colin McCabe <cmccabe@alumni.cmu.edu>
---
 lib/cldc-dns.c |   10 +++++-----
 1 files changed, 5 insertions(+), 5 deletions(-)

diff --git a/lib/cldc-dns.c b/lib/cldc-dns.c
index 41bcf60..6e0aec0 100644
--- a/lib/cldc-dns.c
+++ b/lib/cldc-dns.c
@@ -46,7 +46,7 @@ int cldc_saveaddr(struct cldc_host *hp,
 
 	rc = getaddrinfo(hostname, portstr, &hints, &res0);
 	if (rc) {
-		CLD_INFO(log, "getaddrinfo(%s,%s) failed: %s",
+		CLD_ERR(log, "getaddrinfo(%s,%s) failed: %s",
 		       hostname, portstr, gai_strerror(rc));
 		rc = -EINVAL;
 		goto err_addr;
@@ -65,7 +65,7 @@ int cldc_saveaddr(struct cldc_host *hp,
 	}
 
 	if (!something_suitable) {
-		CLD_INFO(log, "Host %s port %u has no addresses",
+		CLD_ERR(log, "Host %s port %u has no addresses",
 		       hostname, port);
 		rc = -EINVAL;
 		goto err_suitable;
@@ -196,8 +196,8 @@ do_try_again:
 			/* fall through */
 		case NO_RECOVERY:
 		default:
-			CLD_INFO(log, "cldc_getaddr: res_search error (%d): %s",
-				h_errno, hstrerror(h_errno));
+			CLD_ERR(log, "cldc_getaddr: res_search error "
+				"(%d): %s", h_errno, hstrerror(h_errno));
 			return -1;
 		}
 	}
@@ -210,7 +210,7 @@ do_try_again:
 	}
 
 	if (ns_initparse(resp, rlen, &nsb) < 0) {
-		CLD_INFO(log, "cldc_getaddr: ns_initparse error");
+		CLD_ERR(log, "cldc_getaddr: ns_initparse error");
 		return -1;
 	}
 
-- 
1.6.2.5

Re: [PATCH 4/6] cld: modify server code to use logging macros

[Pete Zaitcev]

On Mon,  7 Dec 2009 16:43:02 -0800
Colin McCabe <cmccabe@alumni.cmu.edu> wrote:

> +++ b/server/cld.h
> @@ -26,6 +26,7 @@
>  #include <glib.h>
>  #include "cldb.h"
>  #include <cld_msg.h>
> +#include "common.h"
>  #include <libtimer.h>

This should be <common.h> since it's common (in include).

> -extern int debugging;
> +extern struct cld_log srv_log;

> -	applog(LOG_INFO, "databases down");
> +	CLD_INFO(&srv_log, "databases down");

Great, you took code that was common across Hail and made it specific
to CLD again.

-- Pete

Re: [PATCH 4/6] cld: modify server code to use logging macros

[Colin McCabe]

On Tue, Dec 8, 2009 at 10:13 AM, Pete Zaitcev <zaitcev@redhat.com> wrote:
> On Mon,  7 Dec 2009 16:43:02 -0800
> Colin McCabe <cmccabe@alumni.cmu.edu> wrote:
>
>> +++ b/server/cld.h
>> @@ -26,6 +26,7 @@
>>  #include <glib.h>
>>  #include "cldb.h"
>>  #include <cld_msg.h>
>> +#include "common.h"
>>  #include <libtimer.h>
>
> This should be <common.h> since it's common (in include).

Sure

>
>> -extern int debugging;
>> +extern struct cld_log srv_log;
>
>> -     applog(LOG_INFO, "databases down");
>> +     CLD_INFO(&srv_log, "databases down");
>
> Great, you took code that was common across Hail and made it specific
> to CLD again.

I guess I could name the log messages HAIL_INFO, etc. I don't know if
that would be an improvement or not.

Colin

>
> -- Pete
> --
> To unsubscribe from this list: send the line "unsubscribe hail-devel" in
> the body of a message to majordomo@vger.kernel.org
> More majordomo info at  http://vger.kernel.org/majordomo-info.html
>

Re: [PATCH 4/6] cld: modify server code to use logging macros

[Jeff Garzik]

On 12/08/2009 01:13 PM, Pete Zaitcev wrote:
> On Mon,  7 Dec 2009 16:43:02 -0800
> Colin McCabe<cmccabe@alumni.cmu.edu>  wrote:
>
>> +++ b/server/cld.h
>> @@ -26,6 +26,7 @@
>>   #include<glib.h>
>>   #include "cldb.h"
>>   #include<cld_msg.h>
>> +#include "common.h"
>>   #include<libtimer.h>
>
> This should be<common.h>  since it's common (in include).
>
>> -extern int debugging;
>> +extern struct cld_log srv_log;
>
>> -	applog(LOG_INFO, "databases down");
>> +	CLD_INFO(&srv_log, "databases down");
>
> Great, you took code that was common across Hail and made it specific
> to CLD again.

A fair point...  we did just finish changing from cldlog() to applog()

	Jeff

[PATCH 0/6 v2] logging refactoring

[Colin McCabe]

This patch series creates a common.h and populates it with some function
prototypes and logging stuff.

version 2:
* Rename CLD_DEBUG, etc. to HAIL_DEBUG
* use angle brackets for including common.h from include/

Colin McCabe (6):
  cld: Declare common.c functions in common.h
  cld: create logging macros
  cld: modify client code to use logging macros
  cld: modify server code to use logging macros
  cld: modify cld-dns to use logging macros
  cld: Tweak some log levels in cldc dns

 include/cld_msg.h |   10 -----
 include/cldc.h    |   12 +++----
 include/common.h  |   38 ++++++++++++++++++++
 lib/cldc-dns.c    |   82 +++++++++++++++++---------------------------
 lib/cldc.c        |   98 +++++++++++++++++++++-------------------------------
 server/cld.h      |    4 +-
 server/cldb.c     |    6 ++--
 server/msg.c      |   49 +++++++++++---------------
 server/server.c   |   86 ++++++++++++++++++++--------------------------
 server/session.c  |   57 ++++++++++++-------------------
 server/util.c     |   27 +++++++-------
 tools/cldcli.c    |   14 +++++---
 12 files changed, 223 insertions(+), 260 deletions(-)
 create mode 100644 include/common.h

[PATCH 4/6] cld: modify server code to use logging macros

[Colin McCabe]

Signed-off-by: Colin McCabe <cmccabe@alumni.cmu.edu>
---
 server/cld.h     |    4 +-
 server/cldb.c    |    6 ++--
 server/msg.c     |   49 +++++++++++++-----------------
 server/server.c  |   86 ++++++++++++++++++++++++------------------------------
 server/session.c |   57 ++++++++++++++----------------------
 server/util.c    |   27 +++++++++--------
 6 files changed, 100 insertions(+), 129 deletions(-)

diff --git a/server/cld.h b/server/cld.h
index 05c93ad..efe7ee4 100644
--- a/server/cld.h
+++ b/server/cld.h
@@ -26,6 +26,7 @@
 #include <glib.h>
 #include "cldb.h"
 #include <cld_msg.h>
+#include <common.h>
 #include <libtimer.h>
 
 struct client;
@@ -152,7 +153,7 @@ extern int sess_load(GHashTable *ss);
 /* server.c */
 extern const char *opstr(enum cld_msg_ops op);
 extern struct server cld_srv;
-extern int debugging;
+extern struct hail_log srv_log;
 extern struct timeval current_time;
 extern int udp_tx(int sock_fd, struct sockaddr *, socklen_t,
 	    const void *, size_t);
@@ -161,7 +162,6 @@ extern void resp_err(struct session *sess,
 	      const struct cld_msg_hdr *src, enum cle_err_codes errcode);
 extern void resp_ok(struct session *sess, const struct cld_msg_hdr *src);
 extern bool authsign(struct cld_packet *pkt, size_t pkt_len);
-extern void applog(int prio, const char *fmt, ...);
 
 /* util.c */
 extern int write_pid_file(const char *pid_fn);
diff --git a/server/cldb.c b/server/cldb.c
index 2f012e5..a0d3a67 100644
--- a/server/cldb.c
+++ b/server/cldb.c
@@ -241,7 +241,7 @@ int cldb_init(struct cldb *cldb, const char *db_home, const char *db_password,
 
 	rc = db_env_create(&cldb->env, 0);
 	if (rc) {
-		applog(LOG_WARNING, "cldb->env_create failed: %d", rc);
+		HAIL_WARN(&srv_log, "cldb->env_create failed: %d", rc);
 		return rc;
 	}
 
@@ -375,7 +375,7 @@ static int cldb_up(struct cldb *cldb, unsigned int flags)
 
 	cldb->up = true;
 
-	applog(LOG_INFO, "databases up");
+	HAIL_INFO(&srv_log, "databases up");
 	return 0;
 
 err_out_handle_idx:
@@ -417,7 +417,7 @@ void cldb_down(struct cldb *cldb)
 	cldb->inodes = NULL;
 	cldb->sessions = NULL;
 
-	applog(LOG_INFO, "databases down");
+	HAIL_INFO(&srv_log, "databases down");
 }
 
 void cldb_fini(struct cldb *cldb)
diff --git a/server/msg.c b/server/msg.c
index dc5d5fa..609b882 100644
--- a/server/msg.c
+++ b/server/msg.c
@@ -169,7 +169,7 @@ static bool dirdata_append(void **data, size_t *data_len,
 
 	mem = realloc(*data, new_len);
 	if (!mem) {
-		applog(LOG_CRIT, "out of memory for data [%lu]", (long)new_len);
+		HAIL_CRIT(&srv_log, "out of memory for data [%lz]", new_len);
 		return false;
 	}
 
@@ -238,15 +238,14 @@ static int inode_notify(DB_TXN *txn, cldino_t inum, bool deleted)
 
 		sess = g_hash_table_lookup(cld_srv.sessions, h.sid);
 		if (!sess) {
-			applog(LOG_WARNING, "inode_notify BUG");
+			HAIL_WARN(&srv_log, "inode_notify BUG");
 			continue;
 		}
 
 		if (!sess->sock_fd) {		/* Freshly recovered session */
-			if (debugging)
-				applog(LOG_DEBUG,
-				       "Lost notify sid " SIDFMT " ino %lld",
-				       SIDARG(sess->sid), (long long) inum);
+			HAIL_DEBUG(&srv_log, "Lost notify sid " SIDFMT
+				" ino %lld", SIDARG(sess->sid),
+				(long long) inum);
 			continue;
 		}
 
@@ -363,7 +362,7 @@ int inode_lock_rescan(DB_TXN *txn, cldino_t inum)
 
 		sess = g_hash_table_lookup(cld_srv.sessions, lock.sid);
 		if (!sess) {
-			applog(LOG_WARNING, "inode_lock_rescan BUG");
+			HAIL_WARN(&srv_log, "inode_lock_rescan BUG");
 			break;
 		}
 
@@ -372,10 +371,9 @@ int inode_lock_rescan(DB_TXN *txn, cldino_t inum)
 		 */
 
 		if (!sess->sock_fd) {		/* Freshly recovered session */
-			if (debugging)
-				applog(LOG_DEBUG,
-				       "Lost success sid " SIDFMT " ino %lld",
-				       SIDARG(sess->sid), (long long) inum);
+			HAIL_DEBUG(&srv_log, "Lost success sid " SIDFMT
+				" ino %lld", SIDARG(sess->sid),
+				(long long) inum);
 			continue;
 		}
 
@@ -455,13 +453,10 @@ void msg_get(struct msg_params *mp, bool metadata_only)
 		goto err_out;
 	}
 
-	if (debugging)
-		applog(LOG_DEBUG, "GET-DEBUG: sizeof(resp) %u, name_len %u, "
-		       "inode->size %u, resp_len %u",
-		       sizeof(*resp),
-		       name_len,
-		       inode_size,
-		       resp_len);
+	HAIL_DEBUG(&srv_log, "GET-DEBUG: sizeof(resp) %u, name_len %u, "
+		"inode->size %u, resp_len %u",
+		sizeof(*resp), name_len,
+		inode_size, resp_len);
 
 	/* return response containing inode metadata */
 	memset(resp, 0, resp_len);
@@ -610,7 +605,7 @@ void msg_open(struct msg_params *mp)
 		/* create new in-memory inode */
 		inode = cldb_inode_new(txn, name, name_len, 0);
 		if (!inode) {
-			applog(LOG_CRIT, "cannot allocate new inode");
+			HAIL_CRIT(&srv_log, "cannot allocate new inode");
 			resp_rc = CLE_OOM;
 			goto err_out;
 		}
@@ -667,7 +662,7 @@ void msg_open(struct msg_params *mp)
 	/* alloc & init new handle; updates session's next_fh */
 	h = cldb_handle_new(mp->sess, inum, msg_mode, msg_events);
 	if (!h) {
-		applog(LOG_CRIT, "cannot allocate handle");
+		HAIL_CRIT(&srv_log, "cannot allocate handle");
 		resp_rc = CLE_OOM;
 		goto err_out;
 	}
@@ -695,7 +690,7 @@ void msg_open(struct msg_params *mp)
 	raw_sess = session_new_raw(mp->sess);
 
 	if (!raw_sess) {
-		applog(LOG_CRIT, "cannot allocate session");
+		HAIL_CRIT(&srv_log, "cannot allocate session");
 		resp_rc = CLE_OOM;
 		goto err_out;
 	}
@@ -762,12 +757,10 @@ void msg_put(struct msg_params *mp)
 	/* make sure additional input data as large as expected */
 	data_size = le32_to_cpu(msg->data_size);
 	if (mp->msg_len != (data_size + sizeof(*msg))) {
-		applog(LOG_INFO, "PUT len mismatch: msg len %zu, "
-		       "wanted %zu + %u (== %u)",
-		       mp->msg_len,
-		       sizeof(*msg),
-		       data_size,
-		       data_size + sizeof(*msg));
+		HAIL_INFO(&srv_log, "PUT len mismatch: msg len %zu, "
+			"wanted %zu + %u (== %u)",
+			mp->msg_len,
+			sizeof(*msg), data_size, data_size + sizeof(*msg));
 		resp_rc = CLE_BAD_PKT;
 		goto err_out_noabort;
 	}
@@ -1067,7 +1060,7 @@ void msg_del(struct msg_params *mp)
 	/* remove record from inode's directory data */
 	if (!dirdata_delete(parent_data, &parent_len,
 			    pinfo.base, pinfo.base_len)) {
-		applog(LOG_WARNING, "dirent del failed");
+		HAIL_WARN(&srv_log, "dirent del failed");
 		resp_rc = CLE_DB_ERR;
 		goto err_out;
 	}
diff --git a/server/server.c b/server/server.c
index 39d1a54..f5ac7ce 100644
--- a/server/server.c
+++ b/server/server.c
@@ -37,6 +37,7 @@
 #include <openssl/hmac.h>
 #include <cld-private.h>
 #include "cld.h"
+#include <common.h>
 
 #define PROGRAM_NAME "cld"
 
@@ -84,7 +85,6 @@ static bool server_running = true;
 static bool dump_stats;
 static bool use_syslog = true;
 static bool strict_free = false;
-int debugging = 0;
 struct timeval current_time;
 
 struct server cld_srv = {
@@ -95,7 +95,7 @@ struct server cld_srv = {
 
 static void ensure_root(void);
 
-void applog(int prio, const char *fmt, ...)
+static void applog(int prio, const char *fmt, ...)
 {
 	va_list ap;
 
@@ -116,13 +116,17 @@ void applog(int prio, const char *fmt, ...)
 	va_end(ap);
 }
 
+struct hail_log srv_log = {
+	.func = applog,
+	.verbose = 0,
+};
+
 int udp_tx(int sock_fd, struct sockaddr *addr, socklen_t addr_len,
 	   const void *data, size_t data_len)
 {
 	ssize_t src;
 
-	if (debugging > 1)
-		applog(LOG_DEBUG, "udp_tx, fd %d", sock_fd);
+	HAIL_DEBUG(&srv_log, "udp_tx, fd %d", sock_fd);
 
 	src = sendto(sock_fd, data, data_len, 0, addr, addr_len);
 	if (src < 0 && errno != EAGAIN)
@@ -267,7 +271,7 @@ static void show_msg(const struct cld_msg_hdr *msg)
 	case cmo_not_master:
 	case cmo_event:
 	case cmo_ack_frag:
-		applog(LOG_DEBUG, "msg: op %s, xid %llu",
+		HAIL_DEBUG(&srv_log, "msg: op %s, xid %llu",
 		       opstr(msg->op),
 		       (unsigned long long) le64_to_cpu(msg->xid));
 		break;
@@ -279,7 +283,7 @@ static void udp_rx_msg(const struct client *cli, const struct cld_packet *pkt,
 {
 	struct session *sess = mp->sess;
 
-	if (debugging)
+	if (srv_log.verbose)
 		show_msg(msg);
 
 	switch(msg->op) {
@@ -328,12 +332,10 @@ static void pkt_ack_frag(int sock_fd,
 
 	authsign(outpkt, alloc_len);
 
-	if (debugging)
-		applog(LOG_DEBUG, "ack-partial-msg: "
-		       "sid " SIDFMT ", op %s, seqid %llu",
-		       SIDARG(outpkt->sid),
-		       opstr(ack_msg->hdr.op),
-		       (unsigned long long) le64_to_cpu(outpkt->seqid));
+	HAIL_DEBUG(&srv_log, "ack-partial-msg: "
+		"sid " SIDFMT ", op %s, seqid %llu",
+		SIDARG(outpkt->sid), opstr(ack_msg->hdr.op),
+		(unsigned long long) le64_to_cpu(outpkt->seqid));
 
 	/* transmit ack-partial-msg response (once, without retries) */
 	udp_tx(sock_fd, (struct sockaddr *) &cli->addr, cli->addr_len,
@@ -386,15 +388,12 @@ static void udp_rx(int sock_fd,
 	mp.msg = msg;
 	mp.msg_len = pkt_len - sizeof(*pkt) - SHA_DIGEST_LENGTH;
 
-	if (debugging > 1)
-		applog(LOG_DEBUG, "pkt: len %zu, seqid %llu, sid " SIDFMT ", "
-		       "flags %s%s, user %s",
-		       pkt_len,
-		       (unsigned long long) le64_to_cpu(pkt->seqid),
-		       SIDARG(pkt->sid),
-		       first_frag ? "F" : "",
-		       last_frag ? "L" : "",
-		       pkt->user);
+	HAIL_DEBUG(&srv_log, "pkt: len %zu, seqid %llu, sid " SIDFMT ", "
+		"flags %s%s, user %s",
+		pkt_len, (unsigned long long) le64_to_cpu(pkt->seqid),
+		SIDARG(pkt->sid),
+		first_frag ? "F" : "", last_frag ? "L" : "",
+		pkt->user);
 
 	/* advance sequence id's and update last-contact timestamp */
 	if (!have_new_sess) {
@@ -409,8 +408,7 @@ static void udp_rx(int sock_fd,
 		if (!have_ack) {
 			/* eliminate duplicates; do not return any response */
 			if (le64_to_cpu(pkt->seqid) != sess->next_seqid_in) {
-				if (debugging)
-					applog(LOG_DEBUG, "dropping dup");
+				HAIL_DEBUG(&srv_log, "dropping dup");
 				return;
 			}
 
@@ -421,8 +419,7 @@ static void udp_rx(int sock_fd,
 		if (sess) {
 			/* eliminate duplicates; do not return any response */
 			if (le64_to_cpu(pkt->seqid) != sess->next_seqid_in) {
-				if (debugging)
-					applog(LOG_DEBUG, "dropping dup");
+				HAIL_DEBUG(&srv_log, "dropping dup");
 				return;
 			}
 
@@ -452,8 +449,8 @@ static void udp_rx(int sock_fd,
 		mp.msg = msg = (struct cld_msg_hdr *) sess->msg_buf;
 		mp.msg_len = sess->msg_buf_len;
 
-		if ((debugging > 1) && !first_frag)
-			applog(LOG_DEBUG, "    final message size %u",
+		if ((srv_log.verbose > 1) && !first_frag)
+			HAIL_DEBUG(&srv_log, "    final message size %u",
 			       sess->msg_buf_len);
 	}
 
@@ -475,13 +472,11 @@ err_out:
 
 	authsign(outpkt, alloc_len);
 
-	if (debugging)
-		applog(LOG_DEBUG, "udp_rx err: "
-		       "sid " SIDFMT ", op %s, seqid %llu, code %d",
-		       SIDARG(outpkt->sid),
-		       opstr(resp->hdr.op),
-		       (unsigned long long) le64_to_cpu(outpkt->seqid),
-		       resp_rc);
+	HAIL_DEBUG(&srv_log, "udp_rx err: "
+		"sid " SIDFMT ", op %s, seqid %llu, code %d",
+		SIDARG(outpkt->sid), opstr(resp->hdr.op),
+		(unsigned long long) le64_to_cpu(outpkt->seqid),
+		resp_rc);
 
 	udp_tx(sock_fd, (struct sockaddr *) &cli->addr, cli->addr_len,
 	       outpkt, alloc_len);
@@ -523,9 +518,7 @@ static bool udp_srv_event(int fd, short events, void *userdata)
 
 	strcpy(cli.addr_host, host);
 
-	if (debugging)
-		applog(LOG_DEBUG, "client %s message (%d bytes)",
-		       host, (int) rrc);
+	HAIL_DEBUG(&srv_log, "client %s message (%d bytes)", host, (int) rrc);
 
 	/* if it is complete garbage, drop immediately */
 	if ((rrc < (sizeof(*pkt) + SHA_DIGEST_LENGTH)) ||
@@ -575,8 +568,7 @@ static void cldb_checkpoint(struct timer *timer)
 
 	gettimeofday(&current_time, NULL);
 
-	if (debugging)
-		applog(LOG_INFO, "db4 checkpoint");
+	HAIL_DEBUG(&srv_log, "db4 checkpoint");
 
 	/* flush logs to db, if log files >= 1MB */
 	rc = dbenv->txn_checkpoint(dbenv, 1024, 0, 0);
@@ -841,7 +833,7 @@ static error_t parse_opt (int key, char *arg, struct argp_state *state)
 		break;
 	case 'D':
 		if (atoi(arg) >= 0 && atoi(arg) <= 2)
-			debugging = atoi(arg);
+			srv_log.verbose = atoi(arg);
 		else {
 			fprintf(stderr, "invalid debug level: '%s'\n", arg);
 			argp_usage(state);
@@ -1044,8 +1036,8 @@ int main (int argc, char *argv[])
 	if (rc)
 		goto err_out_pid;
 
-	applog(LOG_INFO, "initialized: dbg %u%s",
-	       debugging,
+	HAIL_INFO(&srv_log, "initialized: verbose %u%s",
+	       srv_log.verbose,
 	       strict_free ? ", strict-free" : "");
 
 	/*
@@ -1098,9 +1090,8 @@ static void ensure_root()
 
 	rc = cldb_inode_get_byname(txn, "/", sizeof("/")-1, &inode, false, 0);
 	if (rc == 0) {
-		if (debugging)
-			applog(LOG_DEBUG, "Root inode found, ino %llu",
-			       (unsigned long long) cldino_from_le(inode->inum));
+		HAIL_DEBUG(&srv_log, "Root inode found, ino %llu",
+			(unsigned long long) cldino_from_le(inode->inum));
 	} else if (rc == DB_NOTFOUND) {
 		inode = cldb_inode_mem("/", sizeof("/")-1, CIFL_DIR, CLD_INO_ROOT);
 		if (!inode) {
@@ -1119,9 +1110,8 @@ static void ensure_root()
 			goto err_;
 		}
 
-		if (debugging)
-			applog(LOG_DEBUG, "Root inode created, ino %llu",
-			       (unsigned long long) cldino_from_le(inode->inum));
+		HAIL_DEBUG(&srv_log, "Root inode created, ino %llu",
+			(unsigned long long) cldino_from_le(inode->inum));
 		free(inode);
 	} else {
 		dbenv->err(dbenv, rc, "Root inode lookup");
diff --git a/server/session.c b/server/session.c
index 09d26fe..905acf1 100644
--- a/server/session.c
+++ b/server/session.c
@@ -158,8 +158,7 @@ void sessions_free(void)
 
 static void session_trash(struct session *sess)
 {
-	if (debugging)
-		applog(LOG_DEBUG, "session " SIDFMT " sent to garbage",
+	HAIL_DEBUG(&srv_log, "session " SIDFMT " sent to garbage",
 		       SIDARG(sess->sid));
 	sess->dead = true;
 }
@@ -391,7 +390,7 @@ int session_dispose(DB_TXN *txn, struct session *sess)
 	session_free(sess, true);
 
 	if (rc)
-		applog(LOG_WARNING, "failed to remove session");
+		HAIL_WARN(&srv_log, "failed to remove session");
 
 	return rc;
 }
@@ -435,9 +434,9 @@ static void session_timeout(struct timer *timer)
 		return;	/* timer added; do not time out session */
 	}
 
-	applog(LOG_INFO, "session %s, addr %s sid " SIDFMT,
-	       sess->dead ? "gc'd" : "timeout",
-	       sess->ipaddr, SIDARG(sess->sid));
+	HAIL_INFO(&srv_log, "session %s, addr %s sid " SIDFMT,
+		sess->dead ? "gc'd" : "timeout",
+		sess->ipaddr, SIDARG(sess->sid));
 
 	/* open transaction */
 	rc = dbenv->txn_begin(dbenv, NULL, &txn, 0);
@@ -576,13 +575,9 @@ static int sess_retry_output(struct session *sess, time_t *next_retry_out)
 		if (current_time.tv_sec < op->next_retry)
 			continue;
 
-		if (debugging)
-			applog(LOG_DEBUG,
-			       "retry: sid " SIDFMT ", op %s, seqid %llu",
-			       SIDARG(outpkt->sid),
-			       opstr(outmsg->op),
-			       (unsigned long long)
-					le64_to_cpu(outpkt->seqid));
+		HAIL_DEBUG(&srv_log, "retry: sid " SIDFMT ", op %s, seqid %llu",
+			SIDARG(outpkt->sid), opstr(outmsg->op),
+			(unsigned long long) le64_to_cpu(outpkt->seqid));
 
 		rc = udp_tx(sess->sock_fd, (struct sockaddr *) &sess->addr,
 			    sess->addr_len, op->pkt, op->pkt_len);
@@ -632,7 +627,7 @@ bool sess_sendmsg(struct session *sess, const void *msg_, size_t msglen,
 	n_pkts = (msglen / CLD_MAX_PKT_MSG_SZ);
 	n_pkts += (msglen % CLD_MAX_PKT_MSG_SZ) ? 1 : 0;
 
-	if (debugging) {
+	if (srv_log.verbose) {
 		const struct cld_msg_hdr *hdr = msg_;
 		const struct cld_msg_resp *rsp;
 
@@ -651,7 +646,7 @@ bool sess_sendmsg(struct session *sess, const void *msg_, size_t msglen,
 		case cmo_get_meta:
 		case cmo_get:
 			rsp = (struct cld_msg_resp *) msg_;
-			applog(LOG_DEBUG, "sendmsg: "
+			HAIL_DEBUG(&srv_log, "sendmsg: "
 			       "sid " SIDFMT ", op %s, msglen %u, code %u, "
 			       "xid %llu, xid_in %llu",
 			       SIDARG(sess->sid),
@@ -662,7 +657,7 @@ bool sess_sendmsg(struct session *sess, const void *msg_, size_t msglen,
 			       (unsigned long long) le64_to_cpu(rsp->xid_in));
 			break;
 		default:
-			applog(LOG_DEBUG, "sendmsg: "
+			HAIL_DEBUG(&srv_log, "sendmsg: "
 			       "sid " SIDFMT ", op %s, msglen %u",
 			       SIDARG(sess->sid),
 			       opstr(hdr->op),
@@ -771,9 +766,8 @@ void msg_ack(struct msg_params *mp)
 		if (mp->pkt->seqid != outpkt->seqid)
 			continue;
 
-		if (debugging)
-			applog(LOG_DEBUG, "    expiring seqid %llu",
-		           (unsigned long long) le64_to_cpu(outpkt->seqid));
+		HAIL_DEBUG(&srv_log, "    expiring seqid %llu",
+			(unsigned long long) le64_to_cpu(outpkt->seqid));
 
 		/* remove and delete the ack'd msg; call ack'd callback */
 		sess->out_q = g_list_delete_link(sess->out_q, tmp1);
@@ -865,18 +859,14 @@ err_out:
 
 	authsign(outpkt, alloc_len);
 
-	if (debugging)
-		applog(LOG_DEBUG,
-		       "new_sess err: sid " SIDFMT ", op %s, seqid %llu",
-		       SIDARG(outpkt->sid),
-		       opstr(resp->hdr.op),
-		       (unsigned long long) le64_to_cpu(outpkt->seqid));
+	HAIL_DEBUG(&srv_log, "new_sess err: sid " SIDFMT ", op %s, seqid %llu",
+		SIDARG(outpkt->sid), opstr(resp->hdr.op),
+		(unsigned long long) le64_to_cpu(outpkt->seqid));
 
 	udp_tx(mp->sock_fd, (struct sockaddr *) &mp->cli->addr,
 	       mp->cli->addr_len, outpkt, alloc_len);
 
-	if (debugging)
-		applog(LOG_DEBUG, "NEW-SESS failed: %d", resp_rc);
+	HAIL_DEBUG(&srv_log, "NEW-SESS failed: %d", resp_rc);
 }
 
 static void end_sess_done(struct session_outpkt *outpkt)
@@ -971,14 +961,11 @@ static int sess_load_db(GHashTable *ss, DB_TXN *txn)
 
 		session_decode(sess, &raw_sess);
 
-		if (debugging)
-			applog(LOG_DEBUG,
-			       " loaded sid " SIDFMT " next seqid %llu/%llu",
-			       SIDARG(sess->sid),
-			       (unsigned long long)
-					le64_to_cpu(sess->next_seqid_out),
-			       (unsigned long long)
-					le64_to_cpu(sess->next_seqid_in));
+		HAIL_DEBUG(&srv_log, " loaded sid " SIDFMT
+			" next seqid %llu/%llu",
+			SIDARG(sess->sid),
+			(unsigned long long) le64_to_cpu(sess->next_seqid_out),
+			(unsigned long long) le64_to_cpu(sess->next_seqid_in));
 
 		g_hash_table_insert(ss, sess->sid, sess);
 
diff --git a/server/util.c b/server/util.c
index 36fa219..9ca53a9 100644
--- a/server/util.c
+++ b/server/util.c
@@ -47,8 +47,9 @@ int write_pid_file(const char *pid_fn)
 	fd = open(pid_fn, O_WRONLY | O_CREAT, S_IRUSR | S_IWUSR);
 	if (fd < 0) {
 		err = errno;
-		applog(LOG_ERR, "Cannot open PID file %s: %s",
-		       pid_fn, strerror(err));
+
+		HAIL_ERR(&srv_log, "Cannot open PID file %s: %s",
+			pid_fn, strerror(err));
 		return -err;
 	}
 
@@ -59,11 +60,11 @@ int write_pid_file(const char *pid_fn)
 	if (fcntl(fd, F_SETLK, &lock) != 0) {
 		err = errno;
 		if (err == EAGAIN) {
-			applog(LOG_ERR, "PID file %s is already locked",
-			       pid_fn);
+			HAIL_ERR(&srv_log, "PID file %s is already locked",
+				pid_fn);
 		} else {
-			applog(LOG_ERR, "Cannot lock PID file %s: %s",
-			       pid_fn, strerror(err));
+			HAIL_ERR(&srv_log, "Cannot lock PID file %s: %s",
+				pid_fn, strerror(err));
 		}
 		close(fd);
 		return -err;
@@ -76,8 +77,8 @@ int write_pid_file(const char *pid_fn)
 		ssize_t rc = write(fd, s, bytes);
 		if (rc < 0) {
 			err = errno;
-			applog(LOG_ERR, "PID number write failed: %s",
-			       strerror(err));
+			HAIL_ERR(&srv_log, "PID number write failed: %s",
+				strerror(err));
 			goto err_out;
 		}
 
@@ -88,7 +89,7 @@ int write_pid_file(const char *pid_fn)
 	/* make sure file data is written to disk */
 	if (fsync(fd) < 0) {
 		err = errno;
-		applog(LOG_ERR, "PID file fsync failed: %s", strerror(err));
+		HAIL_ERR(&srv_log, "PID file fsync failed: %s", strerror(err));
 		goto err_out;
 	}
 
@@ -102,7 +103,7 @@ err_out:
 
 void syslogerr(const char *prefix)
 {
-	applog(LOG_ERR, "%s: %s", prefix, strerror(errno));
+	HAIL_ERR(&srv_log, "%s: %s", prefix, strerror(errno));
 }
 
 int fsetflags(const char *prefix, int fd, int or_flags)
@@ -112,7 +113,7 @@ int fsetflags(const char *prefix, int fd, int or_flags)
 	/* get current flags */
 	old_flags = fcntl(fd, F_GETFL);
 	if (old_flags < 0) {
-		applog(LOG_ERR, "%s F_GETFL: %s", prefix, strerror(errno));
+		HAIL_ERR(&srv_log, "%s F_GETFL: %s", prefix, strerror(errno));
 		return -errno;
 	}
 
@@ -123,8 +124,8 @@ int fsetflags(const char *prefix, int fd, int or_flags)
 	/* set new flags */
 	if (flags != old_flags)
 		if (fcntl(fd, F_SETFL, flags) < 0) {
-			applog(LOG_ERR, "%s F_SETFL: %s", prefix,
-			       strerror(errno));
+			HAIL_ERR(&srv_log, "%s F_SETFL: %s", prefix,
+				strerror(errno));
 			rc = -errno;
 		}
 
-- 
1.6.2.5