[PATCH 0/6 v2] logging refactoring

[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 1/6] cld: Declare common.c functions in common.h

[Colin McCabe]

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]

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..f6ad4f6 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 HAIL_DEBUG(log, ...) \
+	if ((log)->verbose) { \
+		(log)->func(LOG_DEBUG, __VA_ARGS__); \
+	}
+
+/** Print out an informational log message */
+#define HAIL_INFO(log, ...) \
+	(log)->func(LOG_INFO, __VA_ARGS__);
+
+/** Print out a warning message */
+#define HAIL_WARN(log, ...) \
+	(log)->func(LOG_WARNING, __VA_ARGS__);
+
+/** Print out an error message */
+#define HAIL_ERR(log, ...) \
+	(log)->func(LOG_ERR, __VA_ARGS__);
+
+/** Print out a critical warning message */
+#define HAIL_CRIT(log, ...) \
+	(log)->func(LOG_CRIT, __VA_ARGS__);
+
+struct hail_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]

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..584e026 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		hail_log log;
 	void		*private;
 
 	uint8_t		addr[64];		/* server address */
diff --git a/lib/cldc.c b/lib/cldc.c
index 0ab4f19..c2ea8ab 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");
+		HAIL_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));
+		HAIL_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");
+		HAIL_DEBUG(&sess->log, "rx_gen: re-acking");
 	} else {
-		if (sess->verbose)
-			sess->act_log(LOG_DEBUG,
-				      "rx_gen: issuing completion, acking");
+		HAIL_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);
+	HAIL_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);
+			HAIL_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");
+	HAIL_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");
+		HAIL_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");
+		HAIL_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");
+		HAIL_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");
+		HAIL_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"
+			HAIL_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"
+			HAIL_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)",
+			HAIL_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");
+		HAIL_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");
+		HAIL_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");
+		HAIL_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");
+		HAIL_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: "
+		HAIL_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",
+			HAIL_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));
+		HAIL_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]

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

[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 584e026..abec747 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 hail_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 hail_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..d58a8ba 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 hail_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",
+		HAIL_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",
+		HAIL_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);
-	}
+	HAIL_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 hail_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)",
+		HAIL_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)");
+		HAIL_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);
+		HAIL_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);
+		HAIL_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 hail_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");
+		  HAIL_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");
+			HAIL_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",
+			HAIL_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");
+		HAIL_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");
+		HAIL_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);
-				}
+				HAIL_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);
-				}
+				HAIL_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);
-				}
+				HAIL_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");
-			}
+			HAIL_DEBUG(log, "CNAME in SRV request, ignored");
 			break;
 		default:
 			;
diff --git a/tools/cldcli.c b/tools/cldcli.c
index 23cba99..8eeee72 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 hail_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

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

[Pete Zaitcev]

On Tue,  8 Dec 2009 16:11:55 -0800
Colin McCabe <cmccabe@alumni.cmu.edu> wrote:

> @@ -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 hail_log *log)
>  {

Nothing about the change as such, but you are going to change users
of these public interfaces too, right? I mean Chunk and tabled.

-- Pete

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

[Colin McCabe]

On Wed, Dec 9, 2009 at 12:35 PM, Pete Zaitcev <zaitcev@redhat.com> wrote:
> On Tue,  8 Dec 2009 16:11:55 -0800
> Colin McCabe <cmccabe@alumni.cmu.edu> wrote:
>
>> @@ -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 hail_log *log)
>>  {
>
> Nothing about the change as such, but you are going to change users
> of these public interfaces too, right? I mean Chunk and tabled.
>
> -- Pete
>

d'oh! That's what I get for only running the cld tests. I guess I
should run some chunkd and tabled tests from time to time.

Colin

[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 d58a8ba..1bf6355 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) {
-		HAIL_INFO(log, "getaddrinfo(%s,%s) failed: %s",
+		HAIL_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) {
-		HAIL_INFO(log, "Host %s port %u has no addresses",
+		HAIL_ERR(log, "Host %s port %u has no addresses",
 		       hostname, port);
 		rc = -EINVAL;
 		goto err_suitable;
@@ -195,8 +195,8 @@ do_try_again:
 			/* fall through */
 		case NO_RECOVERY:
 		default:
-			HAIL_INFO(log, "cldc_getaddr: res_search error (%d): %s",
-				h_errno, hstrerror(h_errno));
+			HAIL_ERR(log, "cldc_getaddr: res_search error "
+				"(%d): %s", h_errno, hstrerror(h_errno));
 			return -1;
 		}
 	}
@@ -209,7 +209,7 @@ do_try_again:
 	}
 
 	if (ns_initparse(resp, rlen, &nsb) < 0) {
-		HAIL_INFO(log, "cldc_getaddr: ns_initparse error");
+		HAIL_ERR(log, "cldc_getaddr: ns_initparse error");
 		return -1;
 	}
 
-- 
1.6.2.5

Re: [PATCH 0/6 v2] logging refactoring

[Colin McCabe]

Hi all,

I think I'm going to respin this patch to be a lot smaller. Just
refactor one or two things, but leave the existing "verbose" and
"applog" system in place. Let me know what you think-- do you think I
should push ahead with HAIL_DEBUG etc.,

cheers.
Colin


On Tue, Dec 8, 2009 at 4:11 PM, Colin McCabe <cmccabe@alumni.cmu.edu> wrote:
> 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
>
>

Re: [PATCH 0/6 v2] logging refactoring

[Jeff Garzik]

On 12/14/2009 02:23 AM, Colin McCabe wrote:
> Hi all,
>
> I think I'm going to respin this patch to be a lot smaller. Just
> refactor one or two things, but leave the existing "verbose" and
> "applog" system in place. Let me know what you think-- do you think I
> should push ahead with HAIL_DEBUG etc.,

Well...   I was waiting until today to see if downstream API-related 
patches would appear.  Prior to CLD version 1.0, the "rules" are that 
any and all network protocol or client API changes are OK.  After 1.0, 
we will need to take typical userland library precautions to properly 
version API changes, avoid breakage, etc.

However, even prior to v1.0, API changes do introduce breakage in chunkd 
and tabled.  Typically, if you make a client API change, patches to 
update the other projects should be provided as well.

So I was leaning towards applying and then fixing up chunkd/tabled 
myself, but any proposed alternative described as "just refactor a thing 
or two" is certainly very appealing :)

It's up to you...

	Jeff

Re: [PATCH 0/6 v2] logging refactoring

[Colin McCabe]

On Mon, Dec 14, 2009 at 12:36 PM, Jeff Garzik <jeff@garzik.org> wrote:
> On 12/14/2009 02:23 AM, Colin McCabe wrote:
>>
>> Hi all,
>>
>> I think I'm going to respin this patch to be a lot smaller. Just
>> refactor one or two things, but leave the existing "verbose" and
>> "applog" system in place. Let me know what you think-- do you think I
>> should push ahead with HAIL_DEBUG etc.,
>
> Well...   I was waiting until today to see if downstream API-related patches
> would appear.  Prior to CLD version 1.0, the "rules" are that any and all
> network protocol or client API changes are OK.  After 1.0, we will need to
> take typical userland library precautions to properly version API changes,
> avoid breakage, etc.
>
> However, even prior to v1.0, API changes do introduce breakage in chunkd and
> tabled.  Typically, if you make a client API change, patches to update the
> other projects should be provided as well.
>
> So I was leaning towards applying and then fixing up chunkd/tabled myself,
> but any proposed alternative described as "just refactor a thing or two" is
> certainly very appealing :)

I have some patches to get chunkd and tabled compiling, but I'd need
to run them through some minimal testing.

Also my new patch creates a hail_log.h. It didn't really seem right to
force everyone who wanted to use HAIL_LOG to include cldc.h.

I'll convert over the rest of chunkd and tabled to the new macros if
this patch series gets accepted (but not in this patch series!)

>
> It's up to you...
>

Logic says I shouldn't waste time repainting the logging bike shed.
But then I see a two-line comment turn into five lines because of
indentation, and I just want to put a new coat of paint on that thing.

Anyway, I'll post the patches for the full thing in a bit.

Colin

Re: [PATCH 0/6 v2] logging refactoring

[Pete Zaitcev]

On Mon, 14 Dec 2009 18:18:47 -0800
Colin McCabe <cmccabe@alumni.cmu.edu> wrote:

> Also my new patch creates a hail_log.h. It didn't really seem right to
> force everyone who wanted to use HAIL_LOG to include cldc.h.
> 
> I'll convert over the rest of chunkd and tabled to the new macros if
> this patch series gets accepted (but not in this patch series!)

You know what else would be nice? I find it irritating to include
<syslog.h> everywhere due to 1:1 mapping of LOG_XXX values.
I'm inclined to think that a switch(){} in applog() would be an
acceptable price for getting rid of it.

In fact, does anyone even understand why we continue to split
LOG_WARNING and LOG_ERR? We really have three log levels:
 - debug
 - info (which is actually an error)
 - error (not really all that different from info actually)
Might as well create HAIL_DEBUG, HAIL_INFO, and HAIL_ERR (to be
used before exit(1), with values of 0,1,2 and remap to syslog
values where it goes to syslog.

-- Pete

Re: [PATCH 0/6 v2] logging refactoring

[Jeff Garzik]

On 12/15/2009 01:19 PM, Pete Zaitcev wrote:
> On Mon, 14 Dec 2009 18:18:47 -0800
> Colin McCabe<cmccabe@alumni.cmu.edu>  wrote:
>
>> Also my new patch creates a hail_log.h. It didn't really seem right to
>> force everyone who wanted to use HAIL_LOG to include cldc.h.
>>
>> I'll convert over the rest of chunkd and tabled to the new macros if
>> this patch series gets accepted (but not in this patch series!)
>
> You know what else would be nice? I find it irritating to include
> <syslog.h>  everywhere due to 1:1 mapping of LOG_XXX values.
> I'm inclined to think that a switch(){} in applog() would be an
> acceptable price for getting rid of it.
>
> In fact, does anyone even understand why we continue to split
> LOG_WARNING and LOG_ERR? We really have three log levels:
>   - debug
>   - info (which is actually an error)
>   - error (not really all that different from info actually)
> Might as well create HAIL_DEBUG, HAIL_INFO, and HAIL_ERR (to be
> used before exit(1), with values of 0,1,2 and remap to syslog
> values where it goes to syslog.

It would be nice to disconnect from syslog, yes.  But the 'warning' log 
level has value.

	Jeff

Re: [PATCH 0/6 v2] logging refactoring

[Pete Zaitcev]

On Tue, 15 Dec 2009 17:38:18 -0500
Jeff Garzik <jeff@garzik.org> wrote:

> > In fact, does anyone even understand why we continue to split
> > LOG_WARNING and LOG_ERR? We really have three log levels:
> >   - debug
> >   - info (which is actually an error)
> >   - error (not really all that different from info actually)
> > Might as well create HAIL_DEBUG, HAIL_INFO, and HAIL_ERR (to be
> > used before exit(1), with values of 0,1,2 and remap to syslog
> > values where it goes to syslog.
> 
> It would be nice to disconnect from syslog, yes.  But the 'warning' log 
> level has value.

Can you offer any guidelines that are easy to follow and enforce?
I am often confused and select the level randomly. The only rule
I follow is: if and only if it's under if (debugging), then LOG_DEBUG.
Otherwise... hmm...

-- Pete

Re: [PATCH 0/6 v2] logging refactoring

[Jeff Garzik]

On 12/15/2009 05:47 PM, Pete Zaitcev wrote:
> On Tue, 15 Dec 2009 17:38:18 -0500
> Jeff Garzik<jeff@garzik.org>  wrote:
>
>>> In fact, does anyone even understand why we continue to split
>>> LOG_WARNING and LOG_ERR? We really have three log levels:
>>>    - debug
>>>    - info (which is actually an error)
>>>    - error (not really all that different from info actually)
>>> Might as well create HAIL_DEBUG, HAIL_INFO, and HAIL_ERR (to be
>>> used before exit(1), with values of 0,1,2 and remap to syslog
>>> values where it goes to syslog.
>>
>> It would be nice to disconnect from syslog, yes.  But the 'warning' log
>> level has value.
>
> Can you offer any guidelines that are easy to follow and enforce?
> I am often confused and select the level randomly. The only rule
> I follow is: if and only if it's under if (debugging), then LOG_DEBUG.
> Otherwise... hmm...

Sure, man 3 syslog :)

Err - error message, that will probably kill the server.
Warn - warning message - bad, but not fatal to the server
info - information message, like startup messages
debug - debugging messages, of interest mainly to programmers

	Jeff