[PATCH v4] scsi: ufs: core: Add trace event for MCQ

[PATCH v4] scsi: ufs: core: Add trace event for MCQ

[Ziqi Chen]

Added a new trace event to record MCQ relevant information
for each request in MCQ mode, include hardware queue ID,
SQ tail slot, CQ head slot and CQ tail slot.

Signed-off-by: Ziqi Chen <quic_ziqichen@quicinc.com>

---
Changes to v3:
- Free trace_ufshcd_command_mcq() from dependency on trace_ufshcd_command().

Changes to v2:
- Shorten printing strings.

Changes to v1:
- Adjust the order of fileds to keep them aligned.
---
 drivers/ufs/core/ufshcd.c  | 17 ++++++++++++----
 include/trace/events/ufs.h | 48 ++++++++++++++++++++++++++++++++++++++++++++++
 2 files changed, 61 insertions(+), 4 deletions(-)

diff --git a/drivers/ufs/core/ufshcd.c b/drivers/ufs/core/ufshcd.c
index 3b3cf78..e43aee1 100644
--- a/drivers/ufs/core/ufshcd.c
+++ b/drivers/ufs/core/ufshcd.c
@@ -426,6 +426,7 @@ static void ufshcd_add_command_trace(struct ufs_hba *hba, unsigned int tag,
 	struct ufshcd_lrb *lrbp = &hba->lrb[tag];
 	struct scsi_cmnd *cmd = lrbp->cmd;
 	struct request *rq = scsi_cmd_to_rq(cmd);
+	struct ufs_hw_queue *hwq;
 	int transfer_len = -1;
 
 	if (!cmd)
@@ -433,7 +434,8 @@ static void ufshcd_add_command_trace(struct ufs_hba *hba, unsigned int tag,
 
 	/* trace UPIU also */
 	ufshcd_add_cmd_upiu_trace(hba, tag, str_t);
-	if (!trace_ufshcd_command_enabled())
+	if (!trace_ufshcd_command_enabled() &&
+		!trace_ufshcd_command_mcq_enabled())
 		return;
 
 	opcode = cmd->cmnd[0];
@@ -456,9 +458,16 @@ static void ufshcd_add_command_trace(struct ufs_hba *hba, unsigned int tag,
 	}
 
 	intr = ufshcd_readl(hba, REG_INTERRUPT_STATUS);
-	doorbell = ufshcd_readl(hba, REG_UTP_TRANSFER_REQ_DOOR_BELL);
-	trace_ufshcd_command(dev_name(hba->dev), str_t, tag,
-			doorbell, transfer_len, intr, lba, opcode, group_id);
+
+	if (is_mcq_enabled(hba)) {
+		hwq = ufshcd_mcq_req_to_hwq(hba, rq);
+		trace_ufshcd_command_mcq(dev_name(hba->dev), str_t, tag,
+				hwq, transfer_len, intr, lba, opcode, group_id);
+	} else {
+		doorbell = ufshcd_readl(hba, REG_UTP_TRANSFER_REQ_DOOR_BELL);
+		trace_ufshcd_command(dev_name(hba->dev), str_t, tag,
+				doorbell, transfer_len, intr, lba, opcode, group_id);
+	}
 }
 
 static void ufshcd_print_clk_freqs(struct ufs_hba *hba)
diff --git a/include/trace/events/ufs.h b/include/trace/events/ufs.h
index 599739e..604b2cd 100644
--- a/include/trace/events/ufs.h
+++ b/include/trace/events/ufs.h
@@ -10,6 +10,7 @@
 #define _TRACE_UFS_H
 
 #include <linux/tracepoint.h>
+#include <ufs/ufshcd.h>
 
 #define str_opcode(opcode)						\
 	__print_symbolic(opcode,					\
@@ -307,6 +308,53 @@ TRACE_EVENT(ufshcd_command,
 	)
 );
 
+TRACE_EVENT(ufshcd_command_mcq,
+	TP_PROTO(const char *dev_name, enum ufs_trace_str_t str_t,
+		unsigned int tag, struct ufs_hw_queue *hwq, int transfer_len,
+		u32 intr, u64 lba, u8 opcode, u8 group_id),
+
+	TP_ARGS(dev_name, str_t, tag, hwq, transfer_len, intr, lba, opcode, group_id),
+
+	TP_STRUCT__entry(
+		__string(dev_name, dev_name)
+		__field(enum ufs_trace_str_t, str_t)
+		__field(unsigned int, tag)
+		__field(u32, hwq_id)
+		__field(u32, sq_tail)
+		__field(u32, cq_head)
+		__field(u32, cq_tail)
+		__field(int, transfer_len)
+		__field(u32, intr)
+		__field(u64, lba)
+		__field(u8, opcode)
+		__field(u8, group_id)
+	),
+
+	TP_fast_assign(
+		__assign_str(dev_name, dev_name);
+		__entry->str_t = str_t;
+		__entry->tag = tag;
+		__entry->hwq_id = hwq->id;
+		__entry->sq_tail = hwq->sq_tail_slot;
+		__entry->cq_head = hwq->cq_head_slot;
+		__entry->cq_tail = hwq->cq_tail_slot;
+		__entry->transfer_len = transfer_len;
+		__entry->intr = intr;
+		__entry->lba = lba;
+		__entry->opcode = opcode;
+		__entry->group_id = group_id;
+	),
+
+	TP_printk(
+		"%s: %s: tag: %u, hqid: %d, size: %d, IS: %u, LBA: %llu, opcode: 0x%x (%s), group_id: 0x%x, sqt: %d, cqh: %d, cqt: %d",
+		show_ufs_cmd_trace_str(__entry->str_t), __get_str(dev_name),
+		__entry->tag, __entry->hwq_id, __entry->transfer_len,
+		__entry->intr, __entry->lba, (u32)__entry->opcode,
+		str_opcode(__entry->opcode), (u32)__entry->group_id,
+		__entry->sq_tail, __entry->cq_head,  __entry->cq_tail
+	)
+);
+
 TRACE_EVENT(ufshcd_uic_command,
 	TP_PROTO(const char *dev_name, enum ufs_trace_str_t str_t, u32 cmd,
 		 u32 arg1, u32 arg2, u32 arg3),
-- 
2.7.4

Re: [PATCH v4] scsi: ufs: core: Add trace event for MCQ

[Bart Van Assche]

On 3/3/23 01:35, Ziqi Chen wrote:
> -	doorbell = ufshcd_readl(hba, REG_UTP_TRANSFER_REQ_DOOR_BELL);
> -	trace_ufshcd_command(dev_name(hba->dev), str_t, tag,
> -			doorbell, transfer_len, intr, lba, opcode, group_id);
> +
> +	if (is_mcq_enabled(hba)) {
> +		hwq = ufshcd_mcq_req_to_hwq(hba, rq);
> +		trace_ufshcd_command_mcq(dev_name(hba->dev), str_t, tag,
> +				hwq, transfer_len, intr, lba, opcode, group_id);
> +	} else {
> +		doorbell = ufshcd_readl(hba, REG_UTP_TRANSFER_REQ_DOOR_BELL);
> +		trace_ufshcd_command(dev_name(hba->dev), str_t, tag,
> +				doorbell, transfer_len, intr, lba, opcode, group_id);
> +	}
>   }
Users will hate it if the trace events for legacy mode and MCQ mode are 
different. Instead of defining a new trace event for the MCQ mode, I 
think we need to add the MCQ information in the existing trace event.

Thanks,

Bart.

Re: [PATCH v4] scsi: ufs: core: Add trace event for MCQ

[Bart Van Assche]

On 3/6/23 21:53, Ziqi Chen wrote:
> You are right,  users may hate it if the trace events for legacy mode 
> and MCQ mode are different. But if I merge them into one event, it will 
> print much invalid information as we can not add if-else into TP_printk().
> 
> (For example:  in SDB legacy mode, you can see such invalid prints " 
> hqid = 0 , sqt= 0, cqh=0, cqt = 0")
> 
> Users may hate these invalid information.
> 
> Anyway, I have made new version that merge 2 mode into one event, but 
> are you sure we really need to use this way? if yes , I can push new 
> version here.
> 
> Or, could you give some suggestions if you have better way.
> 
> Below is a piece of new version code , you can preview.
> 
>      TP_fast_assign(
>          __assign_str(dev_name, dev_name);
>          __entry->str_t = str_t;
>          __entry->tag = tag;
>          __entry->doorbell = doorbell;
>          __entry->hwq_id = hwq? hwq->id: 0;
>          __entry->sq_tail = hwq? hwq->sq_tail_slot: 0;
>          __entry->cq_head = hwq? hwq->cq_head_slot: 0;
>          __entry->cq_tail = hwq? hwq->cq_tail_slot: 0;
>          __entry->transfer_len = transfer_len;
>          __entry->lba = lba;
>          __entry->intr = intr;
>          __entry->opcode = opcode;
>          __entry->group_id = group_id;
>      ),
> 
>      TP_printk(
>          "%s: %s: tag: %u, DB: 0x%x, size: %d, IS: %u, LBA: %llu, 
> opcode: 0x%x (%s),"
>          "group_id: 0x%x, hqid: %d, sqt: %d, cqh: %d, cqt: %d",
>          show_ufs_cmd_trace_str(__entry->str_t), __get_str(dev_name), 
> __entry->tag,
>          __entry->doorbell, __entry->transfer_len, __entry->intr, 
> __entry->lba,
>          (u32)__entry->opcode, str_opcode(__entry->opcode), 
> (u32)__entry->group_id,
>          __entry->hwq_id,__entry->sq_tail, __entry->cq_head,  
> __entry->cq_tail
>      )

Hi Ziqi,

Please reply below the original e-mail instead of above. This is 
expected on Linux kernel mailing lists.

Regarding your question: I propose to leave out the sq_tail, cq_head and 
cq_tail information. That information may be useful for hardware 
developers but is not useful for other users of the Linux kernel. So the 
only piece of information that is left that is MCQ-specific is the 
hardware queue index. I expect that users will be fine to see that 
information in trace events.

How about reporting hardware queue index -1 for legacy mode instead of 
0? That will allow users to tell the difference between legacy mode and 
MCQ mode from the trace events.

Thanks,

Bart.

Re: [PATCH v4] scsi: ufs: core: Add trace event for MCQ

[Ziqi Chen]

On 3/7/2023 11:47 PM, Bart Van Assche wrote:
> On 3/6/23 21:53, Ziqi Chen wrote:
>> You are right,  users may hate it if the trace events for legacy mode 
>> and MCQ mode are different. But if I merge them into one event, it 
>> will print much invalid information as we can not add if-else into 
>> TP_printk().
>>
>> (For example:  in SDB legacy mode, you can see such invalid prints " 
>> hqid = 0 , sqt= 0, cqh=0, cqt = 0")
>>
>> Users may hate these invalid information.
>>
>> Anyway, I have made new version that merge 2 mode into one event, but 
>> are you sure we really need to use this way? if yes , I can push new 
>> version here.
>>
>> Or, could you give some suggestions if you have better way.
>>
>> Below is a piece of new version code , you can preview.
>>
>>      TP_fast_assign(
>>          __assign_str(dev_name, dev_name);
>>          __entry->str_t = str_t;
>>          __entry->tag = tag;
>>          __entry->doorbell = doorbell;
>>          __entry->hwq_id = hwq? hwq->id: 0;
>>          __entry->sq_tail = hwq? hwq->sq_tail_slot: 0;
>>          __entry->cq_head = hwq? hwq->cq_head_slot: 0;
>>          __entry->cq_tail = hwq? hwq->cq_tail_slot: 0;
>>          __entry->transfer_len = transfer_len;
>>          __entry->lba = lba;
>>          __entry->intr = intr;
>>          __entry->opcode = opcode;
>>          __entry->group_id = group_id;
>>      ),
>>
>>      TP_printk(
>>          "%s: %s: tag: %u, DB: 0x%x, size: %d, IS: %u, LBA: %llu, 
>> opcode: 0x%x (%s),"
>>          "group_id: 0x%x, hqid: %d, sqt: %d, cqh: %d, cqt: %d",
>>          show_ufs_cmd_trace_str(__entry->str_t), __get_str(dev_name), 
>> __entry->tag,
>>          __entry->doorbell, __entry->transfer_len, __entry->intr, 
>> __entry->lba,
>>          (u32)__entry->opcode, str_opcode(__entry->opcode), 
>> (u32)__entry->group_id,
>>          __entry->hwq_id,__entry->sq_tail, __entry->cq_head, 
>> __entry->cq_tail
>>      )
> 
> Hi Ziqi,
> 
> Please reply below the original e-mail instead of above. This is 
> expected on Linux kernel mailing lists.
> 
> Regarding your question: I propose to leave out the sq_tail, cq_head and 
> cq_tail information. That information may be useful for hardware 
> developers but is not useful for other users of the Linux kernel. So the 
> only piece of information that is left that is MCQ-specific is the 
> hardware queue index. I expect that users will be fine to see that 
> information in trace events.
> 
> How about reporting hardware queue index -1 for legacy mode instead of 
> 0? That will allow users to tell the difference between legacy mode and 
> MCQ mode from the trace events.
> 
> Thanks,
> 
> Bart.

Hi Bart,

Thanks for you suggestion. But the member hwq->id is an Unsigned 
integer. if you want to identify SDB mode and MCQ mode,  using "0" is 
enough, Or how about add string such as below?

ufshcd_command: MCQ: complete_rsp: 1d84000.ufshc: tag: 14, DB: 0x0, 
size: 32768, IS: 0, LBA: 5979448,opcode: 0x2a (WRITE_10),group_id: 0x0, 
hqid: 2

Ziqi
> 

Re: [PATCH v4] scsi: ufs: core: Add trace event for MCQ

[Bart Van Assche]

On 3/8/23 18:44, Ziqi Chen wrote:
> Thanks for you suggestion. But the member hwq->id is an Unsigned 
> integer. if you want to identify SDB mode and MCQ mode,  using "0" is 
> enough, Or how about add string such as below?
> 
> ufshcd_command: MCQ: complete_rsp: 1d84000.ufshc: tag: 14, DB: 0x0, 
> size: 32768, IS: 0, LBA: 5979448,opcode: 0x2a (WRITE_10),group_id: 0x0, 
> hqid: 2

Hi Ziqi,

Since 0 is a valid queue ID using 0 to identify the legacy command 
submission mechanism is ambiguous.

Thanks,

Bart.

Re: [PATCH v4] scsi: ufs: core: Add trace event for MCQ

[Ziqi Chen]

On 3/9/2023 11:45 PM, Bart Van Assche wrote:
> On 3/8/23 18:44, Ziqi Chen wrote:
>> Thanks for you suggestion. But the member hwq->id is an Unsigned 
>> integer. if you want to identify SDB mode and MCQ mode,  using "0" is 
>> enough, Or how about add string such as below?
>>
>> ufshcd_command: MCQ: complete_rsp: 1d84000.ufshc: tag: 14, DB: 0x0, 
>> size: 32768, IS: 0, LBA: 5979448,opcode: 0x2a (WRITE_10),group_id: 
>> 0x0, hqid: 2
> 
> Hi Ziqi,
> 
> Since 0 is a valid queue ID using 0 to identify the legacy command 
> submission mechanism is ambiguous.
> 
> Thanks,
> 
> Bart.

OK, let me convert hwq id to int from ftrace side.


Best Regards,
Ziqi