From patchwork Fri Sep 22 06:17:28 2017 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: James Smart X-Patchwork-Id: 9965233 Return-Path: Received: from mail.wl.linuxfoundation.org (pdx-wl-mail.web.codeaurora.org [172.30.200.125]) by pdx-korg-patchwork.web.codeaurora.org (Postfix) with ESMTP id 51B1F602D8 for ; Fri, 22 Sep 2017 06:18:18 +0000 (UTC) Received: from mail.wl.linuxfoundation.org (localhost [127.0.0.1]) by mail.wl.linuxfoundation.org (Postfix) with ESMTP id 42C4329707 for ; Fri, 22 Sep 2017 06:18:18 +0000 (UTC) Received: by mail.wl.linuxfoundation.org (Postfix, from userid 486) id 379CA2970B; Fri, 22 Sep 2017 06:18:18 +0000 (UTC) X-Spam-Checker-Version: SpamAssassin 3.3.1 (2010-03-16) on pdx-wl-mail.web.codeaurora.org X-Spam-Level: X-Spam-Status: No, score=-6.5 required=2.0 tests=BAYES_00,DKIM_SIGNED, DKIM_VALID, DKIM_VALID_AU, FREEMAIL_FROM, RCVD_IN_DNSWL_HI, RCVD_IN_SORBS_SPAM autolearn=ham version=3.3.1 Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by mail.wl.linuxfoundation.org (Postfix) with ESMTP id 73A5329707 for ; Fri, 22 Sep 2017 06:18:17 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1751810AbdIVGSQ (ORCPT ); Fri, 22 Sep 2017 02:18:16 -0400 Received: from mail-pg0-f66.google.com ([74.125.83.66]:37913 "EHLO mail-pg0-f66.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751845AbdIVGSC (ORCPT ); Fri, 22 Sep 2017 02:18:02 -0400 Received: by mail-pg0-f66.google.com with SMTP id m30so115575pgn.5 for ; Thu, 21 Sep 2017 23:18:01 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=gmail.com; s=20161025; h=from:to:cc:subject:date:message-id:in-reply-to:references; bh=KMgY6cfZzJCH2mmME0FNMnho0JQrtyawaf37I2IGpeY=; b=rsrhgw8ojnQ+SJpy+T/jHl5xLe31797ty0iTNpyV1HokFjV0Pqi2PFDu3kbP5nMt1n qG+w08qcHOORSfOOwvcb0xghHvRGOHv12H9w/Ax6TLywUU3/mYwITFk6+Xqhz97jaK7Z YUSR9IzYOsE/M1AhsmfM3mcBDJx3XZW5pUqEx5M10BrcH4+x67vRsmO1sG6nmAYNLww1 k1dEF6KRTOMAW7cuB4LHAUhnDZojBtAtIdQW99dGIz6G8pVnkBAhdg38sOZSnnIbCIeN BUmeyvCjX7FkCQIYItFzeYfkawozr8nBasNDO9jq+ShtkgqD6M+HvrpG6iR29s3OkL1/ cvNQ== X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20161025; h=x-gm-message-state:from:to:cc:subject:date:message-id:in-reply-to :references; bh=KMgY6cfZzJCH2mmME0FNMnho0JQrtyawaf37I2IGpeY=; b=bM8m2wh5jAXiTkIDlkv/si4XDLNK5bG4G1P1AGyo/diDEP8cnsfZLl268AIhk289y+ R8FafWIT0gCser+BByvBZ/DRjmEZCiGU/LlQ6WwfIkb2KKFSQNzIeq4rgWz4ZRPQDCKD C04SRYUbMD99MVjzfqHl3iMbN/1dRS6XZrPMvDEnFNcb57XKQ+GSd2fPi6ZnVcgjyKgF AKP/97XBz6mbfqTJaeMhTxbNOWOhocN0VsMjgwvHZsCjCPlS+PVnRmYM6cZjTf5Y08qd RHwA97d80kr3ajdk+V2R9x4g/hVfrG2oJ8DVELwoOZK09NZDDBwKr/WGsGO2aW0xte8b 5BZQ== X-Gm-Message-State: AHPjjUhVNLvpheznB18gspSQ27gTSdzk+RKFGQzcvrjmwirWrG/jhCDd YqS+va9GXMm8qDKOIcSee7r1Lg== X-Google-Smtp-Source: AOwi7QC0lN8aa7DeMIow8l4MX5I+5FGe7ZZUufPY85uDTLUbKnbUFdjIg4vMUokw+r/HYMYRbmq/fQ== X-Received: by 10.98.74.156 with SMTP id c28mr8084123pfj.266.1506061081247; Thu, 21 Sep 2017 23:18:01 -0700 (PDT) Received: from os42.localdomain (ip68-4-115-207.oc.oc.cox.net. [68.4.115.207]) by smtp.gmail.com with ESMTPSA id e87sm5911355pfl.46.2017.09.21.23.18.00 (version=TLS1_2 cipher=ECDHE-RSA-AES128-SHA bits=128/128); Thu, 21 Sep 2017 23:18:00 -0700 (PDT) From: James Smart To: linux-scsi@vger.kernel.org Cc: Dick Kennedy , James Smart Subject: [PATCH 06/19] lpfc: Make ktime sampling more accurate Date: Thu, 21 Sep 2017 23:17:28 -0700 Message-Id: <20170922061741.12347-7-jsmart2021@gmail.com> X-Mailer: git-send-email 2.13.1 In-Reply-To: <20170922061741.12347-1-jsmart2021@gmail.com> References: <20170922061741.12347-1-jsmart2021@gmail.com> Sender: linux-scsi-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-scsi@vger.kernel.org X-Virus-Scanned: ClamAV using ClamSMTP From: Dick Kennedy 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 Signed-off-by: James Smart --- 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(-) diff --git a/drivers/scsi/lpfc/lpfc_nvme.c b/drivers/scsi/lpfc/lpfc_nvme.c index 2ad23b356bfe..a83b57254de6 100644 --- 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 @@ lpfc_nvme_io_cmd_wqe_cmpl(struct lpfc_hba *phba, struct lpfc_iocbq *pwqeIn, * 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; @@ -1283,9 +1293,11 @@ lpfc_nvme_fcp_io_submit(struct nvme_fc_local_port *pnvme_lport, 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 @@ -1336,7 +1348,7 @@ lpfc_nvme_fcp_io_submit(struct nvme_fc_local_port *pnvme_lport, } #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) { diff --git a/drivers/scsi/lpfc/lpfc_nvmet.c b/drivers/scsi/lpfc/lpfc_nvmet.c index 313d5c10e0ad..46b411894964 100644 --- 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 *phba, struct lpfc_nvmet_ctxbuf *ctx_buf) 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; @@ -519,7 +550,7 @@ lpfc_nvmet_xmt_fcp_op_cmp(struct lpfc_hba *phba, struct lpfc_iocbq *cmdwqe, 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; @@ -553,7 +584,7 @@ lpfc_nvmet_xmt_fcp_op_cmp(struct lpfc_hba *phba, struct lpfc_iocbq *cmdwqe, #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 */ @@ -563,7 +594,7 @@ lpfc_nvmet_xmt_fcp_op_cmp(struct lpfc_hba *phba, struct lpfc_iocbq *cmdwqe, 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(); } @@ -679,7 +710,7 @@ lpfc_nvmet_xmt_fcp_op(struct nvmet_fc_target_port *tgtport, 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 @@ -734,7 +765,7 @@ lpfc_nvmet_xmt_fcp_op(struct nvmet_fc_target_port *tgtport, 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_hba *phba, 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_hba *phba, ctxp->ts_status_wqput = 0; ctxp->ts_isr_status = 0; ctxp->ts_status_nvme = 0; + } else { + ctxp->ts_cmd_nvme = 0; } #endif diff --git a/drivers/scsi/lpfc/lpfc_sli.c b/drivers/scsi/lpfc/lpfc_sli.c index 9024521b97c7..3ace438d8f2e 100644 --- a/drivers/scsi/lpfc/lpfc_sli.c +++ b/drivers/scsi/lpfc/lpfc_sli.c @@ -13064,13 +13064,20 @@ lpfc_sli4_sp_handle_eqe(struct lpfc_hba *phba, struct lpfc_eqe *eqe, 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 (!(++ecount % cq->entry_repost)) break; } @@ -13155,11 +13162,9 @@ lpfc_sli4_fp_handle_fcp_wcqe(struct lpfc_hba *phba, struct lpfc_queue *cq, 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) { @@ -13304,7 +13309,7 @@ lpfc_sli4_nvmet_handle_rcqe(struct lpfc_hba *phba, struct lpfc_queue *cq, 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: @@ -13479,6 +13484,12 @@ lpfc_sli4_hba_handle_eqe(struct lpfc_hba *phba, struct lpfc_eqe *eqe, /* 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 (!(++ecount % cq->entry_repost)) break; @@ -13741,11 +13752,6 @@ lpfc_sli4_hba_intr_handler(int irq, void *dev_id) 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);