From patchwork Tue Dec 13 19:51:56 2016 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: subhashj@codeaurora.org X-Patchwork-Id: 9473051 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 4027B60823 for ; Tue, 13 Dec 2016 19:52:25 +0000 (UTC) Received: from mail.wl.linuxfoundation.org (localhost [127.0.0.1]) by mail.wl.linuxfoundation.org (Postfix) with ESMTP id 3AA432864C for ; Tue, 13 Dec 2016 19:52:25 +0000 (UTC) Received: by mail.wl.linuxfoundation.org (Postfix, from userid 486) id 2DB072868A; Tue, 13 Dec 2016 19:52:25 +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=unavailable 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 8687B28688 for ; Tue, 13 Dec 2016 19:52:24 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S935088AbcLMTwP (ORCPT ); Tue, 13 Dec 2016 14:52:15 -0500 Received: from smtp.codeaurora.org ([198.145.29.96]:33264 "EHLO smtp.codeaurora.org" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S932843AbcLMTwL (ORCPT ); Tue, 13 Dec 2016 14:52:11 -0500 Received: by smtp.codeaurora.org (Postfix, from userid 1000) id 2C5866159A; Tue, 13 Dec 2016 19:52:09 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=codeaurora.org; s=default; t=1481658729; bh=6FS96CZw10yucPa5SdPxDXQeOam6OBA0v+pLMdNkPxg=; h=From:To:Cc:Subject:Date:From; b=E+FZV+etOeLLeDfWzsYcH4WwDzzhswQmofyFiFonQWVEeCL5zomeNKGd+g/Qrtb9c jxFmUa8mWDOIdXnGcpvKVHDK5B4lxtWJygFc8/LAYLjABz/+9wmaqFyuuoWc0UZv5P 3hK40T5uJtCO2mvirtUVqaSg5g4ngHMcRxXbkbvU= Received: from pacamara-linux.qualcomm.com (i-global254.qualcomm.com [199.106.103.254]) (using TLSv1.2 with cipher ECDHE-RSA-AES128-SHA256 (128/128 bits)) (No client certificate requested) (Authenticated sender: subhashj@smtp.codeaurora.org) by smtp.codeaurora.org (Postfix) with ESMTPSA id C369F6145F; Tue, 13 Dec 2016 19:52:07 +0000 (UTC) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/simple; d=codeaurora.org; s=default; t=1481658728; bh=6FS96CZw10yucPa5SdPxDXQeOam6OBA0v+pLMdNkPxg=; h=From:To:Cc:Subject:Date:From; b=RZn0Z4dm3FEACtaddStstL6Ys1jB0n/gMraTx/oot1jw5xm81zCwhCClTAZCrugtt xr4A5Z4ShBeEjbvRdFUhKDLFwQ3tW4ZEW5dLw1tscb6SQjNUwnY4wk+Tw+BGkw9pf3 zdVk42LsL3KOvr8vStSbH7P0zWLitWI9I2UYBc58= DMARC-Filter: OpenDMARC Filter v1.3.1 smtp.codeaurora.org C369F6145F Authentication-Results: pdx-caf-mail.web.codeaurora.org; dmarc=none header.from=codeaurora.org Authentication-Results: pdx-caf-mail.web.codeaurora.org; spf=pass smtp.mailfrom=subhashj@codeaurora.org From: Subhash Jadavani To: vinholikatti@gmail.com, jejb@linux.vnet.ibm.com, martin.petersen@oracle.com Cc: linux-scsi@vger.kernel.org, Subhash Jadavani , Steven Rostedt , Ingo Molnar , Lee Susman , Venkat Gopalakrishnan , Sahitya Tummala , linux-kernel@vger.kernel.org (open list) Subject: [PATCH v2 10/12] scsi: ufs: add time profiling support Date: Tue, 13 Dec 2016 11:51:56 -0800 Message-Id: <1481658720-32252-1-git-send-email-subhashj@codeaurora.org> 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 This patch adds the profiling support for some of the time critical operations like hibern8 enter/exit, clock gating & clock scaling. Reviewed-by: Venkat Gopalakrishnan Signed-off-by: Subhash Jadavani --- drivers/scsi/ufs/ufshcd.c | 24 ++++++++++++++++++++++++ include/trace/events/ufs.h | 40 ++++++++++++++++++++++++++++++++++++++++ 2 files changed, 64 insertions(+) diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c index 70742f9..33f3947 100644 --- a/drivers/scsi/ufs/ufshcd.c +++ b/drivers/scsi/ufs/ufshcd.c @@ -3048,11 +3048,14 @@ static int __ufshcd_uic_hibern8_enter(struct ufs_hba *hba) { int ret; struct uic_command uic_cmd = {0}; + ktime_t start = ktime_get(); ufshcd_vops_hibern8_notify(hba, UIC_CMD_DME_HIBER_ENTER, PRE_CHANGE); uic_cmd.command = UIC_CMD_DME_HIBER_ENTER; ret = ufshcd_uic_pwr_ctrl(hba, &uic_cmd); + trace_ufshcd_profile_hibern8(dev_name(hba->dev), "enter", + ktime_to_us(ktime_sub(ktime_get(), start)), ret); if (ret) { dev_err(hba->dev, "%s: hibern8 enter failed. ret = %d\n", @@ -3088,11 +3091,15 @@ static int ufshcd_uic_hibern8_exit(struct ufs_hba *hba) { struct uic_command uic_cmd = {0}; int ret; + ktime_t start = ktime_get(); ufshcd_vops_hibern8_notify(hba, UIC_CMD_DME_HIBER_EXIT, PRE_CHANGE); uic_cmd.command = UIC_CMD_DME_HIBER_EXIT; ret = ufshcd_uic_pwr_ctrl(hba, &uic_cmd); + trace_ufshcd_profile_hibern8(dev_name(hba->dev), "exit", + ktime_to_us(ktime_sub(ktime_get(), start)), ret); + if (ret) { dev_err(hba->dev, "%s: hibern8 exit failed. ret = %d\n", __func__, ret); @@ -5978,6 +5985,8 @@ static int __ufshcd_setup_clocks(struct ufs_hba *hba, bool on, struct ufs_clk_info *clki; struct list_head *head = &hba->clk_list_head; unsigned long flags; + ktime_t start = ktime_get(); + bool clk_state_changed = false; if (!head || list_empty(head)) goto out; @@ -5991,6 +6000,7 @@ static int __ufshcd_setup_clocks(struct ufs_hba *hba, bool on, if (skip_ref_clk && !strcmp(clki->name, "ref_clk")) continue; + clk_state_changed = on ^ clki->enabled; if (on && !clki->enabled) { ret = clk_prepare_enable(clki->clk); if (ret) { @@ -6026,6 +6036,10 @@ static int __ufshcd_setup_clocks(struct ufs_hba *hba, bool on, spin_unlock_irqrestore(hba->host->host_lock, flags); } + if (clk_state_changed) + trace_ufshcd_profile_clk_gating(dev_name(hba->dev), + (on ? "on" : "off"), + ktime_to_us(ktime_sub(ktime_get(), start)), ret); return ret; } @@ -7030,6 +7044,8 @@ static int ufshcd_scale_clks(struct ufs_hba *hba, bool scale_up) int ret = 0; struct ufs_clk_info *clki; struct list_head *head = &hba->clk_list_head; + ktime_t start = ktime_get(); + bool clk_state_changed = false; if (!head || list_empty(head)) goto out; @@ -7043,6 +7059,8 @@ static int ufshcd_scale_clks(struct ufs_hba *hba, bool scale_up) if (scale_up && clki->max_freq) { if (clki->curr_freq == clki->max_freq) continue; + + clk_state_changed = true; ret = clk_set_rate(clki->clk, clki->max_freq); if (ret) { dev_err(hba->dev, "%s: %s clk set rate(%dHz) failed, %d\n", @@ -7060,6 +7078,8 @@ static int ufshcd_scale_clks(struct ufs_hba *hba, bool scale_up) } else if (!scale_up && clki->min_freq) { if (clki->curr_freq == clki->min_freq) continue; + + clk_state_changed = true; ret = clk_set_rate(clki->clk, clki->min_freq); if (ret) { dev_err(hba->dev, "%s: %s clk set rate(%dHz) failed, %d\n", @@ -7081,6 +7101,10 @@ static int ufshcd_scale_clks(struct ufs_hba *hba, bool scale_up) ret = ufshcd_vops_clk_scale_notify(hba, scale_up, POST_CHANGE); out: + if (clk_state_changed) + trace_ufshcd_profile_clk_scaling(dev_name(hba->dev), + (scale_up ? "up" : "down"), + ktime_to_us(ktime_sub(ktime_get(), start)), ret); return ret; } diff --git a/include/trace/events/ufs.h b/include/trace/events/ufs.h index 7b3d9e1..8bce504 100644 --- a/include/trace/events/ufs.h +++ b/include/trace/events/ufs.h @@ -87,6 +87,46 @@ __get_str(dev_name), __get_str(state)) ); +DECLARE_EVENT_CLASS(ufshcd_profiling_template, + TP_PROTO(const char *dev_name, const char *profile_info, s64 time_us, + int err), + + TP_ARGS(dev_name, profile_info, time_us, err), + + TP_STRUCT__entry( + __string(dev_name, dev_name) + __string(profile_info, profile_info) + __field(s64, time_us) + __field(int, err) + ), + + TP_fast_assign( + __assign_str(dev_name, dev_name); + __assign_str(profile_info, profile_info); + __entry->time_us = time_us; + __entry->err = err; + ), + + TP_printk("%s: %s: took %lld usecs, err %d", + __get_str(dev_name), __get_str(profile_info), + __entry->time_us, __entry->err) +); + +DEFINE_EVENT(ufshcd_profiling_template, ufshcd_profile_hibern8, + TP_PROTO(const char *dev_name, const char *profile_info, s64 time_us, + int err), + TP_ARGS(dev_name, profile_info, time_us, err)); + +DEFINE_EVENT(ufshcd_profiling_template, ufshcd_profile_clk_gating, + TP_PROTO(const char *dev_name, const char *profile_info, s64 time_us, + int err), + TP_ARGS(dev_name, profile_info, time_us, err)); + +DEFINE_EVENT(ufshcd_profiling_template, ufshcd_profile_clk_scaling, + TP_PROTO(const char *dev_name, const char *profile_info, s64 time_us, + int err), + TP_ARGS(dev_name, profile_info, time_us, err)); + DECLARE_EVENT_CLASS(ufshcd_template, TP_PROTO(const char *dev_name, int err, s64 usecs, const char *dev_state, const char *link_state),