* [PATCH v2] mmc: Provide tracepoints for request processing
@ 2016-03-25 8:19 Baolin Wang
2016-03-25 14:10 ` Jens Axboe
2016-03-25 20:05 ` kbuild test robot
0 siblings, 2 replies; 4+ messages in thread
From: Baolin Wang @ 2016-03-25 8:19 UTC (permalink / raw)
To: ulf.hansson, rostedt, mingo
Cc: adrian.hunter, yangbo.lu, akpm, JBottomley, lporzio, jonathanh,
grundler, axboe, fabf, yunpeng.gao, dan.j.williams, rabin.vincent,
chuanxiao.dong, shawn.lin, heiko, dianders, david, broonie,
linus.walleij, takahiro.akashi, baolin.wang, linux-kernel,
linux-mmc
This patch provides some tracepoints for the lifecycle of a request from
fetching to completion to help with performance analysis of MMC subsystem.
Changes since v1:
- Remove the redundant typecasts.
- Fix the bug that could cause a system crash.
Signed-off-by: Baolin Wang <baolin.wang@linaro.org>
---
drivers/mmc/card/block.c | 6 ++
drivers/mmc/card/queue.c | 4 +
drivers/mmc/core/core.c | 5 ++
include/trace/events/mmc.h | 178 ++++++++++++++++++++++++++++++++++++++++++++
4 files changed, 193 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 <trace/events/mmc.h>
+
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 <linux/kthread.h>
#include <linux/scatterlist.h>
#include <linux/dma-mapping.h>
+#include <trace/events/mmc.h>
#include <linux/mmc/card.h>
#include <linux/mmc/host.h>
@@ -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 <linux/random.h>
#include <linux/slab.h>
#include <linux/of.h>
+#include <trace/events/mmc.h>
#include <linux/mmc/card.h>
#include <linux/mmc/host.h>
@@ -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 <CMD%u>: %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..e165ce7
--- /dev/null
+++ b/include/trace/events/mmc.h
@@ -0,0 +1,178 @@
+#undef TRACE_SYSTEM
+#define TRACE_SYSTEM mmc
+
+#if !defined(_TRACE_MMC_H) || defined(TRACE_HEADER_MULTI_READ)
+#define _TRACE_MMC_H
+
+#include <linux/blkdev.h>
+#include <linux/mmc/core.h>
+#include <linux/mmc/host.h>
+#include <linux/tracepoint.h>
+
+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",
+ __entry->rq, (unsigned long)__entry->sector,
+ __entry->cmd_dir, __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)
+ __string(name, mmc_hostname(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;
+ __assign_str(name, mmc_hostname(host));
+ __entry->mrq = mrq;
+ ),
+
+ 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",
+ __get_str(name), __entry->mrq,
+ __entry->cmd_opcode, __entry->cmd_arg, __entry->cmd_flags,
+ __entry->stop_opcode, __entry->stop_arg, __entry->stop_flags,
+ __entry->sbc_opcode, __entry->sbc_arg, __entry->sbc_flags,
+ __entry->blocks, __entry->blksz, __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)
+ __string(name, mmc_hostname(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;
+ __assign_str(name, mmc_hostname(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",
+ __get_str(name), __entry->mrq,
+ __entry->cmd_opcode, __entry->cmd_err,
+ __entry->cmd_resp[0], __entry->cmd_resp[1],
+ __entry->cmd_resp[2], __entry->cmd_resp[3],
+ __entry->stop_opcode, __entry->stop_err,
+ __entry->stop_resp[0], __entry->stop_resp[1],
+ __entry->stop_resp[2], __entry->stop_resp[3],
+ __entry->sbc_opcode, __entry->sbc_err,
+ __entry->sbc_resp[0], __entry->sbc_resp[1],
+ __entry->sbc_resp[2], __entry->sbc_resp[3],
+ __entry->bytes_xfered, __entry->data_err)
+);
+
+#endif /* _TRACE_MMC_H */
+
+/* This part must be outside protection */
+#include <trace/define_trace.h>
--
1.7.9.5
^ permalink raw reply related [flat|nested] 4+ messages in thread
* Re: [PATCH v2] mmc: Provide tracepoints for request processing
2016-03-25 8:19 [PATCH v2] mmc: Provide tracepoints for request processing Baolin Wang
@ 2016-03-25 14:10 ` Jens Axboe
2016-03-28 5:53 ` Baolin Wang
2016-03-25 20:05 ` kbuild test robot
1 sibling, 1 reply; 4+ messages in thread
From: Jens Axboe @ 2016-03-25 14:10 UTC (permalink / raw)
To: Baolin Wang, ulf.hansson, rostedt, mingo
Cc: adrian.hunter, yangbo.lu, akpm, JBottomley, lporzio, jonathanh,
grundler, fabf, yunpeng.gao, dan.j.williams, rabin.vincent,
chuanxiao.dong, shawn.lin, heiko, dianders, david, broonie,
linus.walleij, takahiro.akashi, linux-kernel, linux-mmc
On 03/25/2016 02:19 AM, Baolin Wang wrote:
> 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 <trace/events/mmc.h>
> +
> 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++;
This looks like the only valid trace point in the block part.
> @@ -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);
We just logged a complete event through blk_end_request() here.
> @@ -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);
> }
Ditto
> 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 <linux/kthread.h>
> #include <linux/scatterlist.h>
> #include <linux/dma-mapping.h>
> +#include <trace/events/mmc.h>
>
> #include <linux/mmc/card.h>
> #include <linux/mmc/host.h>
> @@ -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);
Issue event was just logged here, if req != NULL. So also redundant.
Basically only your core mmc events would potentially have merit, the
rest are all dupes. So nak.
--
Jens Axboe
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [PATCH v2] mmc: Provide tracepoints for request processing
2016-03-25 8:19 [PATCH v2] mmc: Provide tracepoints for request processing Baolin Wang
2016-03-25 14:10 ` Jens Axboe
@ 2016-03-25 20:05 ` kbuild test robot
1 sibling, 0 replies; 4+ messages in thread
From: kbuild test robot @ 2016-03-25 20:05 UTC (permalink / raw)
Cc: kbuild-all, ulf.hansson, rostedt, mingo, adrian.hunter, yangbo.lu,
akpm, JBottomley, lporzio, jonathanh, grundler, axboe, fabf,
yunpeng.gao, dan.j.williams, rabin.vincent, chuanxiao.dong,
shawn.lin, heiko, dianders, david, broonie, linus.walleij,
takahiro.akashi, baolin.wang, linux-kernel, linux-mmc
[-- Attachment #1: Type: text/plain, Size: 896 bytes --]
Hi Baolin,
[auto build test ERROR on ulf.hansson-mmc/next]
[also build test ERROR on v4.5 next-20160324]
[if your patch is applied to the wrong git tree, please drop us a note to help improving the system]
url: https://github.com/0day-ci/linux/commits/Baolin-Wang/mmc-Provide-tracepoints-for-request-processing/20160325-162204
base: https://git.linaro.org/people/ulf.hansson/mmc next
config: x86_64-rhel (attached as .config)
reproduce:
# save the attached .config to linux build tree
make ARCH=x86_64
All errors (new ones prefixed by >>):
>> ERROR: "__tracepoint_mmc_request_start" [drivers/mmc/core/mmc_core.ko] undefined!
>> ERROR: "__tracepoint_mmc_request_done" [drivers/mmc/core/mmc_core.ko] undefined!
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/kbuild-all Intel Corporation
[-- Attachment #2: .config.gz --]
[-- Type: application/octet-stream, Size: 36091 bytes --]
^ permalink raw reply [flat|nested] 4+ messages in thread
* Re: [PATCH v2] mmc: Provide tracepoints for request processing
2016-03-25 14:10 ` Jens Axboe
@ 2016-03-28 5:53 ` Baolin Wang
0 siblings, 0 replies; 4+ messages in thread
From: Baolin Wang @ 2016-03-28 5:53 UTC (permalink / raw)
To: Jens Axboe
Cc: Ulf Hansson, Steven Rostedt, mingo, adrian.hunter, yangbo.lu,
akpm, JBottomley, lporzio, jonathanh, Grant Grundler, fabf,
yunpeng.gao, dan.j.williams, rabin.vincent, chuanxiao.dong,
shawn.lin, Heiko Stübner, Douglas Anderson, david,
Mark Brown, Linus Walleij, Takahiro Akashi, LKML, linux-mmc
On 25 March 2016 at 22:10, Jens Axboe <axboe@fb.com> wrote:
> On 03/25/2016 02:19 AM, Baolin Wang wrote:
>>
>> 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 <trace/events/mmc.h>
>> +
>> 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++;
>
>
> This looks like the only valid trace point in the block part.
OK.
>
>> @@ -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);
>
>
> We just logged a complete event through blk_end_request() here.
I'll remove this repeated tracepoint.
>>
>> @@ -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);
>> }
>
>
> Ditto
Will remove it too.
>
>> 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 <linux/kthread.h>
>> #include <linux/scatterlist.h>
>> #include <linux/dma-mapping.h>
>> +#include <trace/events/mmc.h>
>>
>> #include <linux/mmc/card.h>
>> #include <linux/mmc/host.h>
>> @@ -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);
>
>
> Issue event was just logged here, if req != NULL. So also redundant.
Make sense.
>
> Basically only your core mmc events would potentially have merit, the rest
> are all dupes. So nak.
I'll remove the redundant tracepoints. Thanks for your comments.
>
> --
> Jens Axboe
>
--
Baolin.wang
Best Regards
^ permalink raw reply [flat|nested] 4+ messages in thread
end of thread, other threads:[~2016-03-28 5:53 UTC | newest]
Thread overview: 4+ messages (download: mbox.gz follow: Atom feed
-- links below jump to the message on this page --
2016-03-25 8:19 [PATCH v2] mmc: Provide tracepoints for request processing Baolin Wang
2016-03-25 14:10 ` Jens Axboe
2016-03-28 5:53 ` Baolin Wang
2016-03-25 20:05 ` kbuild test robot
This is a public inbox, see mirroring instructions
for how to clone and mirror all data and code used for this inbox