| Message ID | 05d6338bddae751c1755e7825d4179658e78cc71.1458819912.git.baolin.wang@linaro.org (mailing list archive) |
|---|---|
| State | New, archived |
| Headers | show |
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/20160324-195755
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
On 03/24/2016 05:54 AM, Baolin Wang wrote: > This patch provides some tracepoints for the lifecycle of a request from > fetching to completion to help with performance analysis of MMC subsystem. Most of these already exist as block layer trace points, why do we need mmc specific ones?
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/20160324-195755
base: https://git.linaro.org/people/ulf.hansson/mmc next
config: x86_64-randconfig-n0-03242034 (attached as .config)
reproduce:
# save the attached .config to linux build tree
make ARCH=x86_64
All errors (new ones prefixed by >>):
drivers/built-in.o: In function `mmc_request_done':
>> (.text+0x62f58f): undefined reference to `__tracepoint_mmc_request_done'
drivers/built-in.o: In function `mmc_request_done':
(.text+0x62f65e): undefined reference to `__tracepoint_mmc_request_done'
drivers/built-in.o: In function `mmc_request_done':
(.text+0x62f6ee): undefined reference to `__tracepoint_mmc_request_done'
drivers/built-in.o: In function `mmc_start_request':
>> core.c:(.text+0x62f8f1): undefined reference to `__tracepoint_mmc_request_start'
core.c:(.text+0x62f9ad): undefined reference to `__tracepoint_mmc_request_start'
core.c:(.text+0x62fbf1): undefined reference to `__tracepoint_mmc_request_start'
---
0-DAY kernel test infrastructure Open Source Technology Center
https://lists.01.org/pipermail/kbuild-all Intel Corporation
On Thu, 24 Mar 2016 19:54:08 +0800 Baolin Wang <baolin.wang@linaro.org> wrote: > +++ 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 <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", > + (struct request *)__entry->rq, > + (unsigned long)__entry->sector, > + (int)__entry->cmd_dir, > + (unsigned int)__entry->data_len) Why the typecasts? __entry->rq is already of the type "struct request *" as you declared it in the TP_STRUCT__entry(). Same for the other fields. > +); > + > +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), Is this safe? I see mmc_hostname() defined as: dev_name(&(x)->class_dev) Which would be here: dev_name(&(__entry->host)->class_dev) How what happens if ater you trace a host, you free it? Then the old pointer will still be in the buffer. If the user reads the trace data and this is called, then __entry->host will be pointing to freed data, and the dereference could cause a system crash. > + (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), Same here, and please get rid of all the redundant typecasts. -- Steve > + (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 <trace/define_trace.h> -- To unsubscribe from this list: send the line "unsubscribe linux-mmc" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On 24 March 2016 at 22:08, Jens Axboe <axboe@fb.com> wrote: > On 03/24/2016 05:54 AM, Baolin Wang wrote: >> >> This patch provides some tracepoints for the lifecycle of a request from >> fetching to completion to help with performance analysis of MMC subsystem. > > > Most of these already exist as block layer trace points, why do we need mmc > specific ones? Currently the MMC core does not have any tracepoints for use with ftrace. These are very useful as they provide a very low overhead runtime controllable way of getting diagnostics from the system which is capable of recording a great deal of information without impacting system performance. We have tracepoints in the block layer so we can do some trace of MMC but none in MMC itself so adding some where appropriate would help people follow the activity of subsystem. > > > -- > Jens Axboe >
On 24 March 2016 at 23:13, Steven Rostedt <rostedt@goodmis.org> wrote: > On Thu, 24 Mar 2016 19:54:08 +0800 > Baolin Wang <baolin.wang@linaro.org> wrote: > > >> +++ 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 <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", >> + (struct request *)__entry->rq, >> + (unsigned long)__entry->sector, >> + (int)__entry->cmd_dir, >> + (unsigned int)__entry->data_len) > > Why the typecasts? __entry->rq is already of the type "struct request *" > as you declared it in the TP_STRUCT__entry(). Same for the other fields. Oh, I'll remove all the typecasts. Thanks. > > >> +); >> + >> +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), > > Is this safe? I see mmc_hostname() defined as: > > dev_name(&(x)->class_dev) > > Which would be here: > > dev_name(&(__entry->host)->class_dev) > > How what happens if ater you trace a host, you free it? Then the old > pointer will still be in the buffer. If the user reads the trace data > and this is called, then __entry->host will be pointing to freed data, > and the dereference could cause a system crash. Sorry, I missed that, you are right. I'll fix that in next version. Thanks for your good comments. > > >> + (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), > > Same here, and please get rid of all the redundant typecasts. OK. > > -- Steve > >> + (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 <trace/define_trace.h> >
On 03/25/2016 01:32 AM, Baolin Wang wrote: > On 24 March 2016 at 22:08, Jens Axboe <axboe@fb.com> wrote: >> On 03/24/2016 05:54 AM, Baolin Wang wrote: >>> >>> This patch provides some tracepoints for the lifecycle of a request from >>> fetching to completion to help with performance analysis of MMC subsystem. >> >> >> Most of these already exist as block layer trace points, why do we need mmc >> specific ones? > > Currently the MMC core does not have any tracepoints for use with > ftrace. These are very useful as they provide a very low overhead > runtime controllable way of getting diagnostics from the system which > is capable of recording a great deal of information without impacting > system performance. We have tracepoints in the block layer so we can > do some trace of MMC but none in MMC itself so adding some where > appropriate would help people follow the activity of subsystem. But more than half of the trace points you added, those are DIRECTLY related to the block event. So what you are saying makes little sense. I see you resend it with the same trace points, I'll comment on that mail.
On 25 March 2016 at 22:07, Jens Axboe <axboe@fb.com> wrote: > On 03/25/2016 01:32 AM, Baolin Wang wrote: >> >> On 24 March 2016 at 22:08, Jens Axboe <axboe@fb.com> wrote: >>> >>> On 03/24/2016 05:54 AM, Baolin Wang wrote: >>>> >>>> >>>> This patch provides some tracepoints for the lifecycle of a request from >>>> fetching to completion to help with performance analysis of MMC >>>> subsystem. >>> >>> >>> >>> Most of these already exist as block layer trace points, why do we need >>> mmc >>> specific ones? >> >> >> Currently the MMC core does not have any tracepoints for use with >> ftrace. These are very useful as they provide a very low overhead >> runtime controllable way of getting diagnostics from the system which >> is capable of recording a great deal of information without impacting >> system performance. We have tracepoints in the block layer so we can >> do some trace of MMC but none in MMC itself so adding some where >> appropriate would help people follow the activity of subsystem. > > > But more than half of the trace points you added, those are DIRECTLY related > to the block event. So what you are saying makes little sense. I see you > resend it with the same trace points, I'll comment on that mail. OK. I'll address your comments on that new mail. Thanks. > > -- > Jens Axboe >
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..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 <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", + (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 <trace/define_trace.h>
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 <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 | 188 ++++++++++++++++++++++++++++++++++++++++++++ 4 files changed, 203 insertions(+) create mode 100644 include/trace/events/mmc.h