From patchwork Thu Mar 24 11:54:08 2016 Content-Type: text/plain; charset="utf-8" MIME-Version: 1.0 Content-Transfer-Encoding: 7bit X-Patchwork-Submitter: "(Exiting) Baolin Wang" X-Patchwork-Id: 8660131 Return-Path: X-Original-To: patchwork-linux-mmc@patchwork.kernel.org Delivered-To: patchwork-parsemail@patchwork2.web.kernel.org Received: from mail.kernel.org (mail.kernel.org [198.145.29.136]) by patchwork2.web.kernel.org (Postfix) with ESMTP id 83BA6C0553 for ; Thu, 24 Mar 2016 11:55:07 +0000 (UTC) Received: from mail.kernel.org (localhost [127.0.0.1]) by mail.kernel.org (Postfix) with ESMTP id 9C3EC2037C for ; Thu, 24 Mar 2016 11:55:02 +0000 (UTC) Received: from vger.kernel.org (vger.kernel.org [209.132.180.67]) by mail.kernel.org (Postfix) with ESMTP id 29866203B4 for ; Thu, 24 Mar 2016 11:55:00 +0000 (UTC) Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1751340AbcCXLy5 (ORCPT ); Thu, 24 Mar 2016 07:54:57 -0400 Received: from mail-pa0-f45.google.com ([209.85.220.45]:33258 "EHLO mail-pa0-f45.google.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1750926AbcCXLy4 (ORCPT ); Thu, 24 Mar 2016 07:54:56 -0400 Received: by mail-pa0-f45.google.com with SMTP id fl4so19893784pad.0 for ; Thu, 24 Mar 2016 04:54:55 -0700 (PDT) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=linaro.org; s=google; h=from:to:cc:subject:date:message-id; bh=Rhu8QAdCEwe9pOQnfwoYILRvrD+vNGKQJ95Q5mYmCKU=; b=Ht8aqDSz6P/2HjrZpx81Ko6CIilufyE+eE7Oj+/i804bkg1orLT9ToPYsMYoVVrIWJ Q3TNpCZOJsby7tWLPJlHJ3SWpcTcat0Kpia6M77CCcPIjoPcZC/Yh04fjZ2VceYk9/6c 5/Pk1Qr5Ayuw7j8afrPHxJRx92lW5h13KECuI= X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:from:to:cc:subject:date:message-id; bh=Rhu8QAdCEwe9pOQnfwoYILRvrD+vNGKQJ95Q5mYmCKU=; b=bvhgiqf6jgZ+Y6NvkAFFRVgOYEEUBP0skoWw3Gtf+JfeWjbJ6GwL2Zs0n8NKfHI2m2 z17ijx1arW8aKWN/l1smPBPPII2xrrmHfyEpaCSNO7rd7r4R4YkKmb/CxAu0+5A6b10l w837A+gyAQ0em8+9pBST25RV38B+EzoSUfHUnxyYirrxRqKw+iT7qLs+jv36wvpOWM8f aI+uEsv99sMFmxDlucChGFZScPRGDP6vTXghnE3RVQCJ51kJ0ZuQ5wlBkwBF3zsH0nqu r9JIyZOHMvYm2WetU8WS+ZabPUroTWWEsuTQ9LiKxYxgfgzNkfGL75nhCz2mFeIPP+r8 FgVg== X-Gm-Message-State: AD7BkJIcDpGXS1C6v26lKFX+6/KHWW7knIrbZEBPAzyhv2sOXN3REPLDovu0r08/6omd6CWm X-Received: by 10.66.246.165 with SMTP id xx5mr12045267pac.87.1458820495141; Thu, 24 Mar 2016 04:54:55 -0700 (PDT) Received: from baolinwangubtpc.spreadtrum.com ([175.111.195.49]) by smtp.gmail.com with ESMTPSA id y23sm9979340pfi.22.2016.03.24.04.54.47 (version=TLS1 cipher=ECDHE-RSA-AES128-SHA bits=128/128); Thu, 24 Mar 2016 04:54:54 -0700 (PDT) From: Baolin Wang To: ulf.hansson@linaro.org, rostedt@goodmis.org, mingo@redhat.com Cc: adrian.hunter@intel.com, yangbo.lu@freescale.com, akpm@linux-foundation.org, JBottomley@Odin.com, lporzio@micron.com, jonathanh@nvidia.com, grundler@chromium.org, axboe@fb.com, fabf@skynet.be, yunpeng.gao@intel.com, dan.j.williams@intel.com, rabin.vincent@axis.com, chuanxiao.dong@intel.com, shawn.lin@rock-chips.com, heiko@sntech.de, dianders@chromium.org, david@protonic.nl, broonie@kernel.org, linus.walleij@linaro.org, takahiro.akashi@linaro.org, baolin.wang@linaro.org, linux-kernel@vger.kernel.org, linux-mmc@vger.kernel.org Subject: [PATCH] mmc: Provide tracepoints for request processing Date: Thu, 24 Mar 2016 19:54:08 +0800 Message-Id: <05d6338bddae751c1755e7825d4179658e78cc71.1458819912.git.baolin.wang@linaro.org> X-Mailer: git-send-email 1.7.9.5 Sender: linux-mmc-owner@vger.kernel.org Precedence: bulk List-ID: X-Mailing-List: linux-mmc@vger.kernel.org X-Spam-Status: No, score=-6.8 required=5.0 tests=BAYES_00,DKIM_SIGNED, RCVD_IN_DNSWL_HI,T_DKIM_INVALID,T_RP_MATCHES_RCVD,UNPARSEABLE_RELAY autolearn=unavailable version=3.3.1 X-Spam-Checker-Version: SpamAssassin 3.3.1 (2010-03-16) on mail.kernel.org X-Virus-Scanned: ClamAV using ClamSMTP This patch provides some tracepoints for the lifecycle of a request from fetching to completion to help with performance analysis of MMC subsystem. Signed-off-by: Baolin Wang --- drivers/mmc/card/block.c | 6 ++ drivers/mmc/card/queue.c | 4 + drivers/mmc/core/core.c | 5 ++ include/trace/events/mmc.h | 188 ++++++++++++++++++++++++++++++++++++++++++++ 4 files changed, 203 insertions(+) create mode 100644 include/trace/events/mmc.h diff --git a/drivers/mmc/card/block.c b/drivers/mmc/card/block.c index fe207e5..d372a2d 100644 --- a/drivers/mmc/card/block.c +++ b/drivers/mmc/card/block.c @@ -46,6 +46,9 @@ #include "queue.h" +#define CREATE_TRACE_POINTS +#include + MODULE_ALIAS("mmc:block"); #ifdef MODULE_PARAM_PREFIX #undef MODULE_PARAM_PREFIX @@ -1709,6 +1712,7 @@ static u8 mmc_blk_prep_packed_list(struct mmc_queue *mq, struct request *req) if (phys_segments > max_phys_segs) break; + trace_mmc_block_packed_req(next); list_add_tail(&next->queuelist, &mqrq->packed->list); cur = next; reqs++; @@ -1870,6 +1874,7 @@ static int mmc_blk_end_packed_req(struct mmc_queue_req *mq_rq) } list_del_init(&prq->queuelist); blk_end_request(prq, 0, blk_rq_bytes(prq)); + trace_mmc_block_req_done(prq); i++; } @@ -1985,6 +1990,7 @@ static int mmc_blk_issue_rw_rq(struct mmc_queue *mq, struct request *rqc) } else { ret = blk_end_request(req, 0, brq->data.bytes_xfered); + trace_mmc_block_req_done(req); } /* diff --git a/drivers/mmc/card/queue.c b/drivers/mmc/card/queue.c index 6f4323c..d0388cf 100644 --- a/drivers/mmc/card/queue.c +++ b/drivers/mmc/card/queue.c @@ -16,6 +16,7 @@ #include #include #include +#include #include #include @@ -64,6 +65,9 @@ static int mmc_queue_thread(void *d) mq->mqrq_cur->req = req; spin_unlock_irq(q->queue_lock); + if (req) + trace_mmc_queue_fetch(req); + if (req || mq->mqrq_prev->req) { set_current_state(TASK_RUNNING); cmd_flags = req ? req->cmd_flags : 0; diff --git a/drivers/mmc/core/core.c b/drivers/mmc/core/core.c index f95d41f..cb575ca 100644 --- a/drivers/mmc/core/core.c +++ b/drivers/mmc/core/core.c @@ -29,6 +29,7 @@ #include #include #include +#include #include #include @@ -152,6 +153,8 @@ void mmc_request_done(struct mmc_host *host, struct mmc_request *mrq) led_trigger_event(host->led, LED_OFF); + trace_mmc_request_done(host, mrq); + if (mrq->sbc) { pr_debug("%s: req done : %d: %08x %08x %08x %08x\n", mmc_hostname(host), mrq->sbc->opcode, @@ -229,6 +232,8 @@ static int mmc_start_request(struct mmc_host *host, struct mmc_request *mrq) if (mmc_card_removed(host->card)) return -ENOMEDIUM; + trace_mmc_request_start(host, mrq); + if (mrq->sbc) { pr_debug("<%s: starting CMD%u arg %08x flags %08x>\n", mmc_hostname(host), mrq->sbc->opcode, diff --git a/include/trace/events/mmc.h b/include/trace/events/mmc.h new file mode 100644 index 0000000..1af63cd --- /dev/null +++ b/include/trace/events/mmc.h @@ -0,0 +1,188 @@ +#undef TRACE_SYSTEM +#define TRACE_SYSTEM mmc + +#if !defined(_TRACE_MMC_H) || defined(TRACE_HEADER_MULTI_READ) +#define _TRACE_MMC_H + +#include +#include +#include +#include + +DECLARE_EVENT_CLASS(mmc_request, + + TP_PROTO(struct request *rq), + + TP_ARGS(rq), + + TP_STRUCT__entry( + __field(sector_t, sector) + __field(unsigned int, data_len) + __field(int, cmd_dir) + __field(struct request *, rq) + ), + + TP_fast_assign( + __entry->sector = blk_rq_pos(rq); + __entry->data_len = blk_rq_bytes(rq); + __entry->cmd_dir = rq_data_dir(rq); + __entry->rq = rq; + ), + + TP_printk("struct request[%p]:sector=%lu rw=%d len=%u", + (struct request *)__entry->rq, + (unsigned long)__entry->sector, + (int)__entry->cmd_dir, + (unsigned int)__entry->data_len) +); + +DEFINE_EVENT(mmc_request, mmc_queue_fetch, + + TP_PROTO(struct request *rq), + + TP_ARGS(rq) + +); + +DEFINE_EVENT(mmc_request, mmc_block_packed_req, + + TP_PROTO(struct request *rq), + + TP_ARGS(rq) + +); + +DEFINE_EVENT(mmc_request, mmc_block_req_done, + + TP_PROTO(struct request *rq), + + TP_ARGS(rq) + +); + +TRACE_EVENT(mmc_request_start, + + TP_PROTO(struct mmc_host *host, struct mmc_request *mrq), + + TP_ARGS(host, mrq), + + TP_STRUCT__entry( + __field(u32, cmd_opcode) + __field(u32, cmd_arg) + __field(unsigned int, cmd_flags) + __field(u32, stop_opcode) + __field(u32, stop_arg) + __field(unsigned int, stop_flags) + __field(u32, sbc_opcode) + __field(u32, sbc_arg) + __field(unsigned int, sbc_flags) + __field(unsigned int, blocks) + __field(unsigned int, blksz) + __field(unsigned int, data_flags) + __field(struct mmc_request *, mrq) + __field(struct mmc_host *, host) + ), + + TP_fast_assign( + __entry->cmd_opcode = mrq->cmd->opcode; + __entry->cmd_arg = mrq->cmd->arg; + __entry->cmd_flags = mrq->cmd->flags; + __entry->stop_opcode = mrq->stop ? mrq->stop->opcode : 0; + __entry->stop_arg = mrq->stop ? mrq->stop->arg : 0; + __entry->stop_flags = mrq->stop ? mrq->stop->flags : 0; + __entry->sbc_opcode = mrq->sbc ? mrq->sbc->opcode : 0; + __entry->sbc_arg = mrq->sbc ? mrq->sbc->arg : 0; + __entry->sbc_flags = mrq->sbc ? mrq->sbc->flags : 0; + __entry->blksz = mrq->data ? mrq->data->blksz : 0; + __entry->blocks = mrq->data ? mrq->data->blocks : 0; + __entry->data_flags = mrq->data ? mrq->data->flags : 0; + __entry->mrq = mrq; + __entry->host = host; + ), + + TP_printk("%s: start struct mmc_request[%p]: " + "cmd_opcode=%u cmd_arg=0x%x cmd_flags=0x%x " + "stop_opcode=%u stop_arg=0x%x stop_flags=0x%x " + "sbc_opcode=%u sbc_arg=0x%x sbc_flags=0x%x " + "blocks=%u blksz=%u data_flags=0x%x", + mmc_hostname((struct mmc_host *)__entry->host), + (struct mmc_request *)__entry->mrq, + (u32)__entry->cmd_opcode, (u32)__entry->cmd_arg, + (unsigned int)__entry->cmd_flags, + (u32)__entry->stop_opcode, (u32)__entry->stop_arg, + (unsigned int)__entry->stop_flags, + (u32)__entry->sbc_opcode, (u32)__entry->sbc_arg, + (unsigned int)__entry->sbc_flags, + (unsigned int)__entry->blocks, + (unsigned int)__entry->blksz, + (unsigned int)__entry->data_flags) +); + +TRACE_EVENT(mmc_request_done, + + TP_PROTO(struct mmc_host *host, struct mmc_request *mrq), + + TP_ARGS(host, mrq), + + TP_STRUCT__entry( + __field(u32, cmd_opcode) + __field(int, cmd_err) + __array(u32, cmd_resp, 4) + __field(u32, stop_opcode) + __field(int, stop_err) + __array(u32, stop_resp, 4) + __field(u32, sbc_opcode) + __field(int, sbc_err) + __array(u32, sbc_resp, 4) + __field(unsigned int, bytes_xfered) + __field(int, data_err) + __field(struct mmc_request *, mrq) + __field(struct mmc_host *, host) + ), + + TP_fast_assign( + __entry->cmd_opcode = mrq->cmd->opcode; + __entry->cmd_err = mrq->cmd->error; + memcpy(__entry->cmd_resp, mrq->cmd->resp, 4); + __entry->stop_opcode = mrq->stop ? mrq->stop->opcode : 0; + __entry->stop_err = mrq->stop ? mrq->stop->error : 0; + __entry->stop_resp[0] = mrq->stop ? mrq->stop->resp[0] : 0; + __entry->stop_resp[1] = mrq->stop ? mrq->stop->resp[1] : 0; + __entry->stop_resp[2] = mrq->stop ? mrq->stop->resp[2] : 0; + __entry->stop_resp[3] = mrq->stop ? mrq->stop->resp[3] : 0; + __entry->sbc_opcode = mrq->sbc ? mrq->sbc->opcode : 0; + __entry->sbc_err = mrq->sbc ? mrq->sbc->error : 0; + __entry->sbc_resp[0] = mrq->sbc ? mrq->sbc->resp[0] : 0; + __entry->sbc_resp[1] = mrq->sbc ? mrq->sbc->resp[1] : 0; + __entry->sbc_resp[2] = mrq->sbc ? mrq->sbc->resp[2] : 0; + __entry->sbc_resp[3] = mrq->sbc ? mrq->sbc->resp[3] : 0; + __entry->bytes_xfered = mrq->data ? mrq->data->bytes_xfered : 0; + __entry->data_err = mrq->data ? mrq->data->error : 0; + __entry->host = host; + __entry->mrq = mrq; + ), + + TP_printk("%s: end struct mmc_request[%p]: " + "cmd_opcode=%u cmd_err=%d cmd_resp=0x%x 0x%x 0x%x 0x%x " + "stop_opcode=%u stop_err=%d stop_resp=0x%x 0x%x 0x%x 0x%x " + "sbc_opcode=%u sbc_err=%d sbc_resp=0x%x 0x%x 0x%x 0x%x " + "bytes_xfered=%u data_err=%d", + mmc_hostname((struct mmc_host *)__entry->host), + (struct mmc_request *)__entry->mrq, + (u32)__entry->cmd_opcode, (int)__entry->cmd_err, + (u32)__entry->cmd_resp[0], (u32)__entry->cmd_resp[1], + (u32)__entry->cmd_resp[2], (u32)__entry->cmd_resp[3], + (u32)__entry->stop_opcode, (int)__entry->stop_err, + (u32)__entry->stop_resp[0], (u32)__entry->stop_resp[1], + (u32)__entry->stop_resp[2], (u32)__entry->stop_resp[3], + (u32)__entry->sbc_opcode, (int)__entry->sbc_err, + (u32)__entry->sbc_resp[0], (u32)__entry->sbc_resp[1], + (u32)__entry->sbc_resp[2], (u32)__entry->sbc_resp[3], + (unsigned int)__entry->bytes_xfered, + (int)__entry->data_err) +); + +#endif /* _TRACE_MMC_H */ + +/* This part must be outside protection */ +#include