Hi,
This series adds trace event for UIC commands and do a small cleanup in struct uic_command.
v1 -> v2:
- Rename "uic_send" to "send" and "uic_complete" to "complete"
- Move "send" trace before UIC command is sent otherwise "send" trace may log incorrect arguments
- Move "complete" trace to UIC interrupt handler to make logging time precise
Stanley Chu (2):
scsi: ufs: Remove unused field in struct uic_command
scsi: ufs: Add trace event for UIC commands
drivers/scsi/ufs/ufshcd.c | 26 ++++++++++++++++++++++++++
drivers/scsi/ufs/ufshcd.h | 4 ----
include/trace/events/ufs.h | 31 +++++++++++++++++++++++++++++++
3 files changed, 57 insertions(+), 4 deletions(-)
--
2.18.0
Use the ftrace infrastructure to conditionally trace UFS UIC command
events.
New trace event "ufshcd_uic_command" is created, which samples the
following UFS UIC command data:
- Device name
- Optional identification string
- UIC command opcode
- UIC command argument1
- UIC command argument2
- UIC command argement3
Usage:
echo 1 > /sys/kernel/debug/tracing/events/ufs/enable
cat /sys/kernel/debug/tracing/trace_pipe
Signed-off-by: Stanley Chu <[email protected]>
Acked-by: Avri Altman <[email protected]>
---
drivers/scsi/ufs/ufshcd.c | 26 ++++++++++++++++++++++++++
include/trace/events/ufs.h | 31 +++++++++++++++++++++++++++++++
2 files changed, 57 insertions(+)
diff --git a/drivers/scsi/ufs/ufshcd.c b/drivers/scsi/ufs/ufshcd.c
index ad4fc829cbb2..1fd2fd526c68 100644
--- a/drivers/scsi/ufs/ufshcd.c
+++ b/drivers/scsi/ufs/ufshcd.c
@@ -340,6 +340,26 @@ static void ufshcd_add_tm_upiu_trace(struct ufs_hba *hba, unsigned int tag,
&descp->input_param1);
}
+static void ufshcd_add_uic_command_trace(struct ufs_hba *hba,
+ struct uic_command *ucmd,
+ const char *str)
+{
+ u32 cmd;
+
+ if (!trace_ufshcd_uic_command_enabled())
+ return;
+
+ if (!strcmp(str, "send"))
+ cmd = ucmd->command;
+ else
+ cmd = ufshcd_readl(hba, REG_UIC_COMMAND);
+
+ trace_ufshcd_uic_command(dev_name(hba->dev), str, cmd,
+ ufshcd_readl(hba, REG_UIC_COMMAND_ARG_1),
+ ufshcd_readl(hba, REG_UIC_COMMAND_ARG_2),
+ ufshcd_readl(hba, REG_UIC_COMMAND_ARG_3));
+}
+
static void ufshcd_add_command_trace(struct ufs_hba *hba,
unsigned int tag, const char *str)
{
@@ -2052,6 +2072,8 @@ ufshcd_dispatch_uic_cmd(struct ufs_hba *hba, struct uic_command *uic_cmd)
ufshcd_writel(hba, uic_cmd->argument2, REG_UIC_COMMAND_ARG_2);
ufshcd_writel(hba, uic_cmd->argument3, REG_UIC_COMMAND_ARG_3);
+ ufshcd_add_uic_command_trace(hba, uic_cmd, "send");
+
/* Write UIC Cmd */
ufshcd_writel(hba, uic_cmd->command & COMMAND_OPCODE_MASK,
REG_UIC_COMMAND);
@@ -4825,11 +4847,15 @@ static irqreturn_t ufshcd_uic_cmd_compl(struct ufs_hba *hba, u32 intr_status)
ufshcd_get_uic_cmd_result(hba);
hba->active_uic_cmd->argument3 =
ufshcd_get_dme_attr_val(hba);
+ ufshcd_add_uic_command_trace(hba, hba->active_uic_cmd,
+ "complete");
complete(&hba->active_uic_cmd->done);
retval = IRQ_HANDLED;
}
if ((intr_status & UFSHCD_UIC_PWR_MASK) && hba->uic_async_done) {
+ ufshcd_add_uic_command_trace(hba, hba->active_uic_cmd,
+ "complete");
complete(hba->uic_async_done);
retval = IRQ_HANDLED;
}
diff --git a/include/trace/events/ufs.h b/include/trace/events/ufs.h
index 5f300739240d..84841b3a7ffd 100644
--- a/include/trace/events/ufs.h
+++ b/include/trace/events/ufs.h
@@ -249,6 +249,37 @@ TRACE_EVENT(ufshcd_command,
)
);
+TRACE_EVENT(ufshcd_uic_command,
+ TP_PROTO(const char *dev_name, const char *str, u32 cmd,
+ u32 arg1, u32 arg2, u32 arg3),
+
+ TP_ARGS(dev_name, str, cmd, arg1, arg2, arg3),
+
+ TP_STRUCT__entry(
+ __string(dev_name, dev_name)
+ __string(str, str)
+ __field(u32, cmd)
+ __field(u32, arg1)
+ __field(u32, arg2)
+ __field(u32, arg3)
+ ),
+
+ TP_fast_assign(
+ __assign_str(dev_name, dev_name);
+ __assign_str(str, str);
+ __entry->cmd = cmd;
+ __entry->arg1 = arg1;
+ __entry->arg2 = arg2;
+ __entry->arg3 = arg3;
+ ),
+
+ TP_printk(
+ "%s: %s: cmd: 0x%x, arg1: 0x%x, arg2: 0x%x, arg3: 0x%x",
+ __get_str(str), __get_str(dev_name), __entry->cmd,
+ __entry->arg1, __entry->arg2, __entry->arg3
+ )
+);
+
TRACE_EVENT(ufshcd_upiu,
TP_PROTO(const char *dev_name, const char *str, void *hdr, void *tsf),
--
2.18.0
Remove unused field "cmd_active" and "result" in struct ufs_command.
Signed-off-by: Stanley Chu <[email protected]>
Reviewed-by: Alim Akhtar <[email protected]>
---
drivers/scsi/ufs/ufshcd.h | 4 ----
1 file changed, 4 deletions(-)
diff --git a/drivers/scsi/ufs/ufshcd.h b/drivers/scsi/ufs/ufshcd.h
index bf97d616e597..7fa35c78342b 100644
--- a/drivers/scsi/ufs/ufshcd.h
+++ b/drivers/scsi/ufs/ufshcd.h
@@ -88,8 +88,6 @@ enum dev_cmd_type {
* @argument1: UIC command argument 1
* @argument2: UIC command argument 2
* @argument3: UIC command argument 3
- * @cmd_active: Indicate if UIC command is outstanding
- * @result: UIC command result
* @done: UIC command completion
*/
struct uic_command {
@@ -97,8 +95,6 @@ struct uic_command {
u32 argument1;
u32 argument2;
u32 argument3;
- int cmd_active;
- int result;
struct completion done;
};
--
2.18.0
> /* Write UIC Cmd */
> ufshcd_writel(hba, uic_cmd->command & COMMAND_OPCODE_MASK,
> REG_UIC_COMMAND);
> @@ -4825,11 +4847,15 @@ static irqreturn_t ufshcd_uic_cmd_compl(struct
> ufs_hba *hba, u32 intr_status)
> ufshcd_get_uic_cmd_result(hba);
> hba->active_uic_cmd->argument3 =
> ufshcd_get_dme_attr_val(hba);
> + ufshcd_add_uic_command_trace(hba, hba->active_uic_cmd,
> + "complete");
> complete(&hba->active_uic_cmd->done);
> retval = IRQ_HANDLED;
> }
>
> if ((intr_status & UFSHCD_UIC_PWR_MASK) && hba->uic_async_done) {
> + ufshcd_add_uic_command_trace(hba, hba->active_uic_cmd,
> + "complete");
> complete(hba->uic_async_done);
> retval = IRQ_HANDLED;
Why not call ufshcd_add_uic_command_trace once if retval == IRQ_HANDLED?
Is it that the exact timestamp?
Hi Avri,
On Mon, 2020-06-15 at 07:13 +0000, Avri Altman wrote:
> > /* Write UIC Cmd */
> > ufshcd_writel(hba, uic_cmd->command & COMMAND_OPCODE_MASK,
> > REG_UIC_COMMAND);
> > @@ -4825,11 +4847,15 @@ static irqreturn_t ufshcd_uic_cmd_compl(struct
> > ufs_hba *hba, u32 intr_status)
> > ufshcd_get_uic_cmd_result(hba);
> > hba->active_uic_cmd->argument3 =
> > ufshcd_get_dme_attr_val(hba);
> > + ufshcd_add_uic_command_trace(hba, hba->active_uic_cmd,
> > + "complete");
> > complete(&hba->active_uic_cmd->done);
> > retval = IRQ_HANDLED;
> > }
> >
> > if ((intr_status & UFSHCD_UIC_PWR_MASK) && hba->uic_async_done) {
> > + ufshcd_add_uic_command_trace(hba, hba->active_uic_cmd,
> > + "complete");
> > complete(hba->uic_async_done);
> > retval = IRQ_HANDLED;
>
>
> Why not call ufshcd_add_uic_command_trace once if retval == IRQ_HANDLED?
> Is it that the exact timestamp?
Thanks! This makes the code cleaner.
Fixed in v3.
Stanley Chu