[sheepdog] [PATCH stable-0.7 1/2] add INFO level operation logging on each node.

[Hitoshi Mitake]

From: Yoshinori Matsuo <matsuo.yoshinori at lab.ntt.co.jp>

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.

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

diff --git a/sheep/ops.c b/sheep/ops.c
index 75b07f6..1a35a21 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.
 	 *
@@ -1011,6 +1017,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,
 	},
@@ -1018,6 +1025,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,
 	},
@@ -1026,6 +1034,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,
 	},
 
@@ -1033,6 +1042,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,
 	},
 
@@ -1046,6 +1056,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,
 	},
@@ -1099,18 +1110,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,
 	},
 
@@ -1230,6 +1244,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,
 	},
 
@@ -1242,12 +1257,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,
 	},
 
@@ -1366,6 +1383,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 29781cc..fbdc904 100644
--- a/sheep/request.c
+++ b/sheep/request.c
@@ -580,7 +580,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);
 }
 
@@ -619,6 +631,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 2199284..19db37e 100644
--- a/sheep/sheep_priv.h
+++ b/sheep/sheep_priv.h
@@ -373,6 +373,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.10.4