[PATCH rfc 0/2] nvmet nice logging helpers

[PATCH rfc 0/2] nvmet nice logging helpers

[Sagi Grimberg]

This patch set adds some friendly logging helpers with similar
functionality to dev_[err|warn|info|dbg]. When building a
target system with multiple ports and multiple controllers
connected, its useful to have a coherent log message formats
that provide the affected port and controller identifier.

The one annoying thing is that for xxxx_dbg helper I needed
to open-code the dynamic debug macros. If anyone has a better
idea on how to have it, it'd be great (without allocating a class
device for it).

Feedback is welcome.

Sagi Grimberg (2):
  nvmet: add nvmet port logging helpers
  nvmet: add nvmet ctrl logging helpers

 drivers/nvme/target/admin-cmd.c   | 11 ++++-----
 drivers/nvme/target/configfs.c    | 37 +++++++++++-----------------
 drivers/nvme/target/core.c        | 20 +++++++--------
 drivers/nvme/target/discovery.c   | 13 +++++-----
 drivers/nvme/target/fabrics-cmd.c | 15 +++++------
 drivers/nvme/target/io-cmd-bdev.c |  5 ++--
 drivers/nvme/target/nvmet.h       | 44 +++++++++++++++++++++++++++++++++
 drivers/nvme/target/rdma.c        | 52 ++++++++++++++++++++++-----------------
 8 files changed, 122 insertions(+), 75 deletions(-)

-- 
2.14.1

[PATCH rfc 1/2] nvmet: add nvmet port logging helpers

[Sagi Grimberg]

prettify port related logging when we have multiple ports in
the system. Now port logging helpers will use the format
"nvmet portX: ...".

Signed-off-by: Sagi Grimberg <sagi at grimberg.me>
---
 drivers/nvme/target/configfs.c | 37 +++++++++++++++----------------------
 drivers/nvme/target/nvmet.h    | 27 +++++++++++++++++++++++++++
 drivers/nvme/target/rdma.c     | 26 ++++++++++++++------------
 3 files changed, 56 insertions(+), 34 deletions(-)

diff --git a/drivers/nvme/target/configfs.c b/drivers/nvme/target/configfs.c
index 3ba5ea5c4376..8c9b75640c30 100644
--- a/drivers/nvme/target/configfs.c
+++ b/drivers/nvme/target/configfs.c
@@ -59,8 +59,7 @@ static ssize_t nvmet_addr_adrfam_store(struct config_item *item,
 	struct nvmet_port *port = to_nvmet_port(item);
 
 	if (port->enabled) {
-		pr_err("Cannot modify address while enabled\n");
-		pr_err("Disable the address before modifying\n");
+		port_err(port, "Cannot modify address while enabled\n");
 		return -EACCES;
 	}
 
@@ -73,7 +72,7 @@ static ssize_t nvmet_addr_adrfam_store(struct config_item *item,
 	} else if (sysfs_streq(page, "fc")) {
 		port->disc_addr.adrfam = NVMF_ADDR_FAMILY_FC;
 	} else {
-		pr_err("Invalid value '%s' for adrfam\n", page);
+		port_err(port, "Invalid value '%s' for adrfam\n", page);
 		return -EINVAL;
 	}
 
@@ -98,13 +97,12 @@ static ssize_t nvmet_addr_portid_store(struct config_item *item,
 	u16 portid = 0;
 
 	if (kstrtou16(page, 0, &portid)) {
-		pr_err("Invalid value '%s' for portid\n", page);
+		port_err(port, "Invalid value '%s' for portid\n", page);
 		return -EINVAL;
 	}
 
 	if (port->enabled) {
-		pr_err("Cannot modify address while enabled\n");
-		pr_err("Disable the address before modifying\n");
+		port_err(port, "Cannot modify address while enabled\n");
 		return -EACCES;
 	}
 	port->disc_addr.portid = cpu_to_le16(portid);
@@ -128,13 +126,12 @@ static ssize_t nvmet_addr_traddr_store(struct config_item *item,
 	struct nvmet_port *port = to_nvmet_port(item);
 
 	if (count > NVMF_TRADDR_SIZE) {
-		pr_err("Invalid value '%s' for traddr\n", page);
+		port_err(port, "Invalid value '%s' for traddr\n", page);
 		return -EINVAL;
 	}
 
 	if (port->enabled) {
-		pr_err("Cannot modify address while enabled\n");
-		pr_err("Disable the address before modifying\n");
+		port_err(port, "Cannot modify address while enabled\n");
 		return -EACCES;
 	}
 
@@ -166,8 +163,7 @@ static ssize_t nvmet_addr_treq_store(struct config_item *item,
 	struct nvmet_port *port = to_nvmet_port(item);
 
 	if (port->enabled) {
-		pr_err("Cannot modify address while enabled\n");
-		pr_err("Disable the address before modifying\n");
+		port_err(port, "Cannot modify address while enabled\n");
 		return -EACCES;
 	}
 
@@ -178,7 +174,7 @@ static ssize_t nvmet_addr_treq_store(struct config_item *item,
 	} else if (sysfs_streq(page, "not required")) {
 		port->disc_addr.treq = NVMF_TREQ_NOT_REQUIRED;
 	} else {
-		pr_err("Invalid value '%s' for treq\n", page);
+		port_err(port, "Invalid value '%s' for treq\n", page);
 		return -EINVAL;
 	}
 
@@ -202,12 +198,11 @@ static ssize_t nvmet_addr_trsvcid_store(struct config_item *item,
 	struct nvmet_port *port = to_nvmet_port(item);
 
 	if (count > NVMF_TRSVCID_SIZE) {
-		pr_err("Invalid value '%s' for trsvcid\n", page);
+		port_err(port, "Invalid value '%s' for trsvcid\n", page);
 		return -EINVAL;
 	}
 	if (port->enabled) {
-		pr_err("Cannot modify address while enabled\n");
-		pr_err("Disable the address before modifying\n");
+		port_err(port, "Cannot modify address while enabled\n");
 		return -EACCES;
 	}
 
@@ -233,13 +228,12 @@ static ssize_t nvmet_param_inline_data_size_store(struct config_item *item,
 	int ret;
 
 	if (port->enabled) {
-		pr_err("Cannot modify inline_data_size while port enabled\n");
-		pr_err("Disable the port before modifying\n");
+		port_err(port, "Cannot modify inline_data_size while port enabled\n");
 		return -EACCES;
 	}
 	ret = kstrtoint(page, 0, &port->inline_data_size);
 	if (ret) {
-		pr_err("Invalid value '%s' for inline_data_size\n", page);
+		port_err(port, "Invalid value '%s' for inline_data_size\n", page);
 		return -EINVAL;
 	}
 	return count;
@@ -276,8 +270,7 @@ static ssize_t nvmet_addr_trtype_store(struct config_item *item,
 	int i;
 
 	if (port->enabled) {
-		pr_err("Cannot modify address while enabled\n");
-		pr_err("Disable the address before modifying\n");
+		port_err(port, "Cannot modify address while enabled\n");
 		return -EACCES;
 	}
 
@@ -286,7 +279,7 @@ static ssize_t nvmet_addr_trtype_store(struct config_item *item,
 			goto found;
 	}
 
-	pr_err("Invalid value '%s' for trtype\n", page);
+	port_err(port, "Invalid value '%s' for trtype\n", page);
 	return -EINVAL;
 found:
 	memset(&port->disc_addr.tsas, 0, NVMF_TSAS_SIZE);
@@ -854,7 +847,7 @@ static ssize_t nvmet_referral_enable_store(struct config_item *item,
 
 	return count;
 inval:
-	pr_err("Invalid value '%s' for enable\n", page);
+	port_err(port, "Invalid value '%s' for enable\n", page);
 	return -EINVAL;
 }
 
diff --git a/drivers/nvme/target/nvmet.h b/drivers/nvme/target/nvmet.h
index 688993855402..6811258ab8ff 100644
--- a/drivers/nvme/target/nvmet.h
+++ b/drivers/nvme/target/nvmet.h
@@ -270,6 +270,33 @@ struct nvmet_req {
 	const struct nvmet_fabrics_ops *ops;
 };
 
+#define port_err(port, fmt, a...)		\
+	printk(KERN_ERR "nvmet port%d: " fmt, \
+		le32_to_cpu((port)->disc_addr.portid), ##a)
+#define port_info(port, fmt, a...)		\
+	printk(KERN_INFO "nvmet port%d: " fmt, \
+		le32_to_cpu((port)->disc_addr.portid), ##a)
+#define port_warn(port, fmt, a...)		\
+	printk(KERN_WARNING "nvmet port%d: " fmt, \
+		le32_to_cpu((port)->disc_addr.portid), ##a)
+
+#if defined(CONFIG_DYNAMIC_DEBUG)
+#include <linux/dynamic_debug.h>
+#define port_dbg(port, fmt, a...)				\
+do {								\
+	DEFINE_DYNAMIC_DEBUG_METADATA(descriptor, fmt);		\
+	if (DYNAMIC_DEBUG_BRANCH(descriptor))			\
+		printk(KERN_DEBUG "nvmet port%d: " fmt, 	\
+			le32_to_cpu((port)->disc_addr.portid), ##a);\
+} while (0)
+#elif defined(DEBUG)
+#define port_dbg(port, fmt, a...)				\
+	printk(KERN_DEBUG "nvmet port%d: " fmt, 	\
+		le32_to_cpu((port)->disc_addr.portid)
+#else
+#define port_dbg(port, fmt, a...) {}
+#endif
+
 extern struct workqueue_struct *buffered_io_wq;
 
 static inline void nvmet_set_status(struct nvmet_req *req, u16 status)
diff --git a/drivers/nvme/target/rdma.c b/drivers/nvme/target/rdma.c
index e7f43d1e1779..71bf6bf57be9 100644
--- a/drivers/nvme/target/rdma.c
+++ b/drivers/nvme/target/rdma.c
@@ -918,7 +918,7 @@ nvmet_rdma_find_get_device(struct rdma_cm_id *cm_id)
 	list_add(&ndev->entry, &device_list);
 out_unlock:
 	mutex_unlock(&device_list_mutex);
-	pr_debug("added %s.\n", ndev->device->name);
+	port_dbg(port, "added %s.\n", ndev->device->name);
 	return ndev;
 
 out_free_pd:
@@ -1273,7 +1273,8 @@ static void nvmet_rdma_queue_established(struct nvmet_rdma_queue *queue)
 
 	spin_lock_irqsave(&queue->state_lock, flags);
 	if (queue->state != NVMET_RDMA_Q_CONNECTING) {
-		pr_warn("trying to establish a connected queue\n");
+		port_warn(queue->port,
+			"trying to establish a connected queue\n");
 		goto out_unlock;
 	}
 	queue->state = NVMET_RDMA_Q_LIVE;
@@ -1299,7 +1300,8 @@ static void __nvmet_rdma_queue_disconnect(struct nvmet_rdma_queue *queue)
 	bool disconnect = false;
 	unsigned long flags;
 
-	pr_debug("cm_id= %p queue->state= %d\n", queue->cm_id, queue->state);
+	port_dbg(queue->port, "cm_id= %p queue->state= %d\n",
+		queue->cm_id, queue->state);
 
 	spin_lock_irqsave(&queue->state_lock, flags);
 	switch (queue->state) {
@@ -1473,7 +1475,7 @@ static int nvmet_rdma_add_port(struct nvmet_port *port)
 		af = AF_INET6;
 		break;
 	default:
-		pr_err("address family %d not supported\n",
+		port_err(port, "address family %d not supported\n",
 				port->disc_addr.adrfam);
 		return -EINVAL;
 	}
@@ -1481,7 +1483,8 @@ static int nvmet_rdma_add_port(struct nvmet_port *port)
 	if (port->inline_data_size < 0) {
 		port->inline_data_size = NVMET_RDMA_DEFAULT_INLINE_DATA_SIZE;
 	} else if (port->inline_data_size > NVMET_RDMA_MAX_INLINE_DATA_SIZE) {
-		pr_warn("inline_data_size %u is too large, reducing to %u\n",
+		port_warn(port,
+			"inline_data_size %u is too large, reducing to %u\n",
 			port->inline_data_size,
 			NVMET_RDMA_MAX_INLINE_DATA_SIZE);
 		port->inline_data_size = NVMET_RDMA_MAX_INLINE_DATA_SIZE;
@@ -1490,7 +1493,7 @@ static int nvmet_rdma_add_port(struct nvmet_port *port)
 	ret = inet_pton_with_scope(&init_net, af, port->disc_addr.traddr,
 			port->disc_addr.trsvcid, &addr);
 	if (ret) {
-		pr_err("malformed ip/port passed: %s:%s\n",
+		port_err(port, "malformed ip/port passed: %s:%s\n",
 			port->disc_addr.traddr, port->disc_addr.trsvcid);
 		return ret;
 	}
@@ -1498,7 +1501,7 @@ static int nvmet_rdma_add_port(struct nvmet_port *port)
 	cm_id = rdma_create_id(&init_net, nvmet_rdma_cm_handler, port,
 			RDMA_PS_TCP, IB_QPT_RC);
 	if (IS_ERR(cm_id)) {
-		pr_err("CM ID creation failed\n");
+		port_err(port, "CM ID creation failed\n");
 		return PTR_ERR(cm_id);
 	}
 
@@ -1508,26 +1511,25 @@ static int nvmet_rdma_add_port(struct nvmet_port *port)
 	 */
 	ret = rdma_set_afonly(cm_id, 1);
 	if (ret) {
-		pr_err("rdma_set_afonly failed (%d)\n", ret);
+		port_err(port, "rdma_set_afonly failed (%d)\n", ret);
 		goto out_destroy_id;
 	}
 
 	ret = rdma_bind_addr(cm_id, (struct sockaddr *)&addr);
 	if (ret) {
-		pr_err("binding CM ID to %pISpcs failed (%d)\n",
+		port_err(port, "binding CM ID to %pISpcs failed (%d)\n",
 			(struct sockaddr *)&addr, ret);
 		goto out_destroy_id;
 	}
 
 	ret = rdma_listen(cm_id, 128);
 	if (ret) {
-		pr_err("listening to %pISpcs failed (%d)\n",
+		port_err(port, "listening to %pISpcs failed (%d)\n",
 			(struct sockaddr *)&addr, ret);
 		goto out_destroy_id;
 	}
 
-	pr_info("enabling port %d (%pISpcs)\n",
-		le16_to_cpu(port->disc_addr.portid), (struct sockaddr *)&addr);
+	port_info(port, "enabled (%pISpcs)\n", (struct sockaddr *)&addr);
 	port->priv = cm_id;
 	return 0;
 
-- 
2.14.1

[PATCH rfc 2/2] nvmet: add nvmet ctrl logging helpers

[Sagi Grimberg]

prettify ctrl related logging when we have multiple ports in
the system. Now ctrl logging helpers will use the format
"nvmet ctrlX: ...".

Signed-off-by: Sagi Grimberg <sagi at grimberg.me>
---
 drivers/nvme/target/admin-cmd.c   | 11 +++++------
 drivers/nvme/target/core.c        | 20 ++++++++++----------
 drivers/nvme/target/discovery.c   | 13 +++++++------
 drivers/nvme/target/fabrics-cmd.c | 15 ++++++++-------
 drivers/nvme/target/io-cmd-bdev.c |  5 +++--
 drivers/nvme/target/nvmet.h       | 17 +++++++++++++++++
 drivers/nvme/target/rdma.c        | 26 ++++++++++++++++----------
 7 files changed, 66 insertions(+), 41 deletions(-)

diff --git a/drivers/nvme/target/admin-cmd.c b/drivers/nvme/target/admin-cmd.c
index 837bbdbfaa4b..46e2fb9c8bc7 100644
--- a/drivers/nvme/target/admin-cmd.c
+++ b/drivers/nvme/target/admin-cmd.c
@@ -45,8 +45,8 @@ static u16 nvmet_get_smart_log_nsid(struct nvmet_req *req,
 
 	ns = nvmet_find_namespace(req->sq->ctrl, req->cmd->get_log_page.nsid);
 	if (!ns) {
-		pr_err("nvmet : Could not find namespace id : %d\n",
-				le32_to_cpu(req->cmd->get_log_page.nsid));
+		ctrl_err(req->sq->ctrl, "Could not find namespace id : %d\n",
+			le32_to_cpu(req->cmd->get_log_page.nsid));
 		return NVME_SC_INVALID_NS;
 	}
 
@@ -571,8 +571,7 @@ static void nvmet_execute_keep_alive(struct nvmet_req *req)
 {
 	struct nvmet_ctrl *ctrl = req->sq->ctrl;
 
-	pr_debug("ctrl %d update keep-alive timer for %d secs\n",
-		ctrl->cntlid, ctrl->kato);
+	ctrl_dbg(ctrl, "update keep-alive timer for %d secs\n", ctrl->kato);
 
 	mod_delayed_work(system_wq, &ctrl->ka_work, ctrl->kato * HZ);
 	nvmet_req_complete(req, 0);
@@ -660,7 +659,7 @@ u16 nvmet_parse_admin_cmd(struct nvmet_req *req)
 		return 0;
 	}
 
-	pr_err("unhandled cmd %d on qid %d\n", cmd->common.opcode,
-	       req->sq->qid);
+	ctrl_err(req->sq->ctrl, "unhandled cmd %d on qid %d\n",
+		cmd->common.opcode, req->sq->qid);
 	return NVME_SC_INVALID_OPCODE | NVME_SC_DNR;
 }
diff --git a/drivers/nvme/target/core.c b/drivers/nvme/target/core.c
index ddd85715a00a..fbb71d005ea1 100644
--- a/drivers/nvme/target/core.c
+++ b/drivers/nvme/target/core.c
@@ -268,16 +268,14 @@ static void nvmet_keep_alive_timer(struct work_struct *work)
 	struct nvmet_ctrl *ctrl = container_of(to_delayed_work(work),
 			struct nvmet_ctrl, ka_work);
 
-	pr_err("ctrl %d keep-alive timer (%d seconds) expired!\n",
-		ctrl->cntlid, ctrl->kato);
+	ctrl_err(ctrl, "keep-alive timer (%d seconds) expired!\n", ctrl->kato);
 
 	nvmet_ctrl_fatal_error(ctrl);
 }
 
 static void nvmet_start_keep_alive_timer(struct nvmet_ctrl *ctrl)
 {
-	pr_debug("ctrl %d start keep-alive timer for %d secs\n",
-		ctrl->cntlid, ctrl->kato);
+	ctrl_dbg(ctrl, "start keep-alive timer for %d secs\n", ctrl->kato);
 
 	INIT_DELAYED_WORK(&ctrl->ka_work, nvmet_keep_alive_timer);
 	schedule_delayed_work(&ctrl->ka_work, ctrl->kato * HZ);
@@ -285,7 +283,7 @@ static void nvmet_start_keep_alive_timer(struct nvmet_ctrl *ctrl)
 
 static void nvmet_stop_keep_alive_timer(struct nvmet_ctrl *ctrl)
 {
-	pr_debug("ctrl %d stop keep-alive\n", ctrl->cntlid);
+	ctrl_dbg(ctrl, "stop keep-alive\n");
 
 	cancel_delayed_work_sync(&ctrl->ka_work);
 }
@@ -786,14 +784,16 @@ u16 nvmet_ctrl_find_get(const char *subsysnqn, const char *hostnqn, u16 cntlid,
 u16 nvmet_check_ctrl_status(struct nvmet_req *req, struct nvme_command *cmd)
 {
 	if (unlikely(!(req->sq->ctrl->cc & NVME_CC_ENABLE))) {
-		pr_err("got cmd %d while CC.EN == 0 on qid = %d\n",
-		       cmd->common.opcode, req->sq->qid);
+		ctrl_err(req->sq->ctrl,
+			"got cmd %d while CC.EN == 0 on qid = %d\n",
+			cmd->common.opcode, req->sq->qid);
 		return NVME_SC_CMD_SEQ_ERROR | NVME_SC_DNR;
 	}
 
 	if (unlikely(!(req->sq->ctrl->csts & NVME_CSTS_RDY))) {
-		pr_err("got cmd %d while CSTS.RDY == 0 on qid = %d\n",
-		       cmd->common.opcode, req->sq->qid);
+		ctrl_err(req->sq->ctrl,
+			"got cmd %d while CSTS.RDY == 0 on qid = %d\n",
+			cmd->common.opcode, req->sq->qid);
 		return NVME_SC_CMD_SEQ_ERROR | NVME_SC_DNR;
 	}
 	return 0;
@@ -997,7 +997,7 @@ static void nvmet_fatal_error_handler(struct work_struct *work)
 	struct nvmet_ctrl *ctrl =
 			container_of(work, struct nvmet_ctrl, fatal_err_work);
 
-	pr_err("ctrl %d fatal error occurred!\n", ctrl->cntlid);
+	ctrl_err(ctrl, "fatal error occurred!\n");
 	ctrl->ops->delete_ctrl(ctrl);
 }
 
diff --git a/drivers/nvme/target/discovery.c b/drivers/nvme/target/discovery.c
index eae29f493a07..960031608f93 100644
--- a/drivers/nvme/target/discovery.c
+++ b/drivers/nvme/target/discovery.c
@@ -186,9 +186,10 @@ static void nvmet_execute_identify_disc_ctrl(struct nvmet_req *req)
 u16 nvmet_parse_discovery_cmd(struct nvmet_req *req)
 {
 	struct nvme_command *cmd = req->cmd;
+	struct nvmet_ctrl *ctrl = req->sq->ctrl;
 
-	if (unlikely(!(req->sq->ctrl->csts & NVME_CSTS_RDY))) {
-		pr_err("got cmd %d while not ready\n",
+	if (unlikely(!(ctrl->csts & NVME_CSTS_RDY))) {
+		ctrl_err(ctrl, "got cmd %d while not ready\n",
 		       cmd->common.opcode);
 		return NVME_SC_INVALID_OPCODE | NVME_SC_DNR;
 	}
@@ -202,7 +203,7 @@ u16 nvmet_parse_discovery_cmd(struct nvmet_req *req)
 			req->execute = nvmet_execute_get_disc_log_page;
 			return 0;
 		default:
-			pr_err("unsupported get_log_page lid %d\n",
+			ctrl_err(ctrl, "unsupported get_log_page lid %d\n",
 			       cmd->get_log_page.lid);
 		return NVME_SC_INVALID_OPCODE | NVME_SC_DNR;
 		}
@@ -214,16 +215,16 @@ u16 nvmet_parse_discovery_cmd(struct nvmet_req *req)
 				nvmet_execute_identify_disc_ctrl;
 			return 0;
 		default:
-			pr_err("unsupported identify cns %d\n",
+			ctrl_err(ctrl, "unsupported identify cns %d\n",
 			       cmd->identify.cns);
 			return NVME_SC_INVALID_OPCODE | NVME_SC_DNR;
 		}
 	default:
-		pr_err("unsupported cmd %d\n", cmd->common.opcode);
+		ctrl_err(ctrl, "unsupported cmd %d\n", cmd->common.opcode);
 		return NVME_SC_INVALID_OPCODE | NVME_SC_DNR;
 	}
 
-	pr_err("unhandled cmd %d\n", cmd->common.opcode);
+	ctrl_err(ctrl, "unhandled cmd %d\n", cmd->common.opcode);
 	return NVME_SC_INVALID_OPCODE | NVME_SC_DNR;
 }
 
diff --git a/drivers/nvme/target/fabrics-cmd.c b/drivers/nvme/target/fabrics-cmd.c
index d84ae004cb85..3a2722d483d7 100644
--- a/drivers/nvme/target/fabrics-cmd.c
+++ b/drivers/nvme/target/fabrics-cmd.c
@@ -87,7 +87,8 @@ u16 nvmet_parse_fabrics_cmd(struct nvmet_req *req)
 		req->execute = nvmet_execute_prop_get;
 		break;
 	default:
-		pr_err("received unknown capsule type 0x%x\n",
+		ctrl_err(req->sq->ctrl,
+			"received unknown capsule type 0x%x\n",
 			cmd->fabrics.fctype);
 		return NVME_SC_INVALID_OPCODE | NVME_SC_DNR;
 	}
@@ -104,11 +105,11 @@ static u16 nvmet_install_queue(struct nvmet_ctrl *ctrl, struct nvmet_req *req)
 
 	old = cmpxchg(&req->sq->ctrl, NULL, ctrl);
 	if (old) {
-		pr_warn("queue already connected!\n");
+		ctrl_warn(ctrl, "queue already connected!\n");
 		return NVME_SC_CONNECT_CTRL_BUSY | NVME_SC_DNR;
 	}
 	if (!sqsize) {
-		pr_warn("queue size zero!\n");
+		ctrl_warn(ctrl, "queue size zero!\n");
 		return NVME_SC_CONNECT_INVALID_PARAM | NVME_SC_DNR;
 	}
 
@@ -165,8 +166,8 @@ static void nvmet_execute_admin_connect(struct nvmet_req *req)
 		goto out;
 	}
 
-	pr_info("creating controller %d for subsystem %s for NQN %s.\n",
-		ctrl->cntlid, ctrl->subsys->subsysnqn, ctrl->hostnqn);
+	ctrl_info(ctrl, "subsystem %s to host %s.\n",
+		ctrl->subsys->subsysnqn, ctrl->hostnqn);
 	req->rsp->result.u16 = cpu_to_le16(ctrl->cntlid);
 
 out:
@@ -210,7 +211,7 @@ static void nvmet_execute_io_connect(struct nvmet_req *req)
 		goto out;
 
 	if (unlikely(qid > ctrl->subsys->max_qid)) {
-		pr_warn("invalid queue id (%d)\n", qid);
+		ctrl_warn(ctrl, "invalid queue id (%d)\n", qid);
 		status = NVME_SC_CONNECT_INVALID_PARAM | NVME_SC_DNR;
 		req->rsp->result.u32 = IPO_IATTR_CONNECT_SQE(qid);
 		goto out_ctrl_put;
@@ -223,7 +224,7 @@ static void nvmet_execute_io_connect(struct nvmet_req *req)
 		goto out_ctrl_put;
 	}
 
-	pr_debug("adding queue %d to ctrl %d.\n", qid, ctrl->cntlid);
+	ctrl_dbg(ctrl, "adding queue %d.\n", qid);
 
 out:
 	kfree(d);
diff --git a/drivers/nvme/target/io-cmd-bdev.c b/drivers/nvme/target/io-cmd-bdev.c
index e0b0f7df70c2..d4e7b071dce4 100644
--- a/drivers/nvme/target/io-cmd-bdev.c
+++ b/drivers/nvme/target/io-cmd-bdev.c
@@ -234,8 +234,9 @@ u16 nvmet_bdev_parse_io_cmd(struct nvmet_req *req)
 		req->execute = nvmet_bdev_execute_write_zeroes;
 		return 0;
 	default:
-		pr_err("unhandled cmd %d on qid %d\n", cmd->common.opcode,
-		       req->sq->qid);
+		ctrl_err(req->sq->ctrl,
+			"unhandled cmd %d on qid %d\n", cmd->common.opcode,
+			req->sq->qid);
 		return NVME_SC_INVALID_OPCODE | NVME_SC_DNR;
 	}
 }
diff --git a/drivers/nvme/target/nvmet.h b/drivers/nvme/target/nvmet.h
index 6811258ab8ff..73751ded2174 100644
--- a/drivers/nvme/target/nvmet.h
+++ b/drivers/nvme/target/nvmet.h
@@ -280,6 +280,13 @@ struct nvmet_req {
 	printk(KERN_WARNING "nvmet port%d: " fmt, \
 		le32_to_cpu((port)->disc_addr.portid), ##a)
 
+#define ctrl_err(ctrl, fmt, a...)		\
+	printk(KERN_ERR "nvmet ctrl%d: " fmt, (ctrl)->cntlid, ##a)
+#define ctrl_info(ctrl, fmt, a...)		\
+	printk(KERN_INFO "nvmet ctrl%d: " fmt, (ctrl)->cntlid, ##a)
+#define ctrl_warn(ctrl, fmt, a...)		\
+	printk(KERN_WARNING "nvmet ctrl%d: " fmt, (ctrl)->cntlid, ##a)
+
 #if defined(CONFIG_DYNAMIC_DEBUG)
 #include <linux/dynamic_debug.h>
 #define port_dbg(port, fmt, a...)				\
@@ -289,12 +296,22 @@ do {								\
 		printk(KERN_DEBUG "nvmet port%d: " fmt, 	\
 			le32_to_cpu((port)->disc_addr.portid), ##a);\
 } while (0)
+#define ctrl_dbg(ctrl, fmt, a...)				\
+do {								\
+	DEFINE_DYNAMIC_DEBUG_METADATA(descriptor, fmt);		\
+	if (DYNAMIC_DEBUG_BRANCH(descriptor))			\
+		printk(KERN_DEBUG "nvmet ctrl%d: " fmt, 	\
+			(ctrl)->cntlid, ##a);			\
+} while (0)
 #elif defined(DEBUG)
 #define port_dbg(port, fmt, a...)				\
 	printk(KERN_DEBUG "nvmet port%d: " fmt, 	\
 		le32_to_cpu((port)->disc_addr.portid)
+#define ctrl_dbg(ctrl, fmt, a...)				\
+	printk(KERN_DEBUG "nvmet ctrl%d: " fmt, (ctrl)->cntlid, ##a)
 #else
 #define port_dbg(port, fmt, a...) {}
+#define ctrl_dbg(ctrl, fmt, a...) {}
 #endif
 
 extern struct workqueue_struct *buffered_io_wq;
diff --git a/drivers/nvme/target/rdma.c b/drivers/nvme/target/rdma.c
index 71bf6bf57be9..b14227e6e11f 100644
--- a/drivers/nvme/target/rdma.c
+++ b/drivers/nvme/target/rdma.c
@@ -554,7 +554,8 @@ static void nvmet_rdma_queue_response(struct nvmet_req *req)
 		DMA_TO_DEVICE);
 
 	if (unlikely(ib_post_send(cm_id->qp, first_wr, &bad_wr))) {
-		pr_err("sending cmd response failed\n");
+		ctrl_err(req->sq->ctrl,
+			"sending cmd response failed\n");
 		nvmet_rdma_release_rsp(rsp);
 	}
 }
@@ -576,7 +577,8 @@ static void nvmet_rdma_read_data_done(struct ib_cq *cq, struct ib_wc *wc)
 		nvmet_req_uninit(&rsp->req);
 		nvmet_rdma_release_rsp(rsp);
 		if (wc->status != IB_WC_WR_FLUSH_ERR) {
-			pr_info("RDMA READ for CQE 0x%p failed with status %s (%d).\n",
+			ctrl_err(queue->nvme_sq.ctrl,
+				"RDMA READ for CQE 0x%p failed with status %s (%d).\n",
 				wc->wr_cqe, ib_wc_status_msg(wc->status), wc->status);
 			nvmet_rdma_error_comp(queue);
 		}
@@ -620,7 +622,8 @@ static u16 nvmet_rdma_map_sgl_inline(struct nvmet_rdma_rsp *rsp)
 		return NVME_SC_INVALID_FIELD | NVME_SC_DNR;
 
 	if (off + len > rsp->queue->dev->inline_data_size) {
-		pr_err("invalid inline data offset!\n");
+		ctrl_err(rsp->cmd->queue->nvme_sq.ctrl,
+			"invalid inline data offset!\n");
 		return NVME_SC_SGL_INVALID_OFFSET | NVME_SC_DNR;
 	}
 
@@ -677,7 +680,8 @@ static u16 nvmet_rdma_map_sgl(struct nvmet_rdma_rsp *rsp)
 		case NVME_SGL_FMT_OFFSET:
 			return nvmet_rdma_map_sgl_inline(rsp);
 		default:
-			pr_err("invalid SGL subtype: %#x\n", sgl->type);
+			ctrl_err(rsp->cmd->queue->nvme_sq.ctrl,
+				"invalid SGL subtype: %#x\n", sgl->type);
 			return NVME_SC_INVALID_FIELD | NVME_SC_DNR;
 		}
 	case NVME_KEY_SGL_FMT_DATA_DESC:
@@ -687,11 +691,13 @@ static u16 nvmet_rdma_map_sgl(struct nvmet_rdma_rsp *rsp)
 		case NVME_SGL_FMT_ADDRESS:
 			return nvmet_rdma_map_sgl_keyed(rsp, sgl, false);
 		default:
-			pr_err("invalid SGL subtype: %#x\n", sgl->type);
+			ctrl_err(rsp->cmd->queue->nvme_sq.ctrl,
+				"invalid SGL subtype: %#x\n", sgl->type);
 			return NVME_SC_INVALID_FIELD | NVME_SC_DNR;
 		}
 	default:
-		pr_err("invalid SGL type: %#x\n", sgl->type);
+		ctrl_err(rsp->cmd->queue->nvme_sq.ctrl,
+			"invalid SGL type: %#x\n", sgl->type);
 		return NVME_SC_SGL_INVALID_TYPE | NVME_SC_DNR;
 	}
 }
@@ -702,9 +708,9 @@ static bool nvmet_rdma_execute_command(struct nvmet_rdma_rsp *rsp)
 
 	if (unlikely(atomic_sub_return(1 + rsp->n_rdma,
 			&queue->sq_wr_avail) < 0)) {
-		pr_debug("IB send queue full (needed %d): queue %u cntlid %u\n",
-				1 + rsp->n_rdma, queue->idx,
-				queue->nvme_sq.ctrl->cntlid);
+		ctrl_dbg(queue->nvme_sq.ctrl,
+			"IB send queue full (needed %d): queue %u\n",
+			1 + rsp->n_rdma, queue->idx);
 		atomic_add(1 + rsp->n_rdma, &queue->sq_wr_avail);
 		return false;
 	}
@@ -1022,7 +1028,7 @@ static void nvmet_rdma_destroy_queue_ib(struct nvmet_rdma_queue *queue)
 
 static void nvmet_rdma_free_queue(struct nvmet_rdma_queue *queue)
 {
-	pr_debug("freeing queue %d\n", queue->idx);
+	ctrl_dbg(queue->nvme_sq.ctrl, "freeing queue %d\n", queue->idx);
 
 	nvmet_sq_destroy(&queue->nvme_sq);
 
-- 
2.14.1

[PATCH rfc 2/2] nvmet: add nvmet ctrl logging helpers

[Chaitanya Kulkarni]

From: Linux-nvme <linux-nvme-bounces@lists.infradead.org> on behalf of Sagi Grimberg <sagi@grimberg.me>
Sent: Monday, July 16, 2018 3:53 AM
To: linux-nvme at lists.infradead.org
Subject: [PATCH rfc 2/2] nvmet: add nvmet ctrl logging helpers
? 
 
prettify ctrl related logging when we have multiple ports in
the system. Now ctrl logging helpers will use the format
"nvmet ctrlX: ...".

Signed-off-by: Sagi Grimberg <sagi at grimberg.me>
---
?drivers/nvme/target/admin-cmd.c?? | 11 +++++------
?drivers/nvme/target/core.c??????? | 20 ++++++++++----------
?drivers/nvme/target/discovery.c?? | 13 +++++++------
?drivers/nvme/target/fabrics-cmd.c | 15 ++++++++-------
?drivers/nvme/target/io-cmd-bdev.c |? 5 +++--
?drivers/nvme/target/nvmet.h?????? | 17 +++++++++++++++++
?drivers/nvme/target/rdma.c??????? | 26 ++++++++++++++++----------
?7 files changed, 66 insertions(+), 41 deletions(-)

diff --git a/drivers/nvme/target/admin-cmd.c b/drivers/nvme/target/admin-cmd.c
index 837bbdbfaa4b..46e2fb9c8bc7 100644
--- a/drivers/nvme/target/admin-cmd.c
+++ b/drivers/nvme/target/admin-cmd.c
@@ -45,8 +45,8 @@ static u16 nvmet_get_smart_log_nsid(struct nvmet_req *req,
?
???????? ns = nvmet_find_namespace(req->sq->ctrl, req->cmd->get_log_page.nsid);
???????? if (!ns) {
-?????????????? pr_err("nvmet : Could not find namespace id : %d\n",
-?????????????????????????????? le32_to_cpu(req->cmd->get_log_page.nsid));
+?????????????? ctrl_err(req->sq->ctrl, "Could not find namespace id : %d\n",
+?????????????????????? le32_to_cpu(req->cmd->get_log_page.nsid));
???????????????? return NVME_SC_INVALID_NS;
???????? }
?
@@ -571,8 +571,7 @@ static void nvmet_execute_keep_alive(struct nvmet_req *req)
?{
???????? struct nvmet_ctrl *ctrl = req->sq->ctrl;
?
-?????? pr_debug("ctrl %d update keep-alive timer for %d secs\n",
-?????????????? ctrl->cntlid, ctrl->kato);
+?????? ctrl_dbg(ctrl, "update keep-alive timer for %d secs\n", ctrl->kato);
?
???????? mod_delayed_work(system_wq, &ctrl->ka_work, ctrl->kato * HZ);
???????? nvmet_req_complete(req, 0);
@@ -660,7 +659,7 @@ u16 nvmet_parse_admin_cmd(struct nvmet_req *req)
???????????????? return 0;
???????? }
?
-?????? pr_err("unhandled cmd %d on qid %d\n", cmd->common.opcode,
-????????????? req->sq->qid);
+?????? ctrl_err(req->sq->ctrl, "unhandled cmd %d on qid %d\n",
+?????????????? cmd->common.opcode, req->sq->qid);
???????? return NVME_SC_INVALID_OPCODE | NVME_SC_DNR;
?}
diff --git a/drivers/nvme/target/core.c b/drivers/nvme/target/core.c
index ddd85715a00a..fbb71d005ea1 100644
--- a/drivers/nvme/target/core.c
+++ b/drivers/nvme/target/core.c
@@ -268,16 +268,14 @@ static void nvmet_keep_alive_timer(struct work_struct *work)
???????? struct nvmet_ctrl *ctrl = container_of(to_delayed_work(work),
???????????????????????? struct nvmet_ctrl, ka_work);
?
-?????? pr_err("ctrl %d keep-alive timer (%d seconds) expired!\n",
-?????????????? ctrl->cntlid, ctrl->kato);
+?????? ctrl_err(ctrl, "keep-alive timer (%d seconds) expired!\n", ctrl->kato);
?
???????? nvmet_ctrl_fatal_error(ctrl);
?}
?
?static void nvmet_start_keep_alive_timer(struct nvmet_ctrl *ctrl)
?{
-?????? pr_debug("ctrl %d start keep-alive timer for %d secs\n",
-?????????????? ctrl->cntlid, ctrl->kato);
+?????? ctrl_dbg(ctrl, "start keep-alive timer for %d secs\n", ctrl->kato);
?
???????? INIT_DELAYED_WORK(&ctrl->ka_work, nvmet_keep_alive_timer);
???????? schedule_delayed_work(&ctrl->ka_work, ctrl->kato * HZ);
@@ -285,7 +283,7 @@ static void nvmet_start_keep_alive_timer(struct nvmet_ctrl *ctrl)
?
?static void nvmet_stop_keep_alive_timer(struct nvmet_ctrl *ctrl)
?{
-?????? pr_debug("ctrl %d stop keep-alive\n", ctrl->cntlid);
+?????? ctrl_dbg(ctrl, "stop keep-alive\n");
?
???????? cancel_delayed_work_sync(&ctrl->ka_work);
?}
@@ -786,14 +784,16 @@ u16 nvmet_ctrl_find_get(const char *subsysnqn, const char *hostnqn, u16 cntlid,
?u16 nvmet_check_ctrl_status(struct nvmet_req *req, struct nvme_command *cmd)
?{
???????? if (unlikely(!(req->sq->ctrl->cc & NVME_CC_ENABLE))) {
-?????????????? pr_err("got cmd %d while CC.EN == 0 on qid = %d\n",
-????????????????????? cmd->common.opcode, req->sq->qid);
+?????????????? ctrl_err(req->sq->ctrl,
+?????????????????????? "got cmd %d while CC.EN == 0 on qid = %d\n",
+?????????????????????? cmd->common.opcode, req->sq->qid);
???????????????? return NVME_SC_CMD_SEQ_ERROR | NVME_SC_DNR;
???????? }
?
???????? if (unlikely(!(req->sq->ctrl->csts & NVME_CSTS_RDY))) {
-?????????????? pr_err("got cmd %d while CSTS.RDY == 0 on qid = %d\n",
-????????????????????? cmd->common.opcode, req->sq->qid);
+?????????????? ctrl_err(req->sq->ctrl,
+?????????????????????? "got cmd %d while CSTS.RDY == 0 on qid = %d\n",
+?????????????????????? cmd->common.opcode, req->sq->qid);
???????????????? return NVME_SC_CMD_SEQ_ERROR | NVME_SC_DNR;
???????? }
???????? return 0;
@@ -997,7 +997,7 @@ static void nvmet_fatal_error_handler(struct work_struct *work)
???????? struct nvmet_ctrl *ctrl =
???????????????????????? container_of(work, struct nvmet_ctrl, fatal_err_work);
?
-?????? pr_err("ctrl %d fatal error occurred!\n", ctrl->cntlid);
+?????? ctrl_err(ctrl, "fatal error occurred!\n");
???????? ctrl->ops->delete_ctrl(ctrl);
?}
?
diff --git a/drivers/nvme/target/discovery.c b/drivers/nvme/target/discovery.c
index eae29f493a07..960031608f93 100644
--- a/drivers/nvme/target/discovery.c
+++ b/drivers/nvme/target/discovery.c
@@ -186,9 +186,10 @@ static void nvmet_execute_identify_disc_ctrl(struct nvmet_req *req)
?u16 nvmet_parse_discovery_cmd(struct nvmet_req *req)
?{
???????? struct nvme_command *cmd = req->cmd;
+?????? struct nvmet_ctrl *ctrl = req->sq->ctrl;
?
-?????? if (unlikely(!(req->sq->ctrl->csts & NVME_CSTS_RDY))) {
-?????????????? pr_err("got cmd %d while not ready\n",
+?????? if (unlikely(!(ctrl->csts & NVME_CSTS_RDY))) {
+?????????????? ctrl_err(ctrl, "got cmd %d while not ready\n",
??????????????????????? cmd->common.opcode);
???????????????? return NVME_SC_INVALID_OPCODE | NVME_SC_DNR;
???????? }
@@ -202,7 +203,7 @@ u16 nvmet_parse_discovery_cmd(struct nvmet_req *req)
???????????????????????? req->execute = nvmet_execute_get_disc_log_page;
???????????????????????? return 0;
???????????????? default:
-?????????????????????? pr_err("unsupported get_log_page lid %d\n",
+?????????????????????? ctrl_err(ctrl, "unsupported get_log_page lid %d\n",
??????????????????????????????? cmd->get_log_page.lid);
???????????????? return NVME_SC_INVALID_OPCODE | NVME_SC_DNR;
???????????????? }
@@ -214,16 +215,16 @@ u16 nvmet_parse_discovery_cmd(struct nvmet_req *req)
???????????????????????????????? nvmet_execute_identify_disc_ctrl;
???????????????????????? return 0;
???????????????? default:
-?????????????????????? pr_err("unsupported identify cns %d\n",
+?????????????????????? ctrl_err(ctrl, "unsupported identify cns %d\n",
??????????????????????????????? cmd->identify.cns);
???????????????????????? return NVME_SC_INVALID_OPCODE | NVME_SC_DNR;
???????????????? }
???????? default:
-?????????????? pr_err("unsupported cmd %d\n", cmd->common.opcode);
+?????????????? ctrl_err(ctrl, "unsupported cmd %d\n", cmd->common.opcode);
???????????????? return NVME_SC_INVALID_OPCODE | NVME_SC_DNR;
???????? }
?
-?????? pr_err("unhandled cmd %d\n", cmd->common.opcode);
+?????? ctrl_err(ctrl, "unhandled cmd %d\n", cmd->common.opcode);
???????? return NVME_SC_INVALID_OPCODE | NVME_SC_DNR;
?}
?
diff --git a/drivers/nvme/target/fabrics-cmd.c b/drivers/nvme/target/fabrics-cmd.c
index d84ae004cb85..3a2722d483d7 100644
--- a/drivers/nvme/target/fabrics-cmd.c
+++ b/drivers/nvme/target/fabrics-cmd.c
@@ -87,7 +87,8 @@ u16 nvmet_parse_fabrics_cmd(struct nvmet_req *req)
???????????????? req->execute = nvmet_execute_prop_get;
???????????????? break;
???????? default:
-?????????????? pr_err("received unknown capsule type 0x%x\n",
+?????????????? ctrl_err(req->sq->ctrl,
+?????????????????????? "received unknown capsule type 0x%x\n",
???????????????????????? cmd->fabrics.fctype);
???????????????? return NVME_SC_INVALID_OPCODE | NVME_SC_DNR;
???????? }
@@ -104,11 +105,11 @@ static u16 nvmet_install_queue(struct nvmet_ctrl *ctrl, struct nvmet_req *req)
?
???????? old = cmpxchg(&req->sq->ctrl, NULL, ctrl);
???????? if (old) {
-?????????????? pr_warn("queue already connected!\n");
+?????????????? ctrl_warn(ctrl, "queue already connected!\n");
???????????????? return NVME_SC_CONNECT_CTRL_BUSY | NVME_SC_DNR;
???????? }
???????? if (!sqsize) {
-?????????????? pr_warn("queue size zero!\n");
+?????????????? ctrl_warn(ctrl, "queue size zero!\n");
???????????????? return NVME_SC_CONNECT_INVALID_PARAM | NVME_SC_DNR;
???????? }
?
@@ -165,8 +166,8 @@ static void nvmet_execute_admin_connect(struct nvmet_req *req)
???????????????? goto out;
???????? }
?
-?????? pr_info("creating controller %d for subsystem %s for NQN %s.\n",
-?????????????? ctrl->cntlid, ctrl->subsys->subsysnqn, ctrl->hostnqn);
+?????? ctrl_info(ctrl, "subsystem %s to host %s.\n",
+?????????????? ctrl->subsys->subsysnqn, ctrl->hostnqn);
???????? req->rsp->result.u16 = cpu_to_le16(ctrl->cntlid);
?
?out:
@@ -210,7 +211,7 @@ static void nvmet_execute_io_connect(struct nvmet_req *req)
???????????????? goto out;
?
???????? if (unlikely(qid > ctrl->subsys->max_qid)) {
-?????????????? pr_warn("invalid queue id (%d)\n", qid);
+?????????????? ctrl_warn(ctrl, "invalid queue id (%d)\n", qid);
???????????????? status = NVME_SC_CONNECT_INVALID_PARAM | NVME_SC_DNR;
???????????????? req->rsp->result.u32 = IPO_IATTR_CONNECT_SQE(qid);
???????????????? goto out_ctrl_put;
@@ -223,7 +224,7 @@ static void nvmet_execute_io_connect(struct nvmet_req *req)
???????????????? goto out_ctrl_put;
???????? }
?
-?????? pr_debug("adding queue %d to ctrl %d.\n", qid, ctrl->cntlid);
+?????? ctrl_dbg(ctrl, "adding queue %d.\n", qid);
?
?out:
???????? kfree(d);
diff --git a/drivers/nvme/target/io-cmd-bdev.c b/drivers/nvme/target/io-cmd-bdev.c
index e0b0f7df70c2..d4e7b071dce4 100644
--- a/drivers/nvme/target/io-cmd-bdev.c
+++ b/drivers/nvme/target/io-cmd-bdev.c
@@ -234,8 +234,9 @@ u16 nvmet_bdev_parse_io_cmd(struct nvmet_req *req)
???????????????? req->execute = nvmet_bdev_execute_write_zeroes;
???????????????? return 0;
???????? default:
-?????????????? pr_err("unhandled cmd %d on qid %d\n", cmd->common.opcode,
-????????????????????? req->sq->qid);
+?????????????? ctrl_err(req->sq->ctrl,
+?????????????????????? "unhandled cmd %d on qid %d\n", cmd->common.opcode,
+?????????????????????? req->sq->qid);
???????????????? return NVME_SC_INVALID_OPCODE | NVME_SC_DNR;
???????? }
?}
diff --git a/drivers/nvme/target/nvmet.h b/drivers/nvme/target/nvmet.h
index 6811258ab8ff..73751ded2174 100644
--- a/drivers/nvme/target/nvmet.h
+++ b/drivers/nvme/target/nvmet.h
@@ -280,6 +280,13 @@ struct nvmet_req {
???????? printk(KERN_WARNING "nvmet port%d: " fmt, \
???????????????? le32_to_cpu((port)->disc_addr.portid), ##a)
?
+#define ctrl_err(ctrl, fmt, a...)????????????? \
+?????? printk(KERN_ERR "nvmet ctrl%d: " fmt, (ctrl)->cntlid, ##a)
+#define ctrl_info(ctrl, fmt, a...)???????????? \
+?????? printk(KERN_INFO "nvmet ctrl%d: " fmt, (ctrl)->cntlid, ##a)
+#define ctrl_warn(ctrl, fmt, a...)???????????? \
+?????? printk(KERN_WARNING "nvmet ctrl%d: " fmt, (ctrl)->cntlid, ##a)
+

[CK] Can we use pr_XXX for above helpers instead of printk()?

?#if defined(CONFIG_DYNAMIC_DEBUG)
?#include <linux/dynamic_debug.h>
?#define port_dbg(port, fmt, a...)?????????????????????????????? \
@@ -289,12 +296,22 @@ do {????????????????????????????????????????????????????????????? \
???????????????? printk(KERN_DEBUG "nvmet port%d: " fmt,? \
???????????????????????? le32_to_cpu((port)->disc_addr.portid), ##a);\
?} while (0)
+#define ctrl_dbg(ctrl, fmt, a...)????????????????????????????? \
+do {?????????????????????????????????????????????????????????? \
+?????? DEFINE_DYNAMIC_DEBUG_METADATA(descriptor, fmt);???????? \
+?????? if (DYNAMIC_DEBUG_BRANCH(descriptor))?????????????????? \
+?????????????? printk(KERN_DEBUG "nvmet ctrl%d: " fmt,? \
+?????????????????????? (ctrl)->cntlid, ##a);?????????????????? \
+} while (0)
?#elif defined(DEBUG)
?#define port_dbg(port, fmt, a...)?????????????????????????????? \
???????? printk(KERN_DEBUG "nvmet port%d: " fmt,? \
???????????????? le32_to_cpu((port)->disc_addr.portid)
+#define ctrl_dbg(ctrl, fmt, a...)????????????????????????????? \
+?????? printk(KERN_DEBUG "nvmet ctrl%d: " fmt, (ctrl)->cntlid, ##a)
?#else
?#define port_dbg(port, fmt, a...) {}
+#define ctrl_dbg(ctrl, fmt, a...) {}
?#endif
?
?extern struct workqueue_struct *buffered_io_wq;
diff --git a/drivers/nvme/target/rdma.c b/drivers/nvme/target/rdma.c
index 71bf6bf57be9..b14227e6e11f 100644
--- a/drivers/nvme/target/rdma.c
+++ b/drivers/nvme/target/rdma.c
@@ -554,7 +554,8 @@ static void nvmet_rdma_queue_response(struct nvmet_req *req)
???????????????? DMA_TO_DEVICE);
?
???????? if (unlikely(ib_post_send(cm_id->qp, first_wr, &bad_wr))) {
-?????????????? pr_err("sending cmd response failed\n");
+?????????????? ctrl_err(req->sq->ctrl,
+?????????????????????? "sending cmd response failed\n");
???????????????? nvmet_rdma_release_rsp(rsp);
???????? }
?}
@@ -576,7 +577,8 @@ static void nvmet_rdma_read_data_done(struct ib_cq *cq, struct ib_wc *wc)
???????????????? nvmet_req_uninit(&rsp->req);
???????????????? nvmet_rdma_release_rsp(rsp);
???????????????? if (wc->status != IB_WC_WR_FLUSH_ERR) {
-?????????????????????? pr_info("RDMA READ for CQE 0x%p failed with status %s (%d).\n",
+?????????????????????? ctrl_err(queue->nvme_sq.ctrl,
+?????????????????????????????? "RDMA READ for CQE 0x%p failed with status %s (%d).\n",
???????????????????????????????? wc->wr_cqe, ib_wc_status_msg(wc->status), wc->status);
???????????????????????? nvmet_rdma_error_comp(queue);
???????????????? }
@@ -620,7 +622,8 @@ static u16 nvmet_rdma_map_sgl_inline(struct nvmet_rdma_rsp *rsp)
???????????????? return NVME_SC_INVALID_FIELD | NVME_SC_DNR;
?
???????? if (off + len > rsp->queue->dev->inline_data_size) {
-?????????????? pr_err("invalid inline data offset!\n");
+?????????????? ctrl_err(rsp->cmd->queue->nvme_sq.ctrl,
+?????????????????????? "invalid inline data offset!\n");
???????????????? return NVME_SC_SGL_INVALID_OFFSET | NVME_SC_DNR;
???????? }
?
@@ -677,7 +680,8 @@ static u16 nvmet_rdma_map_sgl(struct nvmet_rdma_rsp *rsp)
???????????????? case NVME_SGL_FMT_OFFSET:
???????????????????????? return nvmet_rdma_map_sgl_inline(rsp);
???????????????? default:
-?????????????????????? pr_err("invalid SGL subtype: %#x\n", sgl->type);
+?????????????????????? ctrl_err(rsp->cmd->queue->nvme_sq.ctrl,
+?????????????????????????????? "invalid SGL subtype: %#x\n", sgl->type);
???????????????????????? return NVME_SC_INVALID_FIELD | NVME_SC_DNR;
???????????????? }
???????? case NVME_KEY_SGL_FMT_DATA_DESC:
@@ -687,11 +691,13 @@ static u16 nvmet_rdma_map_sgl(struct nvmet_rdma_rsp *rsp)
???????????????? case NVME_SGL_FMT_ADDRESS:
???????????????????????? return nvmet_rdma_map_sgl_keyed(rsp, sgl, false);
???????????????? default:
-?????????????????????? pr_err("invalid SGL subtype: %#x\n", sgl->type);
+?????????????????????? ctrl_err(rsp->cmd->queue->nvme_sq.ctrl,
+?????????????????????????????? "invalid SGL subtype: %#x\n", sgl->type);
???????????????????????? return NVME_SC_INVALID_FIELD | NVME_SC_DNR;
???????????????? }
???????? default:
-?????????????? pr_err("invalid SGL type: %#x\n", sgl->type);
+?????????????? ctrl_err(rsp->cmd->queue->nvme_sq.ctrl,
+?????????????????????? "invalid SGL type: %#x\n", sgl->type);
???????????????? return NVME_SC_SGL_INVALID_TYPE | NVME_SC_DNR;
???????? }
?}
@@ -702,9 +708,9 @@ static bool nvmet_rdma_execute_command(struct nvmet_rdma_rsp *rsp)
?
???????? if (unlikely(atomic_sub_return(1 + rsp->n_rdma,
???????????????????????? &queue->sq_wr_avail) < 0)) {
-?????????????? pr_debug("IB send queue full (needed %d): queue %u cntlid %u\n",
-?????????????????????????????? 1 + rsp->n_rdma, queue->idx,
-?????????????????????????????? queue->nvme_sq.ctrl->cntlid);
+?????????????? ctrl_dbg(queue->nvme_sq.ctrl,
+?????????????????????? "IB send queue full (needed %d): queue %u\n",
+?????????????????????? 1 + rsp->n_rdma, queue->idx);
???????????????? atomic_add(1 + rsp->n_rdma, &queue->sq_wr_avail);
???????????????? return false;
???????? }
@@ -1022,7 +1028,7 @@ static void nvmet_rdma_destroy_queue_ib(struct nvmet_rdma_queue *queue)
?
?static void nvmet_rdma_free_queue(struct nvmet_rdma_queue *queue)
?{
-?????? pr_debug("freeing queue %d\n", queue->idx);
+?????? ctrl_dbg(queue->nvme_sq.ctrl, "freeing queue %d\n", queue->idx);
?
???????? nvmet_sq_destroy(&queue->nvme_sq);
?
-- 
2.14.1


_______________________________________________
Linux-nvme mailing list
Linux-nvme at lists.infradead.org
http://lists.infradead.org/mailman/listinfo/linux-nvme
    

[PATCH rfc 2/2] nvmet: add nvmet ctrl logging helpers

[Sagi Grimberg]

> diff --git a/drivers/nvme/target/nvmet.h b/drivers/nvme/target/nvmet.h
> index 6811258ab8ff..73751ded2174 100644
> --- a/drivers/nvme/target/nvmet.h
> +++ b/drivers/nvme/target/nvmet.h
> @@ -280,6 +280,13 @@ struct nvmet_req {
>  ???????? printk(KERN_WARNING "nvmet port%d: " fmt, \
>  ???????????????? le32_to_cpu((port)->disc_addr.portid), ##a)
>   
> +#define ctrl_err(ctrl, fmt, a...)????????????? \
> +?????? printk(KERN_ERR "nvmet ctrl%d: " fmt, (ctrl)->cntlid, ##a)
> +#define ctrl_info(ctrl, fmt, a...)???????????? \
> +?????? printk(KERN_INFO "nvmet ctrl%d: " fmt, (ctrl)->cntlid, ##a)
> +#define ctrl_warn(ctrl, fmt, a...)???????????? \
> +?????? printk(KERN_WARNING "nvmet ctrl%d: " fmt, (ctrl)->cntlid, ##a)
> +
> 
> [CK] Can we use pr_XXX for above helpers instead of printk()?

This would add pr_fmt() to the print which would look like:
"nvme-loop: nvmet ctrl1: XXX". Wanted to clean it up like
dev_XXX logging.