[sheepdog] [PATCH v2] add INFO level operation logging on each node.

[Yoshinori Matsuo]

Administrator couldn't track operation on each node without this function.
This function logs only administrative operation at rx_main and tx_main.
Operations that is not related to administrative operation are not
logged in this function. such as read/write etc.

v2
changed logging flag name to is_admin_op.
moved sd_debug to log in rx_main only if is_logging_op() is false.
added sd_debug in tx_main

Signed-off-by: Yoshinori Matsuo <matsuo.yoshinori at lab.ntt.co.jp>
---
 sheep/ops.c        |   22 ++++++++++++++++++++++
 sheep/request.c    |   28 +++++++++++++++++++++++++++-
 sheep/sheep_priv.h |    1 +
 3 files changed, 50 insertions(+), 1 deletions(-)

diff --git a/sheep/ops.c b/sheep/ops.c
index 1e9bc1e..ccc3fff 100644
--- a/sheep/ops.c
+++ b/sheep/ops.c
@@ -27,6 +27,12 @@ struct sd_op_template {
 	bool force;
 
 	/*
+	 * Indicates administrative operation to trace.
+	 * If true is set, rx_main and tx_main log operations at info level.
+	 */
+	bool is_admin_op;
+
+	/*
 	 * process_work() will be called in a worker thread, and process_main()
 	 * will be called in the main thread.
 	 *
@@ -1007,6 +1013,7 @@ static struct sd_op_template sd_ops[] = {
 	[SD_OP_NEW_VDI] = {
 		.name = "NEW_VDI",
 		.type = SD_OP_TYPE_CLUSTER,
+		.is_admin_op = true,
 		.process_work = cluster_new_vdi,
 		.process_main = post_cluster_new_vdi,
 	},
@@ -1014,6 +1021,7 @@ static struct sd_op_template sd_ops[] = {
 	[SD_OP_DEL_VDI] = {
 		.name = "DEL_VDI",
 		.type = SD_OP_TYPE_CLUSTER,
+		.is_admin_op = true,
 		.process_work = cluster_del_vdi,
 		.process_main = post_cluster_del_vdi,
 	},
@@ -1022,6 +1030,7 @@ static struct sd_op_template sd_ops[] = {
 		.name = "MAKE_FS",
 		.type = SD_OP_TYPE_CLUSTER,
 		.force = true,
+		.is_admin_op = true,
 		.process_main = cluster_make_fs,
 	},
 
@@ -1029,6 +1038,7 @@ static struct sd_op_template sd_ops[] = {
 		.name = "SHUTDOWN",
 		.type = SD_OP_TYPE_CLUSTER,
 		.force = true,
+		.is_admin_op = true,
 		.process_main = cluster_shutdown,
 	},
 
@@ -1042,6 +1052,7 @@ static struct sd_op_template sd_ops[] = {
 		.name = "FORCE_RECOVER",
 		.type = SD_OP_TYPE_CLUSTER,
 		.force = true,
+		.is_admin_op = true,
 		.process_work = cluster_force_recover_work,
 		.process_main = cluster_force_recover_main,
 	},
@@ -1095,18 +1106,21 @@ static struct sd_op_template sd_ops[] = {
 	[SD_OP_REWEIGHT] = {
 		.name = "REWEIGHT",
 		.type = SD_OP_TYPE_CLUSTER,
+		.is_admin_op = true,
 		.process_main = cluster_reweight,
 	},
 
 	[SD_OP_ENABLE_RECOVER] = {
 		.name = "ENABLE_RECOVER",
 		.type = SD_OP_TYPE_CLUSTER,
+		.is_admin_op = true,
 		.process_main = cluster_enable_recover,
 	},
 
 	[SD_OP_DISABLE_RECOVER] = {
 		.name = "DISABLE_RECOVER",
 		.type = SD_OP_TYPE_CLUSTER,
+		.is_admin_op = true,
 		.process_main = cluster_disable_recover,
 	},
 
@@ -1226,6 +1240,7 @@ static struct sd_op_template sd_ops[] = {
 		.name = "KILL_NODE",
 		.type = SD_OP_TYPE_LOCAL,
 		.force = true,
+		.is_admin_op = true,
 		.process_main = local_kill_node,
 	},
 
@@ -1238,12 +1253,14 @@ static struct sd_op_template sd_ops[] = {
 	[SD_OP_MD_PLUG] = {
 		.name = "MD_PLUG_DISKS",
 		.type = SD_OP_TYPE_LOCAL,
+		.is_admin_op = true,
 		.process_main = local_md_plug,
 	},
 
 	[SD_OP_MD_UNPLUG] = {
 		.name = "MD_UNPLUG_DISKS",
 		.type = SD_OP_TYPE_LOCAL,
+		.is_admin_op = true,
 		.process_main = local_md_unplug,
 	},
 
@@ -1374,6 +1391,11 @@ bool is_force_op(const struct sd_op_template *op)
 	return !!op->force;
 }
 
+bool is_logging_op(const struct sd_op_template *op)
+{
+	return !!op->is_admin_op;
+}
+
 bool has_process_work(const struct sd_op_template *op)
 {
 	return !!op->process_work;
diff --git a/sheep/request.c b/sheep/request.c
index 9f3f110..bfda665 100644
--- a/sheep/request.c
+++ b/sheep/request.c
@@ -761,7 +761,19 @@ static void rx_main(struct work *work)
 
 	conn_rx_on(&ci->conn);
 
-	sd_debug("%d, %s:%d", ci->conn.fd, ci->conn.ipstr, ci->conn.port);
+	if (is_logging_op(get_sd_op(req->rq.opcode))) {
+		sd_info("req=%p, fd=%d, client=%s:%d, op=%s, data=%s",
+			req,
+			ci->conn.fd,
+			ci->conn.ipstr, ci->conn.port,
+			op_name(get_sd_op(req->rq.opcode)),
+			(char *)req->data);
+	} else {
+		sd_debug("%d, %s:%d",
+			 ci->conn.fd,
+			 ci->conn.ipstr,
+			 ci->conn.port);
+	}
 	queue_request(req);
 }
 
@@ -800,6 +812,20 @@ static void tx_main(struct work *work)
 
 	refcount_dec(&ci->refcnt);
 
+	if (is_logging_op(ci->tx_req->op)) {
+		sd_info("req=%p, fd=%d, client=%s:%d, op=%s, result=%02X",
+			ci->tx_req,
+			ci->conn.fd,
+			ci->conn.ipstr,
+			ci->conn.port,
+			op_name(ci->tx_req->op),
+			ci->tx_req->rp.result);
+	} else {
+		sd_debug("%d, %s:%d",
+			 ci->conn.fd,
+			 ci->conn.ipstr,
+			 ci->conn.port);
+	}
 	free_request(ci->tx_req);
 	ci->tx_req = NULL;
 
diff --git a/sheep/sheep_priv.h b/sheep/sheep_priv.h
index c0a138c..f0e9b9c 100644
--- a/sheep/sheep_priv.h
+++ b/sheep/sheep_priv.h
@@ -412,6 +412,7 @@ bool is_local_op(const struct sd_op_template *op);
 bool is_peer_op(const struct sd_op_template *op);
 bool is_gateway_op(const struct sd_op_template *op);
 bool is_force_op(const struct sd_op_template *op);
+bool is_logging_op(const struct sd_op_template *op);
 bool has_process_work(const struct sd_op_template *op);
 bool has_process_main(const struct sd_op_template *op);
 void do_process_work(struct work *work);
-- 
1.7.2.5