[PATCH 02/20] iser-target: Adjust log levels and prettify some prints

[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index]

 



debug_level 1 (warn): Include warning messages.
debug_level 2 (info): Include relevant info for control plane.
debug_level 3 (debug): Include relevant info in the IO path.

Signed-off-by: Sagi Grimberg <sagig@xxxxxxxxxxxx>
---
 drivers/infiniband/ulp/isert/ib_isert.c |  239 +++++++++++++++++--------------
 1 files changed, 130 insertions(+), 109 deletions(-)

diff --git a/drivers/infiniband/ulp/isert/ib_isert.c b/drivers/infiniband/ulp/isert/ib_isert.c
index 8e2d1e6..2597843 100644
--- a/drivers/infiniband/ulp/isert/ib_isert.c
+++ b/drivers/infiniband/ulp/isert/ib_isert.c
@@ -65,7 +65,7 @@ isert_qp_event_callback(struct ib_event *e, void *context)
 {
 	struct isert_conn *isert_conn = (struct isert_conn *)context;
 
-	isert_err("isert_qp_event_callback event: %d\n", e->event);
+	isert_err("event: %d\n", e->event);
 	switch (e->event) {
 	case IB_EVENT_COMM_EST:
 		rdma_notify(isert_conn->conn_cm_id, IB_EVENT_COMM_EST);
@@ -108,7 +108,7 @@ isert_conn_setup_qp(struct isert_conn *isert_conn, struct rdma_cm_id *cma_id,
 		    device->cq_active_qps[min_index])
 			min_index = index;
 	device->cq_active_qps[min_index]++;
-	isert_dbg("isert_conn_setup_qp: Using min_index: %d\n", min_index);
+	isert_info("conn %p, using min_index: %d\n", isert_conn, min_index);
 	mutex_unlock(&device_list_mutex);
 
 	memset(&attr, 0, sizeof(struct ib_qp_init_attr));
@@ -134,18 +134,12 @@ isert_conn_setup_qp(struct isert_conn *isert_conn, struct rdma_cm_id *cma_id,
 	if (protection)
 		attr.create_flags |= IB_QP_CREATE_SIGNATURE_EN;
 
-	isert_dbg("isert_conn_setup_qp cma_id->device: %p\n",
-		 cma_id->device);
-	isert_dbg("isert_conn_setup_qp conn_pd->device: %p\n",
-		 isert_conn->conn_pd->device);
-
 	ret = rdma_create_qp(cma_id, isert_conn->conn_pd, &attr);
 	if (ret) {
 		isert_err("rdma_create_qp failed for cma_id %d\n", ret);
 		return ret;
 	}
 	isert_conn->conn_qp = cma_id->qp;
-	isert_dbg("rdma_create_qp() returned success >>>>>>>>>>>>>>>>>>>>>>>>>.\n");
 
 	return 0;
 }
@@ -153,7 +147,7 @@ isert_conn_setup_qp(struct isert_conn *isert_conn, struct rdma_cm_id *cma_id,
 static void
 isert_cq_event_callback(struct ib_event *e, void *context)
 {
-	isert_dbg("isert_cq_event_callback event: %d\n", e->event);
+	isert_dbg("event: %d\n", e->event);
 }
 
 static int
@@ -165,6 +159,8 @@ isert_alloc_rx_descriptors(struct isert_conn *isert_conn)
 	u64 dma_addr;
 	int i, j;
 
+	isert_info("conn %p\n", isert_conn);
+
 	isert_conn->conn_rx_descs = kzalloc(ISERT_QP_MAX_RECV_DTOS *
 				sizeof(struct iser_rx_desc), GFP_KERNEL);
 	if (!isert_conn->conn_rx_descs)
@@ -208,6 +204,8 @@ isert_free_rx_descriptors(struct isert_conn *isert_conn)
 	struct iser_rx_desc *rx_desc;
 	int i;
 
+	isert_info("conn %p\n", isert_conn);
+
 	if (!isert_conn->conn_rx_descs)
 		return;
 
@@ -235,6 +233,8 @@ isert_create_device_ib_res(struct isert_device *device)
 	int ret = 0, i, j;
 	int max_rx_cqe, max_tx_cqe;
 
+	isert_info("device %p\n", device);
+
 	dev_attr = &device->dev_attr;
 	ret = isert_query_device(ib_dev, dev_attr);
 	if (ret)
@@ -262,11 +262,11 @@ isert_create_device_ib_res(struct isert_device *device)
 	device->cqs_used = min_t(int, num_online_cpus(),
 				 device->ib_device->num_comp_vectors);
 	device->cqs_used = min(ISERT_MAX_CQ, device->cqs_used);
-	isert_dbg("Using %d CQs, device %s supports %d vectors support "
-		 "Fast registration %d pi_capable %d\n",
-		 device->cqs_used, device->ib_device->name,
-		 device->ib_device->num_comp_vectors, device->use_fastreg,
-		 device->pi_capable);
+	isert_info("Using %d CQs, %s supports %d vectors support "
+		   "Fast registration %d pi_capable %d\n",
+		   device->cqs_used, device->ib_device->name,
+		   device->ib_device->num_comp_vectors, device->use_fastreg,
+		   device->pi_capable);
 	device->cq_desc = kzalloc(sizeof(struct isert_cq_desc) *
 				device->cqs_used, GFP_KERNEL);
 	if (!device->cq_desc) {
@@ -338,6 +338,8 @@ isert_free_device_ib_res(struct isert_device *device)
 	struct isert_cq_desc *cq_desc;
 	int i;
 
+	isert_info("device %p\n", device);
+
 	for (i = 0; i < device->cqs_used; i++) {
 		cq_desc = &device->cq_desc[i];
 
@@ -357,6 +359,7 @@ isert_device_try_release(struct isert_device *device)
 {
 	mutex_lock(&device_list_mutex);
 	device->refcount--;
+	isert_info("device %p refcount %d\n", device, device->refcount);
 	if (!device->refcount) {
 		isert_free_device_ib_res(device);
 		list_del(&device->dev_node);
@@ -376,6 +379,8 @@ isert_device_find_by_ib_dev(struct rdma_cm_id *cma_id)
 		if (device->ib_device->node_guid == cma_id->device->node_guid) {
 			device->refcount++;
 			mutex_unlock(&device_list_mutex);
+			isert_info("Found iser device %p refcount %d\n",
+				   device, device->refcount);
 			return device;
 		}
 	}
@@ -398,6 +403,8 @@ isert_device_find_by_ib_dev(struct rdma_cm_id *cma_id)
 
 	device->refcount++;
 	list_add_tail(&device->dev_node, &device_list);
+	isert_info("Created a new iser device %p refcount %d\n",
+		   device, device->refcount);
 	mutex_unlock(&device_list_mutex);
 
 	return device;
@@ -412,7 +419,7 @@ isert_conn_free_fastreg_pool(struct isert_conn *isert_conn)
 	if (list_empty(&isert_conn->conn_fr_pool))
 		return;
 
-	isert_dbg("Freeing conn %p fastreg pool", isert_conn);
+	isert_info("Freeing conn %p fastreg pool", isert_conn);
 
 	list_for_each_entry_safe(fr_desc, tmp,
 				 &isert_conn->conn_fr_pool, list) {
@@ -431,7 +438,7 @@ isert_conn_free_fastreg_pool(struct isert_conn *isert_conn)
 
 	if (i < isert_conn->conn_fr_pool_size)
 		isert_warn("Pool still has %d regions registered\n",
-			isert_conn->conn_fr_pool_size - i);
+			   isert_conn->conn_fr_pool_size - i);
 }
 
 static int
@@ -475,7 +482,7 @@ isert_create_fr_desc(struct ib_device *ib_device, struct ib_pd *pd,
 						    ISCSI_ISER_SG_TABLESIZE);
 		if (IS_ERR(pi_ctx->prot_frpl)) {
 			isert_err("Failed to allocate prot frpl err=%ld\n",
-			       PTR_ERR(pi_ctx->prot_frpl));
+				  PTR_ERR(pi_ctx->prot_frpl));
 			ret = PTR_ERR(pi_ctx->prot_frpl);
 			goto err_pi_ctx;
 		}
@@ -483,7 +490,7 @@ isert_create_fr_desc(struct ib_device *ib_device, struct ib_pd *pd,
 		pi_ctx->prot_mr = ib_alloc_fast_reg_mr(pd, ISCSI_ISER_SG_TABLESIZE);
 		if (IS_ERR(pi_ctx->prot_mr)) {
 			isert_err("Failed to allocate prot frmr err=%ld\n",
-			       PTR_ERR(pi_ctx->prot_mr));
+				  PTR_ERR(pi_ctx->prot_mr));
 			ret = PTR_ERR(pi_ctx->prot_mr);
 			goto err_prot_frpl;
 		}
@@ -494,7 +501,7 @@ isert_create_fr_desc(struct ib_device *ib_device, struct ib_pd *pd,
 		pi_ctx->sig_mr = ib_create_mr(pd, &mr_init_attr);
 		if (IS_ERR(pi_ctx->sig_mr)) {
 			isert_err("Failed to allocate signature enabled mr err=%ld\n",
-			       PTR_ERR(pi_ctx->sig_mr));
+				  PTR_ERR(pi_ctx->sig_mr));
 			ret = PTR_ERR(pi_ctx->sig_mr);
 			goto err_prot_mr;
 		}
@@ -525,6 +532,8 @@ isert_conn_create_fastreg_pool(struct isert_conn *isert_conn, u8 pi_support)
 	struct se_session *se_sess = isert_conn->conn->sess->se_sess;
 	struct se_node_acl *se_nacl = se_sess->se_node_acl;
 	int i, ret, tag_num;
+
+	isert_info("Creating conn %p fastreg pool", isert_conn);
 	/*
 	 * Setup the number of FRMRs based upon the number of tags
 	 * available to session in iscsi_target_locate_portal().
@@ -579,7 +588,7 @@ isert_connect_request(struct rdma_cm_id *cma_id, struct rdma_cm_event *event)
 	spin_lock_bh(&np->np_thread_lock);
 	if (!np->enabled) {
 		spin_unlock_bh(&np->np_thread_lock);
-		isert_dbg("iscsi_np is not enabled, reject connect request\n");
+		isert_dbg("iscsi_np is not enabled, reject request\n");
 		return rdma_reject(cma_id, NULL, 0);
 	}
 	spin_unlock_bh(&np->np_thread_lock);
@@ -720,7 +729,7 @@ isert_connect_release(struct isert_conn *isert_conn)
 	struct isert_device *device = isert_conn->conn_device;
 	int cq_index;
 
-	isert_dbg("isert_conn %p\n", isert_conn);
+	isert_dbg("conn %p\n", isert_conn);
 
 	if (device && device->use_fastreg)
 		isert_conn_free_fastreg_pool(isert_conn);
@@ -759,6 +768,8 @@ isert_connected_handler(struct rdma_cm_id *cma_id)
 {
 	struct isert_conn *isert_conn = cma_id->context;
 
+	isert_dbg("conn %p\n", isert_conn);
+
 	kref_get(&isert_conn->conn_kref);
 }
 
@@ -768,7 +779,7 @@ isert_release_conn_kref(struct kref *kref)
 	struct isert_conn *isert_conn = container_of(kref,
 				struct isert_conn, conn_kref);
 
-	isert_dbg("final kref %s/%d\n", current->comm, current->pid);
+	isert_info("final kref %s/%d\n", current->comm, current->pid);
 	isert_connect_release(isert_conn);
 }
 
@@ -784,7 +795,8 @@ isert_disconnect_work(struct work_struct *work)
 	struct isert_conn *isert_conn = container_of(work,
 				struct isert_conn, conn_logout_work);
 
-	isert_dbg("isert_conn %p\n", isert_conn);
+	isert_info("conn %p\n", isert_conn);
+
 	mutex_lock(&isert_conn->conn_mutex);
 	if (isert_conn->state == ISER_CONN_UP)
 		isert_conn->state = ISER_CONN_TERMINATING;
@@ -838,8 +850,8 @@ isert_cma_handler(struct rdma_cm_id *cma_id, struct rdma_cm_event *event)
 	int ret = 0;
 	bool disconnect = false;
 
-	isert_dbg("isert_cma_handler: event %d status %d conn %p id %p\n",
-		  event->event, event->status, cma_id->context, cma_id);
+	isert_info("event %d status %d id %p id_context %p\n", event->event,
+		   event->status, cma_id, cma_id->context);
 
 	switch (event->event) {
 	case RDMA_CM_EVENT_CONNECT_REQUEST:
@@ -891,7 +903,7 @@ isert_post_recv(struct isert_conn *isert_conn, u32 count)
 	ret = ib_post_recv(isert_conn->conn_qp, isert_conn->conn_rx_wr,
 				&rx_wr_failed);
 	if (ret) {
-		isert_err("failed with ret: %d\n", ret);
+		isert_err("post_recv failed with ret: %d\n", ret);
 		isert_conn->post_recv_buf_count -= count;
 	} else {
 		isert_dbg("posted %d RX buffers\n", count);
@@ -969,9 +981,9 @@ isert_init_tx_hdrs(struct isert_conn *isert_conn,
 	tx_desc->tx_sg[0].length = ISER_HEADERS_LEN;
 	tx_desc->tx_sg[0].lkey = isert_conn->conn_mr->lkey;
 
-	isert_dbg("isert_init_tx_hdrs: Setup tx_sg[0].addr: 0x%llx length: %u"
-		 " lkey: 0x%08x\n", tx_desc->tx_sg[0].addr,
-		 tx_desc->tx_sg[0].length, tx_desc->tx_sg[0].lkey);
+	isert_dbg("Setup tx_sg[0].addr: 0x%llx length: %u lkey: 0x%x\n",
+		  tx_desc->tx_sg[0].addr, tx_desc->tx_sg[0].length,
+		  tx_desc->tx_sg[0].lkey);
 
 	return 0;
 }
@@ -1033,7 +1045,8 @@ isert_rdma_post_recvl(struct isert_conn *isert_conn)
 		isert_conn->post_recv_buf_count--;
 	}
 
-	isert_dbg("ib_post_recv(): returned success >>>>>>>>>>>>>>>>>>>>>>>>\n");
+	isert_dbg("ib_post_recv(): returned success\n");
+
 	return ret;
 }
 
@@ -1080,7 +1093,7 @@ isert_put_login_tx(struct iscsi_conn *conn, struct iscsi_login *login,
 								     pi_support);
 				if (ret) {
 					isert_err("Conn: %p failed to create"
-					       " fastreg pool\n", isert_conn);
+						  " fastreg pool\n", isert_conn);
 					return ret;
 				}
 			}
@@ -1117,8 +1130,10 @@ isert_rx_login_req(struct iser_rx_desc *rx_desc, int rx_buflen,
 	struct iscsi_login *login = conn->conn_login;
 	int size;
 
+	isert_info("conn %p\n", isert_conn);
+
 	if (!login) {
-		isert_err("conn->conn_login is NULL\n");
+		isert_err("conn %p conn_login is NULL\n", isert_conn);
 		dump_stack();
 		return;
 	}
@@ -1147,8 +1162,9 @@ isert_rx_login_req(struct iser_rx_desc *rx_desc, int rx_buflen,
 	memcpy(&login->req[0], (void *)&rx_desc->iscsi_header, ISCSI_HDR_LEN);
 
 	size = min(rx_buflen, MAX_KEY_VALUE_PAIRS);
-	isert_dbg("Using login payload size: %d, rx_buflen: %d MAX_KEY_VALUE_PAIRS: %d\n",
-		 size, rx_buflen, MAX_KEY_VALUE_PAIRS);
+	isert_dbg("Using login payload size: %d, rx_buflen: %d "
+		  "MAX_KEY_VALUE_PAIRS: %d\n", size, rx_buflen,
+		  MAX_KEY_VALUE_PAIRS);
 	memcpy(login->req_buf, &rx_desc->data[0], size);
 
 	if (login->first_request) {
@@ -1211,7 +1227,7 @@ isert_handle_scsi_cmd(struct isert_conn *isert_conn,
 	sg_nents = max(1UL, DIV_ROUND_UP(imm_data_len, PAGE_SIZE));
 
 	isert_dbg("Copying Immediate SG: %p sg_nents: %u from %p imm_data_len: %d\n",
-		 sg, sg_nents, &rx_desc->data[0], imm_data_len);
+		  sg, sg_nents, &rx_desc->data[0], imm_data_len);
 
 	sg_copy_from_buffer(sg, sg_nents, &rx_desc->data[0], imm_data_len);
 
@@ -1260,8 +1276,10 @@ isert_handle_iscsi_dataout(struct isert_conn *isert_conn,
 		return -1;
 	}
 
-	isert_dbg("Unsolicited DataOut unsol_data_len: %u, write_data_done: %u, data_length: %u\n",
-		 unsol_data_len, cmd->write_data_done, cmd->se_cmd.data_length);
+	isert_dbg("Unsolicited DataOut unsol_data_len: %u, "
+		  "write_data_done: %u, data_length: %u\n",
+		  unsol_data_len,  cmd->write_data_done,
+		  cmd->se_cmd.data_length);
 
 	sg_off = cmd->write_data_done / PAGE_SIZE;
 	sg_start = &cmd->se_cmd.t_data_sg[sg_off];
@@ -1271,12 +1289,14 @@ isert_handle_iscsi_dataout(struct isert_conn *isert_conn,
 	 * FIXME: Non page-aligned unsolicited_data out
 	 */
 	if (page_off) {
-		isert_err("Received unexpected non-page aligned data payload\n");
+		isert_err("Received unexpected non-page "
+			  "aligned data payload\n");
 		dump_stack();
 		return -1;
 	}
-	isert_dbg("Copying DataOut: sg_start: %p, sg_off: %u sg_nents: %u from %p %u\n",
-		 sg_start, sg_off, sg_nents, &rx_desc->data[0], unsol_data_len);
+	isert_dbg("Copying DataOut: sg_start: %p, sg_off: %u "
+		  "sg_nents: %u from %p %u\n", sg_start, sg_off,
+		  sg_nents, &rx_desc->data[0], unsol_data_len);
 
 	sg_copy_from_buffer(sg_start, sg_nents, &rx_desc->data[0],
 			    unsol_data_len);
@@ -1324,7 +1344,7 @@ isert_handle_text_cmd(struct isert_conn *isert_conn, struct isert_cmd *isert_cmd
 	text_in = kzalloc(payload_length, GFP_KERNEL);
 	if (!text_in) {
 		isert_err("Unable to allocate text_in of payload_length: %u\n",
-		       payload_length);
+			  payload_length);
 		return -ENOMEM;
 	}
 	cmd->text_in_ptr = text_in;
@@ -1350,7 +1370,7 @@ isert_rx_opcode(struct isert_conn *isert_conn, struct iser_rx_desc *rx_desc,
 	if (sess->sess_ops->SessionType &&
 	   (!(opcode & ISCSI_OP_TEXT) || !(opcode & ISCSI_OP_LOGOUT))) {
 		isert_err("Got illegal opcode: 0x%02x in SessionType=Discovery,"
-		       " ignoring\n", opcode);
+			  " ignoring\n", opcode);
 		return 0;
 	}
 
@@ -1432,13 +1452,13 @@ isert_rx_do_work(struct iser_rx_desc *rx_desc, struct isert_conn *isert_conn)
 		if (iser_hdr->flags & ISER_RSV) {
 			read_stag = be32_to_cpu(iser_hdr->read_stag);
 			read_va = be64_to_cpu(iser_hdr->read_va);
-			isert_dbg("ISER_RSV: read_stag: 0x%08x read_va: 0x%16llx\n",
+			isert_dbg("ISER_RSV: read_stag: 0x%x read_va: 0x%llx\n",
 				 read_stag, (unsigned long long)read_va);
 		}
 		if (iser_hdr->flags & ISER_WSV) {
 			write_stag = be32_to_cpu(iser_hdr->write_stag);
 			write_va = be64_to_cpu(iser_hdr->write_va);
-			isert_dbg("ISER_WSV: write__stag: 0x%08x write_va: 0x%16llx\n",
+			isert_dbg("ISER_WSV: write_stag: 0x%x write_va: 0x%llx\n",
 				 write_stag, (unsigned long long)write_va);
 		}
 
@@ -1468,12 +1488,12 @@ isert_rx_completion(struct iser_rx_desc *desc, struct isert_conn *isert_conn,
 	if ((char *)desc == isert_conn->login_req_buf) {
 		rx_dma = isert_conn->login_req_dma;
 		rx_buflen = ISER_RX_LOGIN_SIZE;
-		isert_dbg("ISER login_buf: Using rx_dma: 0x%llx, rx_buflen: %d\n",
+		isert_dbg("login_buf: Using rx_dma: 0x%llx, rx_buflen: %d\n",
 			 rx_dma, rx_buflen);
 	} else {
 		rx_dma = desc->dma_addr;
 		rx_buflen = ISER_RX_PAYLOAD_SIZE;
-		isert_dbg("ISER req_buf: Using rx_dma: 0x%llx, rx_buflen: %d\n",
+		isert_dbg("req_buf: Using rx_dma: 0x%llx, rx_buflen: %d\n",
 			 rx_dma, rx_buflen);
 	}
 
@@ -1494,7 +1514,7 @@ isert_rx_completion(struct iser_rx_desc *desc, struct isert_conn *isert_conn,
 				      DMA_FROM_DEVICE);
 
 	isert_conn->post_recv_buf_count--;
-	isert_dbg("iSERT: Decremented post_recv_buf_count: %d\n",
+	isert_dbg("Decremented post_recv_buf_count: %d\n",
 		 isert_conn->post_recv_buf_count);
 
 	if ((char *)desc == isert_conn->login_req_buf)
@@ -1540,7 +1560,7 @@ isert_map_data_buf(struct isert_conn *isert_conn, struct isert_cmd *isert_cmd,
 	}
 
 	isert_dbg("Mapped cmd: %p count: %u sg: %p sg_nents: %u rdma_len %d\n",
-		 isert_cmd, data->dma_nents, data->sg, data->nents, data->len);
+		  isert_cmd, data->dma_nents, data->sg, data->nents, data->len);
 
 	return 0;
 }
@@ -1561,7 +1581,7 @@ isert_unmap_cmd(struct isert_cmd *isert_cmd, struct isert_conn *isert_conn)
 {
 	struct isert_rdma_wr *wr = &isert_cmd->rdma_wr;
 
-	isert_dbg("isert_unmap_cmd: %p\n", isert_cmd);
+	isert_dbg("Cmd %p\n", isert_cmd);
 
 	if (wr->data.sg) {
 		isert_dbg("isert_unmap_cmd: %p unmap_sg op\n", isert_cmd);
@@ -1587,10 +1607,10 @@ isert_unreg_rdma(struct isert_cmd *isert_cmd, struct isert_conn *isert_conn)
 	struct isert_rdma_wr *wr = &isert_cmd->rdma_wr;
 	LIST_HEAD(unmap_list);
 
-	isert_dbg("unreg_fastreg_cmd: %p\n", isert_cmd);
+	isert_dbg("Cmd %p\n", isert_cmd);
 
 	if (wr->fr_desc) {
-		isert_dbg("unreg_fastreg_cmd: %p free fr_desc %p\n",
+		isert_dbg("Cmd %p free fr_desc %p\n",
 			 isert_cmd, wr->fr_desc);
 		if (wr->fr_desc->ind & ISERT_PROTECTED) {
 			isert_unmap_data_buf(isert_conn, &wr->prot);
@@ -1603,7 +1623,7 @@ isert_unreg_rdma(struct isert_cmd *isert_cmd, struct isert_conn *isert_conn)
 	}
 
 	if (wr->data.sg) {
-		isert_dbg("unreg_fastreg_cmd: %p unmap_sg op\n", isert_cmd);
+		isert_dbg("Cmd %p unmap_sg op\n", isert_cmd);
 		isert_unmap_data_buf(isert_conn, &wr->data);
 	}
 
@@ -1619,7 +1639,7 @@ isert_put_cmd(struct isert_cmd *isert_cmd, bool comp_err)
 	struct iscsi_conn *conn = isert_conn->conn;
 	struct isert_device *device = isert_conn->conn_device;
 
-	isert_dbg("Entering isert_put_cmd: %p\n", isert_cmd);
+	isert_dbg("Cmd %p\n", isert_cmd);
 
 	switch (cmd->iscsi_opcode) {
 	case ISCSI_OP_SCSI_CMD:
@@ -1670,7 +1690,7 @@ isert_put_cmd(struct isert_cmd *isert_cmd, bool comp_err)
 		 */
 		if (cmd->se_cmd.se_tfo != NULL) {
 			isert_dbg("Calling transport_generic_free_cmd from"
-				 " isert_put_cmd for 0x%02x\n",
+				  " isert_put_cmd for 0x%02x\n",
 				 cmd->iscsi_opcode);
 			transport_generic_free_cmd(&cmd->se_cmd, 0);
 			break;
@@ -1688,7 +1708,7 @@ static void
 isert_unmap_tx_desc(struct iser_tx_desc *tx_desc, struct ib_device *ib_dev)
 {
 	if (tx_desc->dma_addr != 0) {
-		isert_dbg("Calling ib_dma_unmap_single for tx_desc->dma_addr\n");
+		isert_dbg("ib_dma_unmap_single for tx_desc->dma_addr\n");
 		ib_dma_unmap_single(ib_dev, tx_desc->dma_addr,
 				    ISER_HEADERS_LEN, DMA_TO_DEVICE);
 		tx_desc->dma_addr = 0;
@@ -1700,7 +1720,7 @@ isert_completion_put(struct iser_tx_desc *tx_desc, struct isert_cmd *isert_cmd,
 		     struct ib_device *ib_dev, bool comp_err)
 {
 	if (isert_cmd->pdu_buf_dma != 0) {
-		isert_dbg("Calling ib_dma_unmap_single for isert_cmd->pdu_buf_dma\n");
+		isert_dbg("ib_dma_unmap_single for isert_cmd->pdu_buf_dma\n");
 		ib_dma_unmap_single(ib_dev, isert_cmd->pdu_buf_dma,
 				    isert_cmd->pdu_buf_len, DMA_TO_DEVICE);
 		isert_cmd->pdu_buf_dma = 0;
@@ -1742,11 +1762,11 @@ isert_check_pi_status(struct se_cmd *se_cmd, struct ib_mr *sig_mr)
 		se_cmd->bad_sector = sec_offset_err + se_cmd->t_task_lba;
 
 		isert_err("isert: PI error found type %d at sector 0x%llx "
-		       "expected 0x%x vs actual 0x%x\n",
-		       mr_status.sig_err.err_type,
-		       (unsigned long long)se_cmd->bad_sector,
-		       mr_status.sig_err.expected,
-		       mr_status.sig_err.actual);
+			  "expected 0x%x vs actual 0x%x\n",
+			  mr_status.sig_err.err_type,
+			  (unsigned long long)se_cmd->bad_sector,
+			  mr_status.sig_err.expected,
+			  mr_status.sig_err.actual);
 		ret = 1;
 	}
 
@@ -1826,7 +1846,7 @@ isert_do_control_comp(struct work_struct *work)
 
 	switch (cmd->i_state) {
 	case ISTATE_SEND_TASKMGTRSP:
-		isert_dbg("Calling iscsit_tmr_post_handler >>>>>>>>>>>>>>>>>\n");
+		isert_dbg("Calling iscsit_tmr_post_handler\n");
 
 		atomic_dec(&isert_conn->post_send_buf_count);
 		iscsit_tmr_post_handler(cmd, cmd->conn);
@@ -1835,14 +1855,14 @@ isert_do_control_comp(struct work_struct *work)
 		isert_completion_put(&isert_cmd->tx_desc, isert_cmd, ib_dev, false);
 		break;
 	case ISTATE_SEND_REJECT:
-		isert_dbg("Got isert_do_control_comp ISTATE_SEND_REJECT: >>>\n");
+		isert_dbg("Got ISTATE_SEND_REJECT\n");
 		atomic_dec(&isert_conn->post_send_buf_count);
 
 		cmd->i_state = ISTATE_SENT_STATUS;
 		isert_completion_put(&isert_cmd->tx_desc, isert_cmd, ib_dev, false);
 		break;
 	case ISTATE_SEND_LOGOUTRSP:
-		isert_dbg("Calling iscsit_logout_post_handler >>>>>>>>>>>>>>\n");
+		isert_dbg("Calling iscsit_logout_post_handler\n");
 
 		atomic_dec(&isert_conn->post_send_buf_count);
 		iscsit_logout_post_handler(cmd, cmd->conn);
@@ -1853,7 +1873,7 @@ isert_do_control_comp(struct work_struct *work)
 		isert_completion_put(&isert_cmd->tx_desc, isert_cmd, ib_dev, false);
 		break;
 	default:
-		isert_err("Unknown do_control_comp i_state %d\n", cmd->i_state);
+		isert_err("Unknown i_state %d\n", cmd->i_state);
 		dump_stack();
 		break;
 	}
@@ -1912,27 +1932,27 @@ __isert_send_completion(struct iser_tx_desc *tx_desc,
 
 	switch (wr->iser_ib_op) {
 	case ISER_IB_RECV:
-		isert_err("isert_send_completion: Got ISER_IB_RECV\n");
+		isert_err("Got ISER_IB_RECV\n");
 		dump_stack();
 		break;
 	case ISER_IB_SEND:
-		isert_dbg("isert_send_completion: Got ISER_IB_SEND\n");
+		isert_dbg("Got ISER_IB_SEND\n");
 		isert_response_completion(tx_desc, isert_cmd,
 					  isert_conn, ib_dev);
 		break;
 	case ISER_IB_RDMA_WRITE:
-		isert_dbg("isert_send_completion: Got ISER_IB_RDMA_WRITE\n");
+		isert_dbg("Got ISER_IB_RDMA_WRITE\n");
 		atomic_sub(wr->send_wr_num, &isert_conn->post_send_buf_count);
 		isert_completion_rdma_write(tx_desc, isert_cmd);
 		break;
 	case ISER_IB_RDMA_READ:
-		isert_dbg("isert_send_completion: Got ISER_IB_RDMA_READ:\n");
+		isert_dbg("Got ISER_IB_RDMA_READ:\n");
 
 		atomic_sub(wr->send_wr_num, &isert_conn->post_send_buf_count);
 		isert_completion_rdma_read(tx_desc, isert_cmd);
 		break;
 	default:
-		isert_err("Unknown wr->iser_ib_op: 0x%02x\n", wr->iser_ib_op);
+		isert_err("Unknown iser_ib_op: 0x%02x\n", wr->iser_ib_op);
 		dump_stack();
 		break;
 	}
@@ -2074,7 +2094,7 @@ isert_cq_tx_work(struct work_struct *work)
 		if (wc.status == IB_WC_SUCCESS) {
 			isert_send_completion(tx_desc, isert_conn);
 		} else {
-			isert_dbg("TX wc.status != IB_WC_SUCCESS >>>>>>>>>>>>>>\n");
+			isert_dbg("TX wc.status != IB_WC_SUCCESS\n");
 			isert_dbg("TX wc.status: 0x%08x\n", wc.status);
 			isert_dbg("TX wc.vendor_err: 0x%08x\n", wc.vendor_err);
 
@@ -2120,7 +2140,7 @@ isert_cq_rx_work(struct work_struct *work)
 			xfer_len = (unsigned long)wc.byte_len;
 			isert_rx_completion(rx_desc, isert_conn, xfer_len);
 		} else {
-			isert_dbg("RX wc.status != IB_WC_SUCCESS >>>>>>>>>>>>>>\n");
+			isert_dbg("RX wc.status != IB_WC_SUCCESS\n");
 			if (wc.status != IB_WC_WR_FLUSH_ERR) {
 				isert_dbg("RX wc.status: 0x%08x\n", wc.status);
 				isert_dbg("RX wc.vendor_err: 0x%08x\n",
@@ -2203,7 +2223,7 @@ isert_put_response(struct iscsi_conn *conn, struct iscsi_cmd *cmd)
 
 	isert_init_send_wr(isert_conn, isert_cmd, send_wr, false);
 
-	isert_dbg("Posting SCSI Response IB_WR_SEND >>>>>>>>>>>>>>>>>>>>>>\n");
+	isert_dbg("Posting SCSI Response\n");
 
 	return isert_post_response(isert_conn, isert_cmd);
 }
@@ -2253,7 +2273,7 @@ isert_put_nopin(struct iscsi_cmd *cmd, struct iscsi_conn *conn,
 	isert_init_tx_hdrs(isert_conn, &isert_cmd->tx_desc);
 	isert_init_send_wr(isert_conn, isert_cmd, send_wr, false);
 
-	isert_dbg("Posting NOPIN Response IB_WR_SEND >>>>>>>>>>>>>>>>>>>>>>\n");
+	isert_dbg("Posting NOPIN Response\n");
 
 	return isert_post_response(isert_conn, isert_cmd);
 }
@@ -2271,7 +2291,7 @@ isert_put_logout_rsp(struct iscsi_cmd *cmd, struct iscsi_conn *conn)
 	isert_init_tx_hdrs(isert_conn, &isert_cmd->tx_desc);
 	isert_init_send_wr(isert_conn, isert_cmd, send_wr, false);
 
-	isert_dbg("Posting Logout Response IB_WR_SEND >>>>>>>>>>>>>>>>>>>>>>\n");
+	isert_dbg("Posting Logout Response\n");
 
 	return isert_post_response(isert_conn, isert_cmd);
 }
@@ -2289,7 +2309,7 @@ isert_put_tm_rsp(struct iscsi_cmd *cmd, struct iscsi_conn *conn)
 	isert_init_tx_hdrs(isert_conn, &isert_cmd->tx_desc);
 	isert_init_send_wr(isert_conn, isert_cmd, send_wr, false);
 
-	isert_dbg("Posting Task Management Response IB_WR_SEND >>>>>>>>>>>>>>>>>>>>>>\n");
+	isert_dbg("Posting Task Management Response\n");
 
 	return isert_post_response(isert_conn, isert_cmd);
 }
@@ -2321,7 +2341,7 @@ isert_put_reject(struct iscsi_cmd *cmd, struct iscsi_conn *conn)
 
 	isert_init_send_wr(isert_conn, isert_cmd, send_wr, false);
 
-	isert_dbg("Posting Reject IB_WR_SEND >>>>>>>>>>>>>>>>>>>>>>\n");
+	isert_dbg("Posting Reject\n");
 
 	return isert_post_response(isert_conn, isert_cmd);
 }
@@ -2361,7 +2381,7 @@ isert_put_text_rsp(struct iscsi_cmd *cmd, struct iscsi_conn *conn)
 	}
 	isert_init_send_wr(isert_conn, isert_cmd, send_wr, false);
 
-	isert_dbg("Posting Text Response IB_WR_SEND >>>>>>>>>>>>>>>>>>>>>>\n");
+	isert_dbg("Posting Text Response\n");
 
 	return isert_post_response(isert_conn, isert_cmd);
 }
@@ -2389,17 +2409,18 @@ isert_build_rdma_wr(struct isert_conn *isert_conn, struct isert_cmd *isert_cmd,
 	 * Perform mapping of TCM scatterlist memory ib_sge dma_addr.
 	 */
 	for_each_sg(sg_start, tmp_sg, sg_nents, i) {
-		isert_dbg("ISER RDMA from SGL dma_addr: 0x%16llx dma_len: %u, page_off: %u\n",
-			 (unsigned long long)tmp_sg->dma_address,
-			 tmp_sg->length, page_off);
+		isert_dbg("RDMA from SGL dma_addr: 0x%llx dma_len: %u, "
+			  "page_off: %u\n",
+			  (unsigned long long)tmp_sg->dma_address,
+			  tmp_sg->length, page_off);
 
 		ib_sge->addr = ib_sg_dma_address(ib_dev, tmp_sg) + page_off;
 		ib_sge->length = min_t(u32, data_left,
 				ib_sg_dma_len(ib_dev, tmp_sg) - page_off);
 		ib_sge->lkey = isert_conn->conn_mr->lkey;
 
-		isert_dbg("RDMA ib_sge: addr: 0x%16llx  length: %u lkey: %08x\n",
-			 ib_sge->addr, ib_sge->length, ib_sge->lkey);
+		isert_dbg("RDMA ib_sge: addr: 0x%llx  length: %u lkey: %x\n",
+			  ib_sge->addr, ib_sge->length, ib_sge->lkey);
 		page_off = 0;
 		data_left -= ib_sge->length;
 		ib_sge++;
@@ -2407,7 +2428,7 @@ isert_build_rdma_wr(struct isert_conn *isert_conn, struct isert_cmd *isert_cmd,
 	}
 
 	isert_dbg("Set outgoing sg_list: %p num_sg: %u from TCM SGLs\n",
-		 send_wr->sg_list, send_wr->num_sge);
+		  send_wr->sg_list, send_wr->num_sge);
 
 	return sg_nents;
 }
@@ -2513,9 +2534,9 @@ isert_map_fr_pagelist(struct ib_device *ib_dev,
 			chunk_start = start_addr;
 		end_addr = start_addr + ib_sg_dma_len(ib_dev, tmp_sg);
 
-		isert_dbg("SGL[%d] dma_addr: 0x%16llx len: %u\n",
-			 i, (unsigned long long)tmp_sg->dma_address,
-			 tmp_sg->length);
+		isert_dbg("SGL[%d] dma_addr: 0x%llx len: %u\n",
+			  i, (unsigned long long)tmp_sg->dma_address,
+			  tmp_sg->length);
 
 		if ((end_addr & ~PAGE_MASK) && i < last_ent) {
 			new_chunk = 0;
@@ -2526,8 +2547,8 @@ isert_map_fr_pagelist(struct ib_device *ib_dev,
 		page = chunk_start & PAGE_MASK;
 		do {
 			fr_pl[n_pages++] = page;
-			isert_dbg("Mapped page_list[%d] page_addr: 0x%16llx\n",
-				 n_pages - 1, page);
+			isert_dbg("Mapped page_list[%d] page_addr: 0x%llx\n",
+				  n_pages - 1, page);
 			page += PAGE_SIZE;
 		} while (page < end_addr);
 	}
@@ -2556,8 +2577,8 @@ isert_fast_reg_mr(struct isert_conn *isert_conn,
 		sge->addr = ib_sg_dma_address(ib_dev, &mem->sg[0]);
 		sge->length = ib_sg_dma_len(ib_dev, &mem->sg[0]);
 		isert_dbg("%s:%d sge: addr: 0x%llx  length: %u lkey: %x\n",
-			 __func__, __LINE__, sge->addr, sge->length,
-			 sge->lkey);
+			  __func__, __LINE__, sge->addr, sge->length,
+			  sge->lkey);
 		return 0;
 	}
 
@@ -2574,7 +2595,7 @@ isert_fast_reg_mr(struct isert_conn *isert_conn,
 	page_off = mem->offset % PAGE_SIZE;
 
 	isert_dbg("Use fr_desc %p sg_nents %d offset %u\n",
-		 fr_desc, mem->nents, mem->offset);
+		  fr_desc, mem->nents, mem->offset);
 
 	pagelist_len = isert_map_fr_pagelist(ib_dev, mem->sg, mem->nents,
 					     &frpl->page_list[0]);
@@ -2619,8 +2640,8 @@ isert_fast_reg_mr(struct isert_conn *isert_conn,
 	sge->length = mem->len;
 
 	isert_dbg("%s:%d sge: addr: 0x%llx  length: %u lkey: %x\n",
-		 __func__, __LINE__, sge->addr, sge->length,
-		 sge->lkey);
+		  __func__, __LINE__, sge->addr, sge->length,
+		  sge->lkey);
 
 	return ret;
 }
@@ -2747,8 +2768,8 @@ isert_reg_sig_mr(struct isert_conn *isert_conn, struct se_cmd *se_cmd,
 		sig_sge->length += se_cmd->prot_length;
 
 	isert_dbg("sig_sge: addr: 0x%llx  length: %u lkey: %x\n",
-		 sig_sge->addr, sig_sge->length,
-		 sig_sge->lkey);
+		  sig_sge->addr, sig_sge->length,
+		  sig_sge->lkey);
 err:
 	return ret;
 }
@@ -2922,7 +2943,7 @@ isert_get_dataout(struct iscsi_conn *conn, struct iscsi_cmd *cmd, bool recovery)
 	int rc;
 
 	isert_dbg("Cmd: %p RDMA_READ data_length: %u write_data_done: %u\n",
-		 isert_cmd, se_cmd->data_length, cmd->write_data_done);
+		  isert_cmd, se_cmd->data_length, cmd->write_data_done);
 	wr->iser_ib_op = ISER_IB_RDMA_READ;
 	rc = device->reg_rdma_mem(conn, cmd, wr);
 	if (rc) {
@@ -3033,7 +3054,7 @@ isert_setup_np(struct iscsi_np *np,
 	isert_lid = rdma_create_id(isert_cma_handler, np, RDMA_PS_TCP,
 				IB_QPT_RC);
 	if (IS_ERR(isert_lid)) {
-		isert_err("rdma_create_id() for isert_listen_handler failed: %ld\n",
+		isert_err("rdma_create_id() failed: %ld\n",
 		       PTR_ERR(isert_lid));
 		ret = PTR_ERR(isert_lid);
 		goto out;
@@ -3041,13 +3062,13 @@ isert_setup_np(struct iscsi_np *np,
 
 	ret = rdma_bind_addr(isert_lid, sa);
 	if (ret) {
-		isert_err("rdma_bind_addr() for isert_lid failed: %d\n", ret);
+		isert_err("rdma_bind_addr() failed: %d\n", ret);
 		goto out_lid;
 	}
 
 	ret = rdma_listen(isert_lid, ISERT_RDMA_LISTEN_BACKLOG);
 	if (ret) {
-		isert_err("rdma_listen() for isert_lid failed: %d\n", ret);
+		isert_err("rdma_listen() failed: %d\n", ret);
 		goto out_lid;
 	}
 
@@ -3076,7 +3097,7 @@ isert_rdma_accept(struct isert_conn *isert_conn)
 	cp.retry_count = 7;
 	cp.rnr_retry_count = 7;
 
-	isert_dbg("Before rdma_accept >>>>>>>>>>>>>>>>>>>>.\n");
+	isert_dbg("Before rdma_accept\n");
 
 	ret = rdma_accept(cm_id, &cp);
 	if (ret) {
@@ -3084,7 +3105,7 @@ isert_rdma_accept(struct isert_conn *isert_conn)
 		return ret;
 	}
 
-	isert_dbg("After rdma_accept >>>>>>>>>>>>>>>>>>>>>.\n");
+	isert_dbg("After rdma_accept\n");
 
 	return 0;
 }
@@ -3095,7 +3116,7 @@ isert_get_login_rx(struct iscsi_conn *conn, struct iscsi_login *login)
 	struct isert_conn *isert_conn = (struct isert_conn *)conn->context;
 	int ret;
 
-	isert_dbg("isert_get_login_rx before conn_login_comp conn: %p\n", conn);
+	isert_dbg("before conn_login_comp conn: %p\n", conn);
 	/*
 	 * For login requests after the first PDU, isert_rx_login_req() will
 	 * kick schedule_delayed_work(&conn->login_work) as the packet is
@@ -3109,7 +3130,7 @@ isert_get_login_rx(struct iscsi_conn *conn, struct iscsi_login *login)
 	if (ret)
 		return ret;
 
-	isert_dbg("isert_get_login_rx processing login->req: %p\n", login->req);
+	isert_dbg("processing login->req: %p\n", login->req);
 	return 0;
 }
 
@@ -3197,7 +3218,7 @@ accept_wait:
 
 	isert_set_conn_info(np, conn, isert_conn);
 
-	isert_dbg("Processing isert_accept_np: isert_conn: %p\n", isert_conn);
+	isert_dbg("Processing isert_conn: %p\n", isert_conn);
 	return 0;
 }
 
@@ -3217,11 +3238,11 @@ static void isert_wait_conn(struct iscsi_conn *conn)
 {
 	struct isert_conn *isert_conn = conn->context;
 
-	isert_dbg("Starting conn %p\n", isert_conn);
+	isert_info("Starting conn %p\n", isert_conn);
 
 	mutex_lock(&isert_conn->conn_mutex);
 	if (isert_conn->conn_cm_id && !isert_conn->disconnect) {
-		isert_dbg("Calling rdma_disconnect from isert_wait_conn\n");
+		isert_dbg("Calling rdma_disconnect\n");
 		rdma_disconnect(isert_conn->conn_cm_id);
 	}
 	/*
@@ -3288,7 +3309,7 @@ static int __init isert_init(void)
 	}
 
 	iscsit_register_transport(&iser_target_transport);
-	isert_dbg("iSER_TARGET[0] - Loaded iser_target_transport\n");
+	isert_info("iSER_TARGET[0] - Loaded iser_target_transport\n");
 	return 0;
 
 destroy_rx_wq:
@@ -3302,7 +3323,7 @@ static void __exit isert_exit(void)
 	destroy_workqueue(isert_comp_wq);
 	destroy_workqueue(isert_rx_wq);
 	iscsit_unregister_transport(&iser_target_transport);
-	isert_dbg("iSER_TARGET[0] - Released iser_target_transport\n");
+	isert_info("iSER_TARGET[0] - Released iser_target_transport\n");
 }
 
 MODULE_DESCRIPTION("iSER-Target for mainline target infrastructure");
-- 
1.7.1

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




[Index of Archives]     [Linux SCSI]     [Kernel Newbies]     [Linux SCSI Target Infrastructure]     [Share Photos]     [IDE]     [Security]     [Git]     [Netfilter]     [Bugtraq]     [Yosemite News]     [MIPS Linux]     [ARM Linux]     [Linux Security]     [Linux RAID]     [Linux ATA RAID]     [Linux IIO]     [Device Mapper]

  Powered by Linux