From patchwork Sun Mar 25 07:08:04 2018 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: Ohad Sharabi X-Patchwork-Id: 10306491 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 E1FE960325 for ; Sun, 25 Mar 2018 07:08:53 +0000 (UTC) Received: from mail.wl.linuxfoundation.org (localhost [127.0.0.1]) by mail.wl.linuxfoundation.org (Postfix) with ESMTP id C826929378 for ; Sun, 25 Mar 2018 07:08:53 +0000 (UTC) Received: by mail.wl.linuxfoundation.org (Postfix, from userid 486) id A608529384; Sun, 25 Mar 2018 07:08:53 +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.8 required=2.0 tests=BAYES_00,DKIM_SIGNED, RCVD_IN_DNSWL_HI,T_DKIM_INVALID 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 A5DFA29378 for ; Sun, 25 Mar 2018 07:08:52 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1753072AbeCYHIW (ORCPT ); Sun, 25 Mar 2018 03:08:22 -0400 Received: from esa4.hgst.iphmx.com ([216.71.154.42]:4597 "EHLO esa4.hgst.iphmx.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1751029AbeCYHIV (ORCPT ); Sun, 25 Mar 2018 03:08:21 -0400 DKIM-Signature: v=1; a=rsa-sha256; c=simple/simple; d=sandisk.com; i=@sandisk.com; q=dns/txt; s=dkim.sandisk.com; t=1521961701; x=1553497701; h=from:to:cc:subject:date:message-id; bh=f02rXH9aajzlopmNceV7oP0EKNc/7G1EwQZXOirCSDE=; b=zvPVkbdWmGDkBooKFlxhwz8MdWISQyCqP4SQxsyrEMEnzOiLwc0aF+8f yAvNq2McMKoiLEDKgrDeh1III1HLHC7ixKDIrP0PnKHeYGRlH3WU0/fsX qMx4+LM4FyS2dU4nsi9yx1fGqYaeQDy2bjWFBuH5M//uwk1MZx7wmqkjF nOq/1GGtU10m3bHkfTTOUTRfw+B1jb9Kz4kFOLwNPoprgwKhu9vw61Pjy abUpkKvkmlORoCPpMEbxmyJx/CYX1pNuNhQD7lpVtJvec4SIpHgTg4SUc VS+Xkmmhn7AD7B46wHZVKvwhn0uU1beWyw+pI8sDnK2w1vpq4mlcJPCP7 A==; X-IronPort-AV: E=Sophos;i="5.48,358,1517846400"; d="scan'208";a="74285093" Received: from h199-255-45-15.hgst.com (HELO uls-op-cesaep02.wdc.com) ([199.255.45.15]) by ob1.hgst.iphmx.com with ESMTP; 25 Mar 2018 15:08:20 +0800 Received: from uls-op-cesaip01.wdc.com ([10.248.3.36]) by uls-op-cesaep02.wdc.com with ESMTP; 25 Mar 2018 00:01:00 -0700 Received: from ile419070.sdcorp.global.sandisk.com ([10.0.230.165]) by uls-op-cesaip01.wdc.com with ESMTP; 25 Mar 2018 00:08:14 -0700 From: Ohad Sharabi To: stanislav.nijnikov@wdc.com, jejb@linux.vnet.ibm.com, martin.petersen@oracle.com, gregkh@linuxfoundation.org Cc: linux-scsi@vger.kernel.org, linux-kernel@vger.kernel.org, alex.lemberg@wdc.com, Ohad Sharabi Subject: [PATCH v3] scsi: ufs: add trace event for ufs upiu Date: Sun, 25 Mar 2018 10:08:04 +0300 Message-Id: <1521961684-13588-1-git-send-email-ohad.sharabi@sandisk.com> X-Mailer: git-send-email 1.9.1 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 Add UFS Protocol Information Units(upiu) trace events for ufs driver, used to trace various ufs transaction types- command, task-management and device management. The trace-point format is generic and can be easily adapted to trace other upius if needed. Currently tracing ufs transaction of type 'device management', which this patch introduce, cannot be obtained from any other trace. Device management transactions are used for communication with the device such as reading and writing descriptor or attributes etc. v2->v3: - modify args 3,4 of trace_ufshcd_upiu to be void * v1->v2: - split to transaction specific functions (fix warnings and simplifies code) - adding traces when sending query command Signed-off-by: Ohad Sharabi Reviewed-by: Stanislav Nijnikov Reviewed-by: Bart Van Assche --- drivers/scsi/ufs/ufshcd.c | 40 ++++++++++++++++++++++++++++++++++++++++ include/trace/events/ufs.h | 27 +++++++++++++++++++++++++++ 2 files changed, 67 insertions(+) diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c index c7da2c1..23ffaed 100644 --- a/drivers/scsi/ufs/ufshcd.c +++ b/drivers/scsi/ufs/ufshcd.c @@ -274,6 +274,35 @@ static inline void ufshcd_remove_non_printable(char *val) *val = ' '; } +static void ufshcd_add_cmd_upiu_trace(struct ufs_hba *hba, unsigned int tag, + const char *str) +{ + struct utp_upiu_req *rq = hba->lrb[tag].ucd_req_ptr; + + trace_ufshcd_upiu(dev_name(hba->dev), str, &rq->header, &rq->sc.cdb); +} + +static void ufshcd_add_query_upiu_trace(struct ufs_hba *hba, unsigned int tag, + const char *str) +{ + struct utp_upiu_req *rq = hba->lrb[tag].ucd_req_ptr; + + trace_ufshcd_upiu(dev_name(hba->dev), str, &rq->header, &rq->qr); +} + +static void ufshcd_add_tm_upiu_trace(struct ufs_hba *hba, unsigned int tag, + const char *str) +{ + struct utp_task_req_desc *descp; + struct utp_upiu_task_req *task_req; + int off = (int)tag - hba->nutrs; + + descp = &hba->utmrdl_base_addr[off]; + task_req = (struct utp_upiu_task_req *)descp->task_req_upiu; + trace_ufshcd_upiu(dev_name(hba->dev), str, &task_req->header, + &task_req->input_param1); +} + static void ufshcd_add_command_trace(struct ufs_hba *hba, unsigned int tag, const char *str) { @@ -283,6 +312,9 @@ static void ufshcd_add_command_trace(struct ufs_hba *hba, struct ufshcd_lrb *lrbp; int transfer_len = -1; + /* trace UPIU also */ + ufshcd_add_cmd_upiu_trace(hba, tag, str); + if (!trace_ufshcd_command_enabled()) return; @@ -2584,6 +2616,7 @@ static int ufshcd_exec_dev_cmd(struct ufs_hba *hba, hba->dev_cmd.complete = &wait; + ufshcd_add_query_upiu_trace(hba, tag, "query_send"); /* Make sure descriptors are ready before ringing the doorbell */ wmb(); spin_lock_irqsave(hba->host->host_lock, flags); @@ -2593,6 +2626,9 @@ static int ufshcd_exec_dev_cmd(struct ufs_hba *hba, err = ufshcd_wait_for_dev_cmd(hba, lrbp, timeout); + ufshcd_add_query_upiu_trace(hba, tag, + err ? "query_complete_err" : "query_complete"); + out_put_tag: ufshcd_put_dev_cmd_tag(hba, tag); wake_up(&hba->dev_cmd.tag_wq); @@ -5464,11 +5500,14 @@ static int ufshcd_issue_tm_cmd(struct ufs_hba *hba, int lun_id, int task_id, spin_unlock_irqrestore(host->host_lock, flags); + ufshcd_add_tm_upiu_trace(hba, task_tag, "tm_send"); + /* wait until the task management command is completed */ err = wait_event_timeout(hba->tm_wq, test_bit(free_slot, &hba->tm_condition), msecs_to_jiffies(TM_CMD_TIMEOUT)); if (!err) { + ufshcd_add_tm_upiu_trace(hba, task_tag, "tm_complete_err"); dev_err(hba->dev, "%s: task management cmd 0x%.2x timed-out\n", __func__, tm_function); if (ufshcd_clear_tm_cmd(hba, free_slot)) @@ -5477,6 +5516,7 @@ static int ufshcd_issue_tm_cmd(struct ufs_hba *hba, int lun_id, int task_id, err = -ETIMEDOUT; } else { err = ufshcd_task_req_compl(hba, free_slot, tm_response); + ufshcd_add_tm_upiu_trace(hba, task_tag, "tm_complete"); } clear_bit(free_slot, &hba->tm_condition); diff --git a/include/trace/events/ufs.h b/include/trace/events/ufs.h index bf6f826..f8260e5 100644 --- a/include/trace/events/ufs.h +++ b/include/trace/events/ufs.h @@ -257,6 +257,33 @@ ) ); +TRACE_EVENT(ufshcd_upiu, + TP_PROTO(const char *dev_name, const char *str, void *hdr, void *tsf), + + TP_ARGS(dev_name, str, hdr, tsf), + + TP_STRUCT__entry( + __string(dev_name, dev_name) + __string(str, str) + __array(unsigned char, hdr, 12) + __array(unsigned char, tsf, 16) + ), + + TP_fast_assign( + __assign_str(dev_name, dev_name); + __assign_str(str, str); + memcpy(__entry->hdr, hdr, sizeof(__entry->hdr)); + memcpy(__entry->tsf, tsf, sizeof(__entry->tsf)); + ), + + TP_printk( + "%s: %s: HDR:%s, CDB:%s", + __get_str(str), __get_str(dev_name), + __print_hex(__entry->hdr, sizeof(__entry->hdr)), + __print_hex(__entry->tsf, sizeof(__entry->tsf)) + ) +); + #endif /* if !defined(_TRACE_UFS_H) || defined(TRACE_HEADER_MULTI_READ) */ /* This part must be outside protection */