Blob Blame History Raw
From: Dick Kennedy <dick.kennedy@broadcom.com>
Date: Fri, 29 Sep 2017 17:34:33 -0700
Subject: scsi: lpfc: Make ktime sampling more accurate
Patch-mainline: Queued in subsystem maintainer repository
Git-repo: git://git.kernel.org/pub/scm/linux/kernel/git/jejb/scsi.git
Git-commit: c8a4ce0bf3aad1a73d5122a3781a0be83bc0d0a4
References: bsc#1050239,FATE#322918

Need to make ktime samples more accurate

If ktime is turned on in the middle of an IO, the max calculation could
be misleading. Base sampling on the start time of the IO as opposed to
ktime_on.

Make ISR ktime timestamps be from when CQE is read instead of EQE.
Added additional sanity checks when deciding whether to accept an IO
sample or not.

Signed-off-by: Dick Kennedy <dick.kennedy@broadcom.com>
Signed-off-by: James Smart <james.smart@broadcom.com>
Reviewed-by: Johannes Thumshirn <jthumshirn@suse.de>
Signed-off-by: Martin K. Petersen <martin.petersen@oracle.com>
---
 drivers/scsi/lpfc/lpfc_nvme.c  |   34 +++++++++-----
 drivers/scsi/lpfc/lpfc_nvmet.c |   99 +++++++++++++++++++++++++++--------------
 drivers/scsi/lpfc/lpfc_sli.c   |   34 ++++++++------
 3 files changed, 109 insertions(+), 58 deletions(-)

--- a/drivers/scsi/lpfc/lpfc_nvme.c
+++ b/drivers/scsi/lpfc/lpfc_nvme.c
@@ -667,15 +667,17 @@ lpfc_nvme_ktime(struct lpfc_hba *phba,
 		struct lpfc_nvme_buf *lpfc_ncmd)
 {
 	uint64_t seg1, seg2, seg3, seg4;
+	uint64_t segsum;
 
-	if (!phba->ktime_on)
-		return;
 	if (!lpfc_ncmd->ts_last_cmd ||
 	    !lpfc_ncmd->ts_cmd_start ||
 	    !lpfc_ncmd->ts_cmd_wqput ||
 	    !lpfc_ncmd->ts_isr_cmpl ||
 	    !lpfc_ncmd->ts_data_nvme)
 		return;
+
+	if (lpfc_ncmd->ts_data_nvme < lpfc_ncmd->ts_cmd_start)
+		return;
 	if (lpfc_ncmd->ts_cmd_start < lpfc_ncmd->ts_last_cmd)
 		return;
 	if (lpfc_ncmd->ts_cmd_wqput < lpfc_ncmd->ts_cmd_start)
@@ -695,15 +697,23 @@ lpfc_nvme_ktime(struct lpfc_hba *phba,
 	 * cmpl is handled off to the NVME Layer.
 	 */
 	seg1 = lpfc_ncmd->ts_cmd_start - lpfc_ncmd->ts_last_cmd;
-	if (seg1 > 5000000)  /* 5 ms - for sequential IOs */
-		return;
+	if (seg1 > 5000000)  /* 5 ms - for sequential IOs only */
+		seg1 = 0;
 
 	/* Calculate times relative to start of IO */
 	seg2 = (lpfc_ncmd->ts_cmd_wqput - lpfc_ncmd->ts_cmd_start);
-	seg3 = (lpfc_ncmd->ts_isr_cmpl -
-		lpfc_ncmd->ts_cmd_start) - seg2;
-	seg4 = (lpfc_ncmd->ts_data_nvme -
-		lpfc_ncmd->ts_cmd_start) - seg2 - seg3;
+	segsum = seg2;
+	seg3 = lpfc_ncmd->ts_isr_cmpl - lpfc_ncmd->ts_cmd_start;
+	if (segsum > seg3)
+		return;
+	seg3 -= segsum;
+	segsum += seg3;
+
+	seg4 = lpfc_ncmd->ts_data_nvme - lpfc_ncmd->ts_cmd_start;
+	if (segsum > seg4)
+		return;
+	seg4 -= segsum;
+
 	phba->ktime_data_samples++;
 	phba->ktime_seg1_total += seg1;
 	if (seg1 < phba->ktime_seg1_min)
@@ -902,7 +912,7 @@ out_err:
 	 * owns the dma address.
 	 */
 #ifdef CONFIG_SCSI_LPFC_DEBUG_FS
-	if (phba->ktime_on) {
+	if (lpfc_ncmd->ts_cmd_start) {
 		lpfc_ncmd->ts_isr_cmpl = pwqeIn->isr_timestamp;
 		lpfc_ncmd->ts_data_nvme = ktime_get_ns();
 		phba->ktime_last_cmd = lpfc_ncmd->ts_data_nvme;
@@ -1293,9 +1303,11 @@ lpfc_nvme_fcp_io_submit(struct nvme_fc_l
 		goto out_fail;
 	}
 #ifdef CONFIG_SCSI_LPFC_DEBUG_FS
-	if (phba->ktime_on) {
+	if (start) {
 		lpfc_ncmd->ts_cmd_start = start;
 		lpfc_ncmd->ts_last_cmd = phba->ktime_last_cmd;
+	} else {
+		lpfc_ncmd->ts_cmd_start = 0;
 	}
 #endif
 
@@ -1346,7 +1358,7 @@ lpfc_nvme_fcp_io_submit(struct nvme_fc_l
 	}
 
 #ifdef CONFIG_SCSI_LPFC_DEBUG_FS
-	if (phba->ktime_on)
+	if (lpfc_ncmd->ts_cmd_start)
 		lpfc_ncmd->ts_cmd_wqput = ktime_get_ns();
 
 	if (phba->cpucheck_on & LPFC_CHECK_NVME_IO) {
--- a/drivers/scsi/lpfc/lpfc_nvmet.c
+++ b/drivers/scsi/lpfc/lpfc_nvmet.c
@@ -221,9 +221,8 @@ lpfc_nvmet_ctxbuf_post(struct lpfc_hba *
 		spin_lock_init(&ctxp->ctxlock);
 
 #ifdef CONFIG_SCSI_LPFC_DEBUG_FS
-		if (phba->ktime_on) {
+		if (ctxp->ts_cmd_nvme) {
 			ctxp->ts_cmd_nvme = ktime_get_ns();
-			ctxp->ts_isr_cmd = ctxp->ts_cmd_nvme;
 			ctxp->ts_nvme_data = 0;
 			ctxp->ts_data_wqput = 0;
 			ctxp->ts_isr_data = 0;
@@ -289,9 +288,7 @@ lpfc_nvmet_ktime(struct lpfc_hba *phba,
 {
 	uint64_t seg1, seg2, seg3, seg4, seg5;
 	uint64_t seg6, seg7, seg8, seg9, seg10;
-
-	if (!phba->ktime_on)
-		return;
+	uint64_t segsum;
 
 	if (!ctxp->ts_isr_cmd || !ctxp->ts_cmd_nvme ||
 	    !ctxp->ts_nvme_data || !ctxp->ts_data_wqput ||
@@ -300,6 +297,8 @@ lpfc_nvmet_ktime(struct lpfc_hba *phba,
 	    !ctxp->ts_isr_status || !ctxp->ts_status_nvme)
 		return;
 
+	if (ctxp->ts_status_nvme < ctxp->ts_isr_cmd)
+		return;
 	if (ctxp->ts_isr_cmd  > ctxp->ts_cmd_nvme)
 		return;
 	if (ctxp->ts_cmd_nvme > ctxp->ts_nvme_data)
@@ -344,34 +343,66 @@ lpfc_nvmet_ktime(struct lpfc_hba *phba,
 	 * (Segments 1 thru 4) for READDATA_RSP
 	 */
 	seg1 = ctxp->ts_cmd_nvme - ctxp->ts_isr_cmd;
-	seg2 = (ctxp->ts_nvme_data - ctxp->ts_isr_cmd) - seg1;
-	seg3 = (ctxp->ts_data_wqput - ctxp->ts_isr_cmd) -
-		seg1 - seg2;
-	seg4 = (ctxp->ts_isr_data - ctxp->ts_isr_cmd) -
-		seg1 - seg2 - seg3;
-	seg5 = (ctxp->ts_data_nvme - ctxp->ts_isr_cmd) -
-		seg1 - seg2 - seg3 - seg4;
+	segsum = seg1;
+
+	seg2 = ctxp->ts_nvme_data - ctxp->ts_isr_cmd;
+	if (segsum > seg2)
+		return;
+	seg2 -= segsum;
+	segsum += seg2;
+
+	seg3 = ctxp->ts_data_wqput - ctxp->ts_isr_cmd;
+	if (segsum > seg3)
+		return;
+	seg3 -= segsum;
+	segsum += seg3;
+
+	seg4 = ctxp->ts_isr_data - ctxp->ts_isr_cmd;
+	if (segsum > seg4)
+		return;
+	seg4 -= segsum;
+	segsum += seg4;
+
+	seg5 = ctxp->ts_data_nvme - ctxp->ts_isr_cmd;
+	if (segsum > seg5)
+		return;
+	seg5 -= segsum;
+	segsum += seg5;
+
 
 	/* For auto rsp commands seg6 thru seg10 will be 0 */
 	if (ctxp->ts_nvme_status > ctxp->ts_data_nvme) {
-		seg6 = (ctxp->ts_nvme_status -
-			ctxp->ts_isr_cmd) -
-			seg1 - seg2 - seg3 - seg4 - seg5;
-		seg7 = (ctxp->ts_status_wqput -
-			ctxp->ts_isr_cmd) -
-			seg1 - seg2 - seg3 -
-			seg4 - seg5 - seg6;
-		seg8 = (ctxp->ts_isr_status -
-			ctxp->ts_isr_cmd) -
-			seg1 - seg2 - seg3 - seg4 -
-			seg5 - seg6 - seg7;
-		seg9 = (ctxp->ts_status_nvme -
-			ctxp->ts_isr_cmd) -
-			seg1 - seg2 - seg3 - seg4 -
-			seg5 - seg6 - seg7 - seg8;
+		seg6 = ctxp->ts_nvme_status - ctxp->ts_isr_cmd;
+		if (segsum > seg6)
+			return;
+		seg6 -= segsum;
+		segsum += seg6;
+
+		seg7 = ctxp->ts_status_wqput - ctxp->ts_isr_cmd;
+		if (segsum > seg7)
+			return;
+		seg7 -= segsum;
+		segsum += seg7;
+
+		seg8 = ctxp->ts_isr_status - ctxp->ts_isr_cmd;
+		if (segsum > seg8)
+			return;
+		seg8 -= segsum;
+		segsum += seg8;
+
+		seg9 = ctxp->ts_status_nvme - ctxp->ts_isr_cmd;
+		if (segsum > seg9)
+			return;
+		seg9 -= segsum;
+		segsum += seg9;
+
+		if (ctxp->ts_isr_status < ctxp->ts_isr_cmd)
+			return;
 		seg10 = (ctxp->ts_isr_status -
 			ctxp->ts_isr_cmd);
 	} else {
+		if (ctxp->ts_isr_data < ctxp->ts_isr_cmd)
+			return;
 		seg6 =  0;
 		seg7 =  0;
 		seg8 =  0;
@@ -523,7 +554,7 @@ lpfc_nvmet_xmt_fcp_op_cmp(struct lpfc_hb
 		ctxp->entry_cnt++;
 
 #ifdef CONFIG_SCSI_LPFC_DEBUG_FS
-		if (phba->ktime_on) {
+		if (ctxp->ts_cmd_nvme) {
 			if (rsp->op == NVMET_FCOP_READDATA_RSP) {
 				ctxp->ts_isr_data =
 					cmdwqe->isr_timestamp;
@@ -557,7 +588,7 @@ lpfc_nvmet_xmt_fcp_op_cmp(struct lpfc_hb
 #endif
 		rsp->done(rsp);
 #ifdef CONFIG_SCSI_LPFC_DEBUG_FS
-		if (phba->ktime_on)
+		if (ctxp->ts_cmd_nvme)
 			lpfc_nvmet_ktime(phba, ctxp);
 #endif
 		/* lpfc_nvmet_xmt_fcp_release() will recycle the context */
@@ -567,7 +598,7 @@ lpfc_nvmet_xmt_fcp_op_cmp(struct lpfc_hb
 		memset(((char *)cmdwqe) + start_clean, 0,
 		       (sizeof(struct lpfc_iocbq) - start_clean));
 #ifdef CONFIG_SCSI_LPFC_DEBUG_FS
-		if (phba->ktime_on) {
+		if (ctxp->ts_cmd_nvme) {
 			ctxp->ts_isr_data = cmdwqe->isr_timestamp;
 			ctxp->ts_data_nvme = ktime_get_ns();
 		}
@@ -683,7 +714,7 @@ lpfc_nvmet_xmt_fcp_op(struct nvmet_fc_ta
 	int rc;
 
 #ifdef CONFIG_SCSI_LPFC_DEBUG_FS
-	if (phba->ktime_on) {
+	if (ctxp->ts_cmd_nvme) {
 		if (rsp->op == NVMET_FCOP_RSP)
 			ctxp->ts_nvme_status = ktime_get_ns();
 		else
@@ -738,7 +769,7 @@ lpfc_nvmet_xmt_fcp_op(struct nvmet_fc_ta
 	rc = lpfc_sli4_issue_wqe(phba, LPFC_FCP_RING, nvmewqeq);
 	if (rc == WQE_SUCCESS) {
 #ifdef CONFIG_SCSI_LPFC_DEBUG_FS
-		if (!phba->ktime_on)
+		if (!ctxp->ts_cmd_nvme)
 			return 0;
 		if (rsp->op == NVMET_FCOP_RSP)
 			ctxp->ts_status_wqput = ktime_get_ns();
@@ -1633,7 +1664,7 @@ lpfc_nvmet_unsol_fcp_buffer(struct lpfc_
 	spin_lock_init(&ctxp->ctxlock);
 
 #ifdef CONFIG_SCSI_LPFC_DEBUG_FS
-	if (phba->ktime_on) {
+	if (isr_timestamp) {
 		ctxp->ts_isr_cmd = isr_timestamp;
 		ctxp->ts_cmd_nvme = ktime_get_ns();
 		ctxp->ts_nvme_data = 0;
@@ -1644,6 +1675,8 @@ lpfc_nvmet_unsol_fcp_buffer(struct lpfc_
 		ctxp->ts_status_wqput = 0;
 		ctxp->ts_isr_status = 0;
 		ctxp->ts_status_nvme = 0;
+	} else {
+		ctxp->ts_cmd_nvme = 0;
 	}
 #endif
 
--- a/drivers/scsi/lpfc/lpfc_sli.c
+++ b/drivers/scsi/lpfc/lpfc_sli.c
@@ -13078,13 +13078,20 @@ lpfc_sli4_sp_process_cq(struct work_stru
 		break;
 	case LPFC_WCQ:
 		while ((cqe = lpfc_sli4_cq_get(cq))) {
-			if ((cq->subtype == LPFC_FCP) ||
-			    (cq->subtype == LPFC_NVME))
+			if (cq->subtype == LPFC_FCP ||
+			    cq->subtype == LPFC_NVME) {
+#ifdef CONFIG_SCSI_LPFC_DEBUG_FS
+				if (phba->ktime_on)
+					cq->isr_timestamp = ktime_get_ns();
+				else
+					cq->isr_timestamp = 0;
+#endif
 				workposted |= lpfc_sli4_fp_handle_cqe(phba, cq,
 								       cqe);
-			else
+			} else {
 				workposted |= lpfc_sli4_sp_handle_cqe(phba, cq,
 								      cqe);
+			}
 			if (!(++ccount % cq->entry_repost))
 				break;
 		}
@@ -13167,11 +13174,9 @@ lpfc_sli4_fp_handle_fcp_wcqe(struct lpfc
 				bf_get(lpfc_wcqe_c_request_tag, wcqe));
 		return;
 	}
-
-	if (cq->assoc_qp)
-		cmdiocbq->isr_timestamp =
-			cq->assoc_qp->isr_timestamp;
-
+#ifdef CONFIG_SCSI_LPFC_DEBUG_FS
+	cmdiocbq->isr_timestamp = cq->isr_timestamp;
+#endif
 	if (cmdiocbq->iocb_cmpl == NULL) {
 		if (cmdiocbq->wqe_cmpl) {
 			if (cmdiocbq->iocb_flag & LPFC_DRIVER_ABORTED) {
@@ -13316,7 +13321,7 @@ lpfc_sli4_nvmet_handle_rcqe(struct lpfc_
 			dma_buf->bytes_recv = bf_get(lpfc_rcqe_length,  rcqe);
 			lpfc_nvmet_unsol_fcp_event(
 				phba, idx, dma_buf,
-				cq->assoc_qp->isr_timestamp);
+				cq->isr_timestamp);
 			return false;
 		}
 drop:
@@ -13516,6 +13521,12 @@ lpfc_sli4_hba_process_cq(struct work_str
 
 	/* Process all the entries to the CQ */
 	while ((cqe = lpfc_sli4_cq_get(cq))) {
+#ifdef CONFIG_SCSI_LPFC_DEBUG_FS
+		if (phba->ktime_on)
+			cq->isr_timestamp = ktime_get_ns();
+		else
+			cq->isr_timestamp = 0;
+#endif
 		workposted |= lpfc_sli4_fp_handle_cqe(phba, cq, cqe);
 		if (!(++ccount % cq->entry_repost))
 			break;
@@ -13754,11 +13765,6 @@ lpfc_sli4_hba_intr_handler(int irq, void
 	if (unlikely(!fpeq))
 		return IRQ_NONE;
 
-#ifdef CONFIG_SCSI_LPFC_DEBUG_FS
-	if (phba->ktime_on)
-		fpeq->isr_timestamp = ktime_get_ns();
-#endif
-
 	if (lpfc_fcp_look_ahead) {
 		if (atomic_dec_and_test(&hba_eq_hdl->hba_eq_in_use))
 			lpfc_sli4_eq_clr_intr(fpeq);